fix(log): record each message once in the journal, with its real priority

[ibiltari]

Every CUEMS log line was reaching journald three times, and none of the copies could be filtered by level. Found while debugging why cuems-logs looked broken on the test2 controller.

The three copies

#	Source	Transport	Rendered as
1	StreamHandler(sys.stdout)	stdout	controller-engine[…]: [ts][DEBUG] FormitGo…
2	SysLogHandler('/dev/log')	syslog	controller-engi[…]: [ts][DEBUG] FormitGo…
3	root StreamHandler(stderr)	stdout	controller-engine[…]: DEBUG:cuemsengine.…

Measured on a controller: cuems-controller-engine produced 2781 journal entries for 927 logical messages; cuems-node-engine 927 for 309. cuems-editor, which does not import cuemsengine.osc, sat at 1:1 stdout:syslog — which is what pinned down copy #3.

What this changes

1. Copy Release v0.0.5 - Ensure proper xml and json reading and writing. #3 — pyossia calls the module-level logging.info() helper at import time (reached via cuemsengine.osc). With no handler on root yet, Python runs logging.basicConfig() implicitly and attaches a StreamHandler(stderr) using BASIC_FORMAT; module loggers here propagate, so every record was re-emitted through it. Seeding root with a NullHandler makes that implicit call a no-op. Traced with an addHandler/basicConfig probe:

   File ".../cuemsengine/osc/__init__.py", line 5, in <module>
   File "/usr/lib/python3/dist-packages/pyossia/__init__.py", line 30, in <module>
   File "/usr/lib/python3.11/logging/__init__.py", line 2147, in info
   → logging.basicConfig() → addHandler on 'root' fmt='%(levelname)s:%(name)s:%(message)s'
   

   Propagation is deliberately left enabled: pytest's caplog captures through a root handler and depends on it. Setting propagate = False was the obvious fix and would have broken a chunk of the suite.

2. Copy Extra optional, rename logging functions to shorter names #1 vs Parser fixxes #2 — under systemd both terminate in the same journal. Keep only syslog there, because systemd stamps every stdout line PRIORITY=6 regardless of the Python level, so journalctl -p (and therefore cuems-logs -l/--level and -e/--errors) cannot tell DEBUG from ERROR on the stdout copy. Detection is JOURNAL_STREAM, which systemd sets exactly when stdout is wired to the journal, so interactive runs and pytest still print to stdout.

3. Identifier — journald parses SYSLOG_IDENTIFIER off a leading TAG:. Without one the entry has no identifier and journalctl falls back to _COMM, truncated by the kernel to 15 chars, so controller-engine showed up as controller-engi and read as a separate process. The PID is left out of the tag so journald's _PID, taken from socket credentials, stays correct across a fork.

Verification (test2 controller)

	Before	After
Copies per message	3× (450 entries / 150 msgs)	1× — ratio 1.00, 100% syslog
Priorities	all stdout stamped 6	DEBUG=7 / WARNING=4 / ERROR=3
Identifier	controller-engi (truncated)	controller-engine
Interactive run	stdout	stdout (unchanged)
Long messages	—	1 K–60 K intact, single entry

Post-restart, controller engine: 95 records / 95 unique / ratio 1.00. Node engine reads 1.07 — verified to be the @logged decorator firing on real repeated apply_volume/set_value calls, not handler duplication.

Test suite 552 passed, identical to baseline.

Note

cuems-common d1c2109 is the companion change (cuems-logs fixes + journal retention).

[cursor]

Bugbot is not enabled for your account, so this pull request was not reviewed.

Enable Bugbot in the Cursor dashboard to get automatic reviews on future PRs.

[codecov]

Codecov Report

❌ Patch coverage is 88.88889% with 1 line in your changes missing coverage. Please review.

Files with missing lines	Patch %	Lines
src/cuemsutils/log.py	88.88%	0 Missing and 1 partial ⚠️

📢 Thoughts on this report? Let us know!