Fix VM logs websocket endpoint getting stuck

[olethanh]

Jira ticket: ALEPH-316

At some point the websocket endpoint stopped sending log entries to client

Original report from Arnaud:

"aleph instance logs" output gets stuck
VM started and is accessible, but logs seem frozen when querying them via CLI.

Analysis:

The log entries are in journald and retrievable but they don't get put at on the internal queue. My guess is that there is a lock bug between the journal polling and the queue max length, probably that if the queue is full and get emptied, the polling doesn't reset unless new message arrive in journald.

Solution:

Rework the journald to Queue implementation.

Note:

I have tried a lot of combinaison and variation of the logic and rewrote that code block multiple times, this version works as far as I can tell.

The interaction between asyncio select handling, journald fd reset and async task is complicated and confusing.

Other versions broke in some way or others, sometimes subtle. For examples:

• Past logs working but new log entries not getting consumed
• Queue (re)filling starting only when a new entrie was created
• infinite tasks always popping up
• multiple task consuming the same fd
• Polling never resetting and consumer being called in a loop

Some of theses issues get hidden by the TCP buffer on the websocket and only popup after some time or depending on the network or how the client interact.

So beware if you try to rewrite that logic.
Also DO NOT TRUST ChatGPT or Deepseek on this, they will produce nice looking code that do not works properly.

To test:

Start an instance or a program on your dev CRN. Fetch the logs using aleph instance logs with the --domain option.

For testing you can insert additional log entries using the systemd-cat command

echo 1 $(date)|systemd-cat -t vm-63faf8b5db1cf8d965e6a464a0cb8062af8e7df131729e48738342d956f29ace-stdout

or

for ((i=1; i<=400; i++));
do
 echo $i
 echo $i |systemd-cat -t vm-63faf8b5db1cf8d965e6a464a0cb8062af8e7df131729e48738342d956f29ace-stdout
 sleep 1
done

Log server side can be checked using

journalctl -t vm-63faf8b5db1cf8d965e6a464a0cb8062af8e7df131729e48738342d956f29ace-stderr -t vm-63faf8b5db1cf8d965e6a464a0cb8062af8e7df131729e48738342d956f29ace-stdout -f

For reproducing or debugging issues adding an asyncio.sleep(0.2) inside the websocket handling code
usually helps, most inner loop of stream_logs method inside src/aleph/vm/orchestrator/views/operator.py

[codecov]

Codecov Report

Attention: Patch coverage is 75.67568% with 9 lines in your changes missing coverage. Please review.

Project coverage is 63.07%. Comparing base (c2ad82a) to head (7a50834).
Report is 6 commits behind head on main.

Files with missing lines	Patch %	Lines
src/aleph/vm/utils/logs.py	72.00%	7 Missing ⚠️
tests/supervisor/test_log.py	81.81%	1 Missing and 1 partial ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main     #736      +/-   ##
==========================================
+ Coverage   62.81%   63.07%   +0.25%     
==========================================
  Files          70       71       +1     
  Lines        6314     6334      +20     
  Branches      516      517       +1     
==========================================
+ Hits         3966     3995      +29     
+ Misses       2190     2179      -11     
- Partials      158      160       +2     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.