[ADD] migration state: read the server log so nobody has to
A step log reaches thirteen megabytes — measured on a real migration. Nobody reads that, and the question one asks in front of it is two words long: where did it go wrong? The screen now answers it. Each step carries its count of ERROR and CRITICAL, and the pane lists the DISTINCT messages with how many times each occurred. Forty-eight « Model X has no table » is one problem seen forty-eight times, not forty-eight problems, and the raw list buries everything else. WARNING is left out of the count: a migration produces thousands, and a total that includes them means nothing. Each message keeps its logger and its DATABASE, which is what tells the six bumps apart — they shared one file before a step opened its own. Measured: thirteen megabytes scanned in 0.09 s, seventy occurrences reduced to fifteen messages, and cached on (size, mtime) because the screen repaints on every keystroke. --- FR --- [ADD] état de migration : lire le journal pour que personne n'ait à le faire Un journal d'étape atteint treize mégaoctets — mesuré. Personne ne le lit, et la question qu'on se pose devant lui tient en deux mots : où est-ce que ça a mal tourné ? L'écran y répond désormais. Chaque étape porte son compte d'ERROR et de CRITICAL, et le panneau liste les messages DISTINCTS avec leur nombre. Quarante-huit fois « Model X has no table » est un problème vu quarante-huit fois, pas quarante-huit problèmes. Les WARNING sont hors du compte : une migration en produit des milliers. Chaque message garde son logger et sa BASE, ce qui distingue les six paliers — ils partageaient un fichier avant qu'une étape n'ouvre le sien. Mesuré : treize mégaoctets analysés en 0,09 s, soixante-dix occurrences ramenées à quinze messages. Assisted-by: Claude Opus 5
This commit is contained in:
parent
6dff7aa304
commit
6715700a16
3 changed files with 321 additions and 3 deletions
|
|
@ -21,6 +21,7 @@ toucher une base ni lancer un serveur. On l'ouvre en pleine migration.
|
|||
|
||||
import json
|
||||
import os
|
||||
import re
|
||||
import sys
|
||||
|
||||
sys.path.append(
|
||||
|
|
@ -190,6 +191,86 @@ def step_slug(msg):
|
|||
return (nom or "step")[:80].lower()
|
||||
|
||||
|
||||
# Le format d'une ligne de journal Odoo :
|
||||
# 2026-08-19 09:21:07,074 132948 ERROR <base> odoo.tools.translate: message
|
||||
# Le nom de la base en fait partie, et c'est ce qui permet de séparer six
|
||||
# paliers écrits dans un même fichier — ce qui était le cas avant qu'une
|
||||
# étape n'ouvre son propre journal.
|
||||
RE_LOG_LINE = re.compile(
|
||||
r"^\d{4}-\d\d-\d\d \d\d:\d\d:\d\d,\d+ \d+ (\w+) (\S+) ([\w.]+): (.*)$"
|
||||
)
|
||||
GRAVE = ("ERROR", "CRITICAL")
|
||||
|
||||
_CACHE = {}
|
||||
|
||||
|
||||
def scan_log(chemin):
|
||||
"""Compter les sévérités et relever les erreurs DISTINCTES d'un journal.
|
||||
|
||||
Mis en cache sur (taille, date) : l'écran se redessine à chaque touche,
|
||||
et un journal d'étape atteint treize mégaoctets — mesuré. Le relire à
|
||||
chaque frappe rendrait l'écran inutilisable.
|
||||
|
||||
Les erreurs sont dédoublonnées avec leur nombre : quarante-huit fois
|
||||
« Model X has no table » est UN problème vu quarante-huit fois, pas
|
||||
quarante-huit problèmes, et la liste brute noie tout le reste.
|
||||
"""
|
||||
try:
|
||||
stat = os.stat(chemin)
|
||||
except OSError:
|
||||
return {"count": {}, "errors": []}
|
||||
cle = (chemin, stat.st_size, int(stat.st_mtime))
|
||||
if cle in _CACHE:
|
||||
return _CACHE[cle]
|
||||
compte = {}
|
||||
distinct = {}
|
||||
try:
|
||||
with open(chemin, "r", encoding="utf-8", errors="replace") as handle:
|
||||
for ligne in handle:
|
||||
trouve = RE_LOG_LINE.match(ligne)
|
||||
if not trouve:
|
||||
if ligne.startswith("Traceback"):
|
||||
compte["TRACEBACK"] = compte.get("TRACEBACK", 0) + 1
|
||||
continue
|
||||
niveau, base, logger, message = trouve.groups()
|
||||
compte[niveau] = compte.get(niveau, 0) + 1
|
||||
if niveau in GRAVE:
|
||||
signature = (base, logger, message.strip()[:120])
|
||||
distinct[signature] = distinct.get(signature, 0) + 1
|
||||
except OSError:
|
||||
return {"count": {}, "errors": []}
|
||||
resultat = {
|
||||
"count": compte,
|
||||
"errors": [
|
||||
{
|
||||
"database": base,
|
||||
"logger": logger,
|
||||
"message": message,
|
||||
"times": nombre,
|
||||
}
|
||||
for (base, logger, message), nombre in sorted(
|
||||
distinct.items(), key=lambda item: -item[1]
|
||||
)
|
||||
],
|
||||
}
|
||||
# Un seul journal en cache : ils pèsent des mégaoctets, et l'écran ne
|
||||
# regarde qu'une étape à la fois.
|
||||
_CACHE.clear()
|
||||
_CACHE[cle] = resultat
|
||||
return resultat
|
||||
|
||||
|
||||
def step_log_scan(dct, step):
|
||||
"""Ce que le journal de cette étape contient de grave."""
|
||||
chemin = step_log_path(dct, step)
|
||||
return scan_log(chemin) if chemin else {"count": {}, "errors": []}
|
||||
|
||||
|
||||
def severe_count(scan):
|
||||
"""Combien d'ERROR et de CRITICAL, en un seul nombre."""
|
||||
return sum(scan["count"].get(niveau, 0) for niveau in GRAVE)
|
||||
|
||||
|
||||
def step_log_tail(dct, step, lines=400):
|
||||
"""Les dernières lignes du journal de cette étape, et le compte total.
|
||||
|
||||
|
|
@ -397,10 +478,21 @@ def render_text(dct, limit_cmd=12, colour=None):
|
|||
for section in journal_by_step(dct):
|
||||
lst_cmd = section["lst_cmd"]
|
||||
journal = " 📄" if step_log_path(dct, section["step"]) else ""
|
||||
scan = step_log_scan(dct, section["step"])
|
||||
graves = severe_count(scan)
|
||||
# Le nombre d'ERROR à côté de l'étape : c'est la seule façon de
|
||||
# voir d'un coup d'œil OÙ la migration a souffert, sans ouvrir
|
||||
# treize mégaoctets de journal.
|
||||
alerte = f" {paint(f'❌ {graves}', 'fail', colour)}" if graves else ""
|
||||
lignes.append(
|
||||
f" {paint(section['step'], 'step', colour)}"
|
||||
f" ({len(lst_cmd)}){journal}"
|
||||
f" ({len(lst_cmd)}){journal}{alerte}"
|
||||
)
|
||||
for item in scan["errors"][:3]:
|
||||
lignes.append(
|
||||
f" ×{item['times']:<3}"
|
||||
f" {paint(item['message'][:100], 'warn', colour)}"
|
||||
)
|
||||
for cmd in lst_cmd[:limit_cmd]:
|
||||
# LA demande : distinguer d'un coup d'œil ce qui a été lancé
|
||||
# du reste du rapport. Une liste de commandes en texte plat se
|
||||
|
|
|
|||
|
|
@ -79,11 +79,15 @@ def rows(dct):
|
|||
}
|
||||
)
|
||||
for section in status.journal_by_step(dct):
|
||||
graves = status.severe_count(
|
||||
status.step_log_scan(dct, section["step"])
|
||||
)
|
||||
lst.append(
|
||||
{
|
||||
"kind": "step",
|
||||
"label": section["step"],
|
||||
"detail": str(len(section["lst_cmd"])),
|
||||
"severe": str(graves) if graves else "",
|
||||
"data": section,
|
||||
}
|
||||
)
|
||||
|
|
@ -131,6 +135,24 @@ def pane_text(dct, row, colour=False, show_log=True):
|
|||
# la liste des commandes dit ce qui a été lancé, jamais ce que cela a
|
||||
# répondu. Mais les deux mélangés dans un même panneau se confondent —
|
||||
# d'où « l », qui les sépare.
|
||||
# Les erreurs DISTINCTES d'abord, le journal brut ensuite : quarante-
|
||||
# huit fois le même message est un problème vu quarante-huit fois, et
|
||||
# la liste brute le noie au milieu de cent mille lignes.
|
||||
scan = status.step_log_scan(dct, section["step"])
|
||||
if scan["errors"]:
|
||||
lignes.append("")
|
||||
lignes.append(
|
||||
f"── {t('errors in the log')} :" f" {status.severe_count(scan)} ──"
|
||||
)
|
||||
for item in scan["errors"][:15]:
|
||||
lignes.append(
|
||||
f" ×{item['times']:<4}"
|
||||
f" {status.paint(item['message'], 'fail', colour)}"
|
||||
)
|
||||
lignes.append(
|
||||
f" {status.paint(item['logger'], 'dim', colour)}"
|
||||
f" · {item['database']}"
|
||||
)
|
||||
tail, total = status.step_log_tail(dct, section["step"])
|
||||
if not show_log:
|
||||
if total:
|
||||
|
|
@ -267,9 +289,11 @@ def build_app(dct, path=None):
|
|||
def _fill_table(self):
|
||||
table = self.query_one("#left", DataTable)
|
||||
table.clear(columns=True)
|
||||
table.add_columns(t("Test results"), "#")
|
||||
table.add_columns(t("Test results"), "#", "❌")
|
||||
for row in self.lst_row:
|
||||
table.add_row(row["label"][:38], row["detail"])
|
||||
table.add_row(
|
||||
row["label"][:38], row["detail"], row.get("severe", "")
|
||||
)
|
||||
table.styles.width = self.left_width
|
||||
self.query_one("#head", Static).update(head_text(self.dct))
|
||||
|
||||
|
|
|
|||
|
|
@ -1014,6 +1014,208 @@ class TestHowLongItTook(Base):
|
|||
)
|
||||
|
||||
|
||||
class TestReadingTheLogForTheUser(DiskCase):
|
||||
"""Compter les erreurs à la place de quelqu'un.
|
||||
|
||||
Un journal d'étape atteint treize mégaoctets — mesuré. Personne ne le
|
||||
lit, et la question qu'on se pose devant lui tient en deux mots : où
|
||||
est-ce que ça a mal tourné ? C'est cette question-là que l'écran doit
|
||||
savoir répondre sans qu'on ouvre le fichier.
|
||||
"""
|
||||
|
||||
JOURNAL = (
|
||||
"2026-08-19 09:21:07,074 132948 ERROR base13"
|
||||
" odoo.tools.translate: couldn't read translation file\n"
|
||||
"Traceback (most recent call last):\n"
|
||||
"2026-08-19 09:34:27,088 133771 ERROR base14"
|
||||
" odoo.modules.registry: Model account.bank.statement.import"
|
||||
" has no table.\n"
|
||||
"2026-08-19 09:34:28,088 133771 ERROR base14"
|
||||
" odoo.modules.registry: Model account.bank.statement.import"
|
||||
" has no table.\n"
|
||||
"2026-08-19 09:44:51,959 134592 CRITICAL base15"
|
||||
" odoo.service.server: Failed to initialize database.\n"
|
||||
"2026-08-19 09:44:52,000 134592 WARNING base15"
|
||||
" odoo.schema: unable to add constraint\n"
|
||||
"2026-08-19 09:44:53,000 134592 INFO base15"
|
||||
" odoo.modules.loading: Modules loaded.\n"
|
||||
)
|
||||
|
||||
def poser(self, contenu=None, etape="4 - Upgrade"):
|
||||
obj = self.upgrade()
|
||||
obj.add_comment_progression(etape)
|
||||
obj.close_step_log()
|
||||
chemin = os.path.join(
|
||||
"private",
|
||||
"odoo",
|
||||
"migration",
|
||||
"essai_db",
|
||||
"step_log",
|
||||
status.step_slug(etape) + ".log",
|
||||
)
|
||||
with open(chemin, "w") as handle:
|
||||
handle.write(contenu if contenu is not None else self.JOURNAL)
|
||||
# La progression de l'objet, pas un dict nu : c'est elle qui porte
|
||||
# `command_executed`, donc le découpage par étape.
|
||||
return obj.dct_progression
|
||||
|
||||
def test_it_counts_the_severities(self):
|
||||
scan = status.step_log_scan(self.poser(), "4 - Upgrade")
|
||||
self.assertEqual(scan["count"]["ERROR"], 3)
|
||||
self.assertEqual(scan["count"]["CRITICAL"], 1)
|
||||
self.assertEqual(scan["count"]["WARNING"], 1)
|
||||
self.assertEqual(scan["count"]["TRACEBACK"], 1)
|
||||
|
||||
def test_the_severe_ones_are_summed(self):
|
||||
# ERROR et CRITICAL, pas WARNING : une migration en produit des
|
||||
# milliers, et un compte qui les inclut ne veut plus rien dire.
|
||||
scan = status.step_log_scan(self.poser(), "4 - Upgrade")
|
||||
self.assertEqual(status.severe_count(scan), 4)
|
||||
|
||||
def test_the_same_message_is_counted_ONCE(self):
|
||||
# Quarante-huit fois « Model X has no table » est UN problème vu
|
||||
# quarante-huit fois, pas quarante-huit problèmes.
|
||||
scan = status.step_log_scan(self.poser(), "4 - Upgrade")
|
||||
modele = [e for e in scan["errors"] if "has no table" in e["message"]]
|
||||
self.assertEqual(len(modele), 1)
|
||||
self.assertEqual(modele[0]["times"], 2)
|
||||
|
||||
def test_the_loudest_comes_first(self):
|
||||
scan = status.step_log_scan(self.poser(), "4 - Upgrade")
|
||||
self.assertEqual(scan["errors"][0]["times"], 2)
|
||||
|
||||
def test_each_error_carries_its_database(self):
|
||||
# Six paliers ont pu écrire dans le même fichier : sans la base,
|
||||
# on ne sait pas lequel a souffert.
|
||||
scan = status.step_log_scan(self.poser(), "4 - Upgrade")
|
||||
bases = {e["database"] for e in scan["errors"]}
|
||||
self.assertEqual(bases, {"base13", "base14", "base15"})
|
||||
|
||||
def test_it_carries_the_logger_too(self):
|
||||
scan = status.step_log_scan(self.poser(), "4 - Upgrade")
|
||||
loggers = {e["logger"] for e in scan["errors"]}
|
||||
self.assertIn("odoo.tools.translate", loggers)
|
||||
|
||||
def test_warnings_are_never_listed_as_errors(self):
|
||||
scan = status.step_log_scan(self.poser(), "4 - Upgrade")
|
||||
self.assertNotIn(
|
||||
"unable to add constraint",
|
||||
" ".join(e["message"] for e in scan["errors"]),
|
||||
)
|
||||
|
||||
def test_a_step_without_a_log_counts_zero(self):
|
||||
self.assertEqual(
|
||||
status.severe_count(
|
||||
status.step_log_scan(
|
||||
{"config_database_name": "essai_db"}, "9 - rien"
|
||||
)
|
||||
),
|
||||
0,
|
||||
)
|
||||
|
||||
def test_a_healthy_log_shows_no_alarm(self):
|
||||
dct = self.poser(
|
||||
"2026-08-19 09:00:00,000 1 INFO db odoo.modules: Modules loaded.\n"
|
||||
)
|
||||
self.assertEqual(
|
||||
status.severe_count(status.step_log_scan(dct, "4 - Upgrade")), 0
|
||||
)
|
||||
# La LIGNE d'étape, pas tout le rapport : celui-ci porte toujours
|
||||
# l'en-tête « Commandes en échec », qui a le même symbole.
|
||||
etapes = status.render_text(dct, colour=False).split("step by step")[1]
|
||||
self.assertNotIn("❌", etapes)
|
||||
|
||||
def test_the_report_names_the_count_and_the_top_errors(self):
|
||||
texte = status.render_text(self.poser(), colour=False)
|
||||
self.assertIn("❌ 4", texte)
|
||||
self.assertIn("has no table", texte)
|
||||
|
||||
def test_the_full_screen_lists_them_with_their_source(self):
|
||||
dct = self.poser()
|
||||
etape = [x for x in tui.rows(dct) if x["kind"] == "step"][0]
|
||||
texte = tui.pane_text(dct, etape, show_log=False)
|
||||
self.assertIn("×2", texte)
|
||||
self.assertIn("odoo.modules.registry", texte)
|
||||
self.assertIn("base14", texte)
|
||||
|
||||
def test_the_left_column_shows_the_count(self):
|
||||
dct = self.poser()
|
||||
etape = [x for x in tui.rows(dct) if x["kind"] == "step"][0]
|
||||
self.assertEqual(etape["severe"], "4")
|
||||
|
||||
def test_a_clean_step_leaves_the_column_empty(self):
|
||||
# Un « 0 » dans chaque ligne n'apprend rien et occupe la place.
|
||||
dct = self.poser(
|
||||
"2026-08-19 09:00:00,000 1 INFO db odoo.modules: ok\n"
|
||||
)
|
||||
etape = [x for x in tui.rows(dct) if x["kind"] == "step"][0]
|
||||
self.assertEqual(etape["severe"], "")
|
||||
|
||||
|
||||
class TestReadingItTwiceIsFree(DiskCase):
|
||||
"""L'écran se redessine à chaque touche.
|
||||
|
||||
Relire treize mégaoctets à chaque frappe rendrait l'écran inutilisable.
|
||||
"""
|
||||
|
||||
def test_the_second_read_does_not_touch_the_disk(self):
|
||||
obj = self.upgrade()
|
||||
obj.add_comment_progression("4 - Upgrade")
|
||||
obj.close_step_log()
|
||||
chemin = os.path.join(
|
||||
"private",
|
||||
"odoo",
|
||||
"migration",
|
||||
"essai_db",
|
||||
"step_log",
|
||||
status.step_slug("4 - Upgrade") + ".log",
|
||||
)
|
||||
with open(chemin, "w") as handle:
|
||||
handle.write("2026-08-19 09:00:00,000 1 ERROR db odoo.x: boum\n")
|
||||
dct = {"config_database_name": "essai_db"}
|
||||
premier = status.step_log_scan(dct, "4 - Upgrade")
|
||||
lectures = []
|
||||
vrai_open = open
|
||||
|
||||
def compter(*args, **kwargs):
|
||||
lectures.append(args[0])
|
||||
return vrai_open(*args, **kwargs)
|
||||
|
||||
import builtins
|
||||
|
||||
builtins.open = compter
|
||||
self.addCleanup(setattr, builtins, "open", vrai_open)
|
||||
second = status.step_log_scan(dct, "4 - Upgrade")
|
||||
self.assertEqual(premier, second)
|
||||
self.assertEqual([x for x in lectures if str(x).endswith(".log")], [])
|
||||
|
||||
def test_a_changed_file_IS_read_again(self):
|
||||
# Sinon « r » ne rafraîchirait rien : la migration écrit pendant
|
||||
# qu'on regarde.
|
||||
obj = self.upgrade()
|
||||
obj.add_comment_progression("4 - Upgrade")
|
||||
obj.close_step_log()
|
||||
chemin = os.path.join(
|
||||
"private",
|
||||
"odoo",
|
||||
"migration",
|
||||
"essai_db",
|
||||
"step_log",
|
||||
status.step_slug("4 - Upgrade") + ".log",
|
||||
)
|
||||
dct = {"config_database_name": "essai_db"}
|
||||
with open(chemin, "w") as handle:
|
||||
handle.write("2026-08-19 09:00:00,000 1 ERROR db odoo.x: un\n")
|
||||
self.assertEqual(
|
||||
status.severe_count(status.step_log_scan(dct, "4 - Upgrade")), 1
|
||||
)
|
||||
with open(chemin, "a") as handle:
|
||||
handle.write("2026-08-19 09:00:01,000 1 ERROR db odoo.y: deux\n")
|
||||
self.assertEqual(
|
||||
status.severe_count(status.step_log_scan(dct, "4 - Upgrade")), 2
|
||||
)
|
||||
|
||||
|
||||
class TestSeparatingCommandsFromLogs(Base):
|
||||
"""Les deux mélangés dans un même panneau se confondent.
|
||||
|
||||
|
|
|
|||
Loading…
Reference in a new issue