nodes/ComfyAssets-ComfyUI_PromptManager
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

fix(logs): accept pre-1970 identities, refuse duplicate rows, say the foreign-writer check is best effort (#389)

Browse Source 
Review follow-ups: a negative mtime_ns no longer makes every workspace
clear 400; a name listed twice is a malformed list; the confirmed-row cap
is 10000; the hard-link refusal says how to recover; the hard-link and
foreign-append tests assert the kept bytes before the refusal code, so on
the old code they fail on lost data.
This commit is contained in:
Vito Sansevero
2026-10-27 18:56:52 -07:00
parent 83bac3988f
commit be07d1e74e
3 changed files with 56 additions and 25 deletions
Download Patch File Download Diff File Expand all files Collapse all files
TESTING.md
+3 -1
View File
@@ -3991,7 +3991,9 @@ modals use the same routes and keep working.
- Without a body (the legacy admin page, whose confirm lists nothing; also the
workspace when the file list could not be read and the dialog said "deletes its
rotated copies") every rotated copy present at the locked rescan is deleted.
- Either way, before anything changes: a second writer of the active log (our
- Either way, before anything changes (best effort, not a cross-process lock: a
write before our own last write, or any while file logging is off here, is not
seen): a second writer of the active log (our
handler's flushed stream is behind the file's size, or its file is now a rotated
copy: another ComfyUI sharing the folder) is 409 `logs-foreign-writer`; an active
log with more than one name (`st_nlink > 1` by `lstat` or the handler's `fstat`,
tests/test_utils_logging_config.py
+41 -19
View File
@@ -819,7 +819,19 @@ class TestClearOnlyWhatWasConfirmed(IsolatedLoggerTestCase):
for row in self.manager.get_log_files():
with self.subTest(name=row["filename"]):
self.assertIsInstance(row["identity"], str)
self.assertRegex(row["identity"], r"^\d+:\d+:\d+$")
self.assertRegex(row["identity"], r"^\d+:-?\d+:\d+$")
def test_a_copy_dated_before_1970_can_be_confirmed(self):
self._write("prompt_manager.log.1")
try:
os.utime(self._path("prompt_manager.log.1"), ns=(0, -(10**9)))
except (OSError, OverflowError, ValueError) as error:
self.skipTest(f"this filesystem cannot store a time before 1970: {error}")
confirmed = self._confirmed()
if not any(":-" in row["identity"] for row in confirmed):
self.skipTest("the filesystem did not keep the negative time")
result = self.manager.truncate_logs(confirmed)
self.assertIn("prompt_manager.log.1", result["truncated"])
def test_a_rollover_after_the_confirmation_deletes_nothing(self):
self._write("prompt_manager.log.1", b"one" * 10)
@@ -847,21 +859,31 @@ class TestClearOnlyWhatWasConfirmed(IsolatedLoggerTestCase):
["prompt_manager.log", "prompt_manager.log.5"],
)
def _clear(self, confirmed=None):
"""Run a clear and return what it raised (None), so the files are
asserted first: on the old code the test fails on lost bytes."""
try:
if confirmed is None:
self.manager.truncate_logs() # the legacy page's call
else:
self.manager.truncate_logs(confirmed)
except Exception as error: # noqa: BLE001 - asserted below
return error
return None
def test_a_foreign_append_to_the_active_log_is_refused(self):
# A second ComfyUI sharing the folder writes the same active log.
self._write("prompt_manager.log.1")
for confirmed in (self._confirmed(), None):
with self.subTest(listed=confirmed is not None):
listings = (None, "listed")
for listing in listings:
with self.subTest(listed=listing is not None):
confirmed = self._confirmed() if listing else None
with open(self._path("prompt_manager.log"), "ab") as other:
other.write(b"line from another process\n")
before = self._snapshot()
with self.assertRaises(logging_config.ClearRefused) as caught:
if confirmed is None:
self.manager.truncate_logs() # the legacy page's call
else:
self.manager.truncate_logs(confirmed)
self.assertEqual(caught.exception.code, "logs-foreign-writer")
error = self._clear(confirmed)
self._assert_unchanged(before)
self.assertEqual(getattr(error, "code", None), "logs-foreign-writer")
self.logger.info("our own line") # our stream catches up again
@unittest.skipIf(os.name == "nt", "Windows cannot rename a log that is open")
@@ -917,24 +939,20 @@ class TestClearOnlyWhatWasConfirmed(IsolatedLoggerTestCase):
self._require_hard_link(self._path("prompt_manager.log"), other_name)
kept = self._read(other_name)
self.assertTrue(kept)
for call in (lambda: self.manager.truncate_logs(), None):
with self.subTest(listed=call is None):
with self.assertRaises(logging_config.ClearRefused) as caught:
if call is None:
self.manager.truncate_logs(self._confirmed())
else:
call()
self.assertEqual(caught.exception.code, "logs-hard-link")
for listed in (False, True):
with self.subTest(listed=listed):
error = self._clear(self._confirmed() if listed else None)
self.assertTrue(self._read(other_name).startswith(kept))
self.assertEqual(getattr(error, "code", None), "logs-hard-link")
def test_a_hard_linked_active_log_with_file_logging_off_is_kept(self):
self.manager.update_config({"file_logging": False})
other_name = os.path.join(self.outside, "kept-by-the-user.log")
self._require_hard_link(self._path("prompt_manager.log"), other_name)
kept = self._read(other_name)
with self.assertRaises(logging_config.ClearRefused):
self.manager.truncate_logs()
error = self._clear()
self.assertEqual(self._read(other_name), kept)
self.assertEqual(getattr(error, "code", None), "logs-hard-link")
def test_a_malformed_confirmation_is_refused_before_anything_changes(self):
self._write("prompt_manager.log.1")
@@ -945,6 +963,10 @@ class TestClearOnlyWhatWasConfirmed(IsolatedLoggerTestCase):
[{"name": "prompt_manager.log.1", "identity": 7}],
[{"name": "prompt_manager.log.1", "identity": "1:2"}],
[{"name": 1, "identity": "1:2:3"}],
[
{"name": "prompt_manager.log.1", "identity": "1:2:3"},
{"name": "prompt_manager.log.1", "identity": "1:2:3"},
],
["prompt_manager.log.1"],
):
with self.subTest(expected=expected):
utils/logging_config.py
+12 -5
View File
@@ -50,12 +50,14 @@ CLEAR_FOREIGN_WRITER = (
)
CLEAR_HARD_LINK = (
"prompt_manager.log has another name (a hard link); emptying it would empty"
" that file too, so nothing was cleared."
" that file too, so nothing was cleared. Remove the other name, then clear"
" again."
)
# A confirmed row's identity: "<size>:<mtime_ns>:<ino>", a string because
# mtime_ns and many inodes are larger than a browser's exact integers.
_IDENTITY = re.compile(r"([0-9]{1,20}):([0-9]{1,20}):([0-9]{1,40})")
MAX_CONFIRMED_ROWS = 1000
# mtime_ns is negative for a time before 1970 (a restored archive, say).
_IDENTITY = re.compile(r"([0-9]{1,20}):(-?[0-9]{1,20}):([0-9]{1,40})")
MAX_CONFIRMED_ROWS = 10000
class ClearRefused(Exception):
@@ -169,7 +171,7 @@ def parse_confirmed(expected) -> List[Dict[str, Any]]:
"""
if not isinstance(expected, list) or len(expected) > MAX_CONFIRMED_ROWS:
raise ValueError("expected must be a list of listed log files")
rows = []
rows, seen = [], set()
for item in expected:
if not isinstance(item, dict):
raise ValueError("each expected file must be an object")
@@ -180,6 +182,9 @@ def parse_confirmed(expected) -> List[Dict[str, Any]]:
if match is None:
raise ValueError("an expected file's identity is not size:mtime_ns:ino")
size, mtime_ns, ino = (int(part) for part in match.groups())
if _name_key(name) in seen:
raise ValueError("an expected file is listed twice")
seen.add(_name_key(name))
rows.append({"name": name, "size": size, "mtime_ns": mtime_ns, "ino": ino})
return rows
@@ -678,7 +683,9 @@ class PromptManagerLogger:
program's doing. Our handler's stream is flushed: a file larger than
the stream's own offset was appended to by someone else, and a stream
whose file is now a rotated copy was rolled over by someone else.
Either is a second writer (another ComfyUI sharing the folder). An
Either is a second writer (another ComfyUI sharing the folder). This
is best effort, not a lock: writes before our own last write, or any
write while this process has file logging off, go unseen. An
active log with more than one name (a hard link) is never emptied: the
other name would be emptied too.
"""