Patrick Schurig 483bbcb027 feat(traces): traces de décision NDJSON, une ligne par cycle (brief 4 T6, annexe D)
Réglage optimizerTrace (energy.conf Optimizer/trace, …RetentionDays, …MaxBytesPerDay), défaut
DÉSACTIVÉ : ni objet, ni fil, ni fichier. NymeaEnergy.GetOptimizerTrace / SetOptimizerTrace,
PermissionScopeAdmin comme SetOptimizerEndpoint, type contrôlé par le moteur, appliqué à chaud.

Une ligne par cycle — rule-based, optimiseur, et L2 (strategy none, sans requête) : t (heure
locale), request (params GetPlan envoyés, ou qui l'auraient été), response (ce qui a répondu
à CETTE requête : result brut, error.code, no-response ; sinon le plan du rule-based en codes),
executed (appliqué, clamped, shed), strategy, latencyMs. La ligne N attend la réponse à la
requête N (elle sert au cycle N+1).

Toutes les E/S sur un fil dédié (OptimizerTraceWriter) : rotation à minuit heure locale, purge
au-delà de la rétention (14 j), plafond par fichier journalier (64 Mio, mesuré : 5 Ko/ligne
rule-based, 39 Ko sous un optimiseur à 48 créneaux, 1 cycle/min), file bornée à 256 lignes.
Échec d'écriture et plafond dits une fois. update() ne fait que poster. Le token n'est jamais
dans une ligne ; recopié par une réponse d'optimiseur, il est masqué.

Preuves : decisions IDENTIQUE traces désactivées ET activées (21 132 lignes de trace écrites,
ETM_DECISIONS_TRACES=1). socketscheduler 33 fonctions, 114/0 (+10 fonctions T6).

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-17 12:12:25 +02:00

397 lines
14 KiB
C++
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

// SPDX-License-Identifier: GPL-3.0-or-later
// Copyright (C) 2025 - 2026, Patrick Schurig / ETM PowerSync
#include "optimizertrace.h"
#include <QDir>
#include <QFileInfo>
#include <QJsonArray>
#include <QJsonDocument>
#include <QJsonObject>
#include <QLoggingCategory>
#include <QRegularExpression>
#include <nymeasettings.h>
#include "energysettings.h"
Q_DECLARE_LOGGING_CATEGORY(dcNymeaEnergy)
namespace OptimizerTrace {
namespace {
QString iso(const QDateTime &t) { return t.toUTC().toString(Qt::ISODate); }
QString nomKind(LoadAction::Kind k)
{
switch (k) {
case LoadAction::Setpoint: return QStringLiteral("setpoint");
case LoadAction::State: return QStringLiteral("state");
case LoadAction::Constraint: return QStringLiteral("constraint");
}
return QString();
}
// Une action DÉCIDÉE, au format d'une action de plan (§6) — le motif en code, jamais en phrase.
QVariantMap actionDecidee(const LoadAction &a)
{
QVariantMap m;
m.insert(QStringLiteral("loadId"), a.loadId);
m.insert(QStringLiteral("kind"), nomKind(a.kind));
m.insert(QStringLiteral("powerW"), qMax(0.0, a.estimatedPowerW));
if (a.kind == LoadAction::State)
m.insert(QStringLiteral("state"), a.state);
m.insert(QStringLiteral("reasonCode"), a.reason.code);
if (!a.reason.params.isEmpty())
m.insert(QStringLiteral("reasonParams"), a.reason.params);
return m;
}
const QString CleActive = QStringLiteral("Optimizer/trace");
const QString CleRetention = QStringLiteral("Optimizer/traceRetentionDays");
const QString ClePlafond = QStringLiteral("Optimizer/traceMaxBytesPerDay");
} // namespace
QString nomFichier(const QDate &jour)
{
return QLatin1String(PrefixeFichier) + jour.toString(QStringLiteral("yyyy-MM-dd"))
+ QLatin1String(SuffixeFichier);
}
QDate dateDuFichier(const QString &nom)
{
static const QRegularExpression forme(QLatin1String("^") + QRegularExpression::escape(QLatin1String(PrefixeFichier))
+ QStringLiteral("(\\d{4}-\\d{2}-\\d{2})")
+ QRegularExpression::escape(QLatin1String(SuffixeFichier))
+ QStringLiteral("$"));
const QRegularExpressionMatch m = forme.match(nom);
return m.hasMatch() ? QDate::fromString(m.captured(1), QStringLiteral("yyyy-MM-dd")) : QDate();
}
QString horodatage(const QDateTime &t)
{
const QDateTime local = t.toLocalTime();
return local.toOffsetFromUtc(local.offsetFromUtc()).toString(Qt::ISODate);
}
QVariantMap reponseRegles(const Plan &plan, const QDateTime &now)
{
QVariantMap r;
r.insert(QStringLiteral("strategy"), QStringLiteral("rules"));
r.insert(QStringLiteral("computedAt"), iso(now));
QVariantList creneaux;
QDateTime fin;
for (const Slot &s : plan.timeSlots) {
QVariantList actions;
for (const LoadAction &a : s.actions)
actions.append(actionDecidee(a));
creneaux.append(QVariantMap{{QStringLiteral("from"), iso(s.from.isValid() ? s.from : now)},
{QStringLiteral("to"), iso(s.to.isValid() ? s.to : now)},
{QStringLiteral("actions"), actions}});
if (s.to.isValid() && (!fin.isValid() || s.to > fin))
fin = s.to;
}
if (fin.isValid())
r.insert(QStringLiteral("validUntil"), iso(fin));
r.insert(QStringLiteral("slots"), creneaux);
return QVariantMap{{QStringLiteral("result"), r}};
}
QVariantList executees(const Slot &slot, const QHash<QString, LoadAction> &appliquees,
const QSet<QString> &delestees)
{
// Même lecture que le plan publié : ce que l'adaptateur a RENDU ; une charge délestée par L4
// ou non dispatchée n'a pas de retour, son action du créneau (fusionnée) fait foi.
QVariantList l;
for (const LoadAction &a : slot.actions) {
const auto r = appliquees.constFind(a.loadId);
const LoadAction &faite = r != appliquees.constEnd() ? *r : a;
QVariantMap m;
m.insert(QStringLiteral("loadId"), a.loadId);
m.insert(QStringLiteral("kind"), nomKind(a.kind));
m.insert(QStringLiteral("powerW"), qMax(0.0, faite.estimatedPowerW));
if (a.kind == LoadAction::State)
m.insert(QStringLiteral("state"), faite.state);
m.insert(QStringLiteral("clamped"), a.clamped);
if (delestees.contains(a.loadId))
m.insert(QStringLiteral("shed"), true);
l.append(m);
}
return l;
}
QByteArray masquerToken(const QByteArray &ligne, const QByteArray &token, int *masques)
{
if (masques)
*masques = 0;
if (token.isEmpty())
return ligne;
// La forme que QJsonDocument donnerait au token dans une chaîne : ["…"] sans ses bornes.
const QByteArray tableau = QJsonDocument(QJsonArray{QString::fromUtf8(token)}).toJson(QJsonDocument::Compact);
const QByteArray echappe = tableau.mid(2, tableau.size() - 4);
if (echappe.isEmpty() || !ligne.contains(echappe))
return ligne;
QByteArray out = ligne;
const int n = out.count(echappe);
out.replace(echappe, QByteArrayLiteral("[token masqué]"));
if (masques)
*masques = n;
return out;
}
Reglage Reglage::lire()
{
EnergySettings s;
Reglage r;
r.active = s.value(CleActive, false).toBool();
bool ok = false;
const int jours = s.value(CleRetention, RetentionDefautJours).toInt(&ok);
if (ok && jours >= RetentionMinJours && jours <= RetentionMaxJours)
r.retentionJours = jours;
const qint64 plafond = s.value(ClePlafond, PlafondDefautOctets).toLongLong(&ok);
if (ok && plafond >= PlafondMinOctets && plafond <= PlafondMaxOctets)
r.plafondOctetsJour = plafond;
return r;
}
bool Reglage::operator==(const Reglage &o) const
{
return active == o.active && retentionJours == o.retentionJours
&& plafondOctetsJour == o.plafondOctetsJour && dossier == o.dossier
&& cheminToken == o.cheminToken;
}
} // namespace OptimizerTrace
// --- Écrivain : son propre fil, toutes les E/S ------------------------------------------------
OptimizerTraceWriter::OptimizerTraceWriter(std::shared_ptr<std::atomic<int>> enAttente)
: m_enAttente(std::move(enAttente))
{
}
void OptimizerTraceWriter::configurer(const OptimizerTrace::Reglage &r)
{
const bool autreDossier = r.dossier != m_reglage.dossier;
m_reglage = r;
if (autreDossier) {
m_fichier.close();
m_jour = QDate();
}
// Un plafond relevé vaut tout de suite, le jour même.
m_plafondAtteint = QDate();
if (m_jour.isValid())
purger(m_jour);
}
void OptimizerTraceWriter::ecrire(const QVariantMap &ligne, const QDate &jour)
{
// La ligne quitte la file quoi qu'il arrive ici : écrite, refusée par le plafond, ou perdue
// sur un échec.
struct Decompte {
std::atomic<int> *n;
~Decompte() { n->fetch_sub(1); }
} decompte{m_enAttente.get()};
int masques = 0;
const QByteArray l = OptimizerTrace::masquerToken(
QJsonDocument(QJsonObject::fromVariantMap(ligne)).toJson(QJsonDocument::Compact),
token(), &masques)
+ '\n';
if (masques > 0 && !m_masqueSignale) {
// La requête ne porte jamais le token : seule la réponse BRUTE d'un optimiseur peut le
// recopier. On dit le fait, jamais la valeur.
m_masqueSignale = true;
qCWarning(dcNymeaEnergy()) << "[Trace] la réponse de l'optimiseur recopie le token — masqué dans"
" la trace (signalé une fois par session)";
}
if (jour != m_jour)
ouvrir(jour);
if (m_plafondAtteint == jour)
return;
if (!m_fichier.isOpen()) {
ouvrir(jour); // un échec précédent : on retente à chaque ligne, sans le redire
if (!m_fichier.isOpen())
return;
}
if (m_taille + l.size() > m_reglage.plafondOctetsJour) {
m_plafondAtteint = jour;
m_fichier.close();
qCWarning(dcNymeaEnergy()).noquote()
<< QStringLiteral("[Trace] plafond journalier atteint (%1 octets, réglage %2) — plus aucune"
" ligne jusqu'à demain ; décisions inchangées")
.arg(m_taille).arg(m_reglage.plafondOctetsJour);
return;
}
const qint64 n = m_fichier.write(l);
if (n != l.size() || !m_fichier.flush()) {
echec(m_fichier.fileName() + QStringLiteral(" : ") + m_fichier.errorString());
m_fichier.close();
return;
}
m_taille += n;
if (m_echecSignale) {
m_echecSignale = false;
qCInfo(dcNymeaEnergy()).noquote() << "[Trace] écriture rétablie :" << m_fichier.fileName();
}
}
void OptimizerTraceWriter::ouvrir(const QDate &jour)
{
m_fichier.close();
if (jour != m_jour)
purger(jour);
m_jour = jour;
m_taille = 0;
const QString dossier = m_reglage.dossier.isEmpty() ? NymeaSettings::storagePath() : m_reglage.dossier;
m_fichier.setFileName(QDir(dossier).filePath(OptimizerTrace::nomFichier(jour)));
if (!m_fichier.open(QIODevice::WriteOnly | QIODevice::Append)) {
echec(m_fichier.fileName() + QStringLiteral(" : ") + m_fichier.errorString());
return;
}
m_taille = m_fichier.size();
}
void OptimizerTraceWriter::purger(const QDate &aujourdhui)
{
const QString dossier = m_reglage.dossier.isEmpty() ? NymeaSettings::storagePath() : m_reglage.dossier;
QDir d(dossier);
// Rétention de N jours, celui du jour compris : on garde [aujourd'hui − N + 1, aujourd'hui].
const QDate limite = aujourdhui.addDays(-m_reglage.retentionJours);
int supprimes = 0;
const QStringList noms = d.entryList({QLatin1String(OptimizerTrace::PrefixeFichier) + QLatin1Char('*')
+ QLatin1String(OptimizerTrace::SuffixeFichier)},
QDir::Files);
for (const QString &nom : noms) {
const QDate date = OptimizerTrace::dateDuFichier(nom);
if (date.isValid() && date <= limite && d.remove(nom))
++supprimes;
}
if (supprimes > 0)
qCInfo(dcNymeaEnergy()) << "[Trace]" << supprimes << "fichier(s) de plus de"
<< m_reglage.retentionJours << "jour(s) supprimé(s)";
}
void OptimizerTraceWriter::echec(const QString &detail)
{
if (m_echecSignale)
return;
m_echecSignale = true;
qCWarning(dcNymeaEnergy()).noquote() << "[Trace] écriture impossible :" << detail
<< "— traces suspendues jusqu'à la prochaine écriture réussie"
" (signalé une fois) ; décisions inchangées";
}
QByteArray OptimizerTraceWriter::token()
{
if (m_reglage.cheminToken.isEmpty())
return QByteArray();
const QFileInfo fi(m_reglage.cheminToken);
if (!fi.exists()) {
m_token.clear();
m_tokenTaille = -1;
return m_token;
}
if (fi.lastModified() != m_tokenLuA || fi.size() != m_tokenTaille) {
QFile f(m_reglage.cheminToken);
m_token = f.open(QIODevice::ReadOnly) ? f.read(8192).trimmed() : QByteArray();
m_tokenLuA = fi.lastModified();
m_tokenTaille = fi.size();
}
return m_token;
}
// --- Traceur : fil de l'arbitre, jamais d'E/S ------------------------------------------------
OptimizerTracer::OptimizerTracer(const OptimizerTrace::Reglage &r, QObject *parent)
: QObject(parent)
, m_enAttente(std::make_shared<std::atomic<int>>(0))
{
qRegisterMetaType<OptimizerTrace::Reglage>();
m_ecrivain = new OptimizerTraceWriter(m_enAttente);
m_ecrivain->moveToThread(&m_fil);
connect(&m_fil, &QThread::finished, m_ecrivain, &QObject::deleteLater);
connect(this, &OptimizerTracer::versEcrivain, m_ecrivain, &OptimizerTraceWriter::ecrire);
connect(this, &OptimizerTracer::reglageVersEcrivain, m_ecrivain, &OptimizerTraceWriter::configurer);
m_fil.setObjectName(QStringLiteral("etm-powersync-trace"));
m_fil.start(QThread::LowestPriority);
configurer(r);
}
OptimizerTracer::~OptimizerTracer()
{
terminerEnAttente();
// L'arrêt passe DERRIÈRE les lignes déjà postées : elles sont écrites, puis le fil s'arrête.
// Jamais appelé depuis update() — à la désactivation (RPC) ou à l'arrêt du plugin.
QThread *fil = &m_fil;
QMetaObject::invokeMethod(m_ecrivain, [fil] { fil->quit(); }, Qt::QueuedConnection);
m_fil.wait();
}
void OptimizerTracer::configurer(const OptimizerTrace::Reglage &r)
{
m_reglage = r;
emit reglageVersEcrivain(r);
}
void OptimizerTracer::noterCycle(const QVariantMap &ligne, const QDateTime &t, quint64 idRequete)
{
terminerEnAttente();
if (idRequete == 0) {
poster(ligne, t);
return;
}
m_ligneEnAttente = ligne;
m_tEnAttente = t;
m_idEnAttente = idRequete;
}
void OptimizerTracer::noterReponse(quint64 id, const QVariantMap &reponse, qint64 latenceMs)
{
if (id == 0 || id != m_idEnAttente)
return;
QVariantMap l = m_ligneEnAttente;
l.insert(QStringLiteral("response"), reponse);
l.insert(QStringLiteral("latencyMs"), latenceMs);
m_idEnAttente = 0;
m_ligneEnAttente.clear();
poster(l, m_tEnAttente);
}
void OptimizerTracer::terminerEnAttente()
{
if (m_idEnAttente == 0)
return;
QVariantMap l = m_ligneEnAttente;
l.insert(QStringLiteral("response"),
QVariantMap{{QStringLiteral("error"),
QVariantMap{{QStringLiteral("code"), QLatin1String(OptimizerTrace::SansReponse)}}}});
m_idEnAttente = 0;
m_ligneEnAttente.clear();
poster(l, m_tEnAttente);
}
void OptimizerTracer::poster(const QVariantMap &ligne, const QDateTime &t)
{
if (m_enAttente->load() >= OptimizerTrace::FileMaxLignes) {
++m_abandonnees;
if (!m_fileSignalee) {
m_fileSignalee = true;
qCWarning(dcNymeaEnergy()) << "[Trace] l'écrivain ne suit plus (" << OptimizerTrace::FileMaxLignes
<< "lignes en attente) — lignes abandonnées jusqu'à ce qu'il rattrape ;"
" décisions inchangées";
}
return;
}
if (m_fileSignalee) {
m_fileSignalee = false;
qCInfo(dcNymeaEnergy()) << "[Trace] l'écrivain a rattrapé —" << m_abandonnees
<< "ligne(s) abandonnée(s) depuis le démarrage des traces";
}
m_enAttente->fetch_add(1);
emit versEcrivain(ligne, t.toLocalTime().date());
}