Forward each sly-net-client log line once across restarts - #127
Draft
supervisely-integrations[bot] wants to merge 3 commits into
Draft
supervisely-integrations[bot] wants to merge 3 commits into
supervisely-integrations[bot] wants to merge 3 commits into
Conversation
added 3 commits
September 24, 2026 22:36
The net-client log reader re-read the container's whole docker log on every reconnect and attached another log handler each time, so every restart re-sent all historical lines (multiplied) to events.publish. Follow the stream with timestamps and resume from the last delivered line's timestamp (starting at agent start), and set up the net_client logger once. Refs supervisely/issues#6216
…played prefix Docker stamps stdout and stderr in separate goroutines, so a live stderr line (e.g. curl's error) can follow a stdout line with a later timestamp. The follower dropped every line older than its cursor, including such new lines; the timestamp filter now only applies until the stream has passed what was already delivered.
…al supervisor The Docker regression test called the reader body by hand and stopped at the agent's log queue. Run it under _run_daemon (the loop that reconnects after each net-client restart) and drain it with submit_log into a recorded Log RPC, the point where lines leave the agent for worker-api. Wait for delivered lines instead of sleeping, since docker's restart delay grows with each crash. Refs supervisely/issues#6216
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Resolves https://github.com/supervisely/issues/issues/6216
What Problem This Solves
When the sly-net-client container restarted or its log stream reconnected, the agent re-read the container's whole Docker log from the beginning and sent it to worker-api again. worker-api turned every replayed line into its own events.publish, so a net-client that restarts about once a minute flooded API. The agent now resumes from the last line it delivered, or from agent start if it has delivered nothing, so each line reaches worker-api once and new lines still arrive.
Why This Change Was Made
Two things caused the duplicates, and both are fixed.
logs(follow=True, stream=True)had nosince, so every reconnect started from the beginning of the log.task_stream_net_client_logsattached another TaskHandler and file handler on each re-entry from_run_daemon, so every line was sent once per past reconnect.The new
ContainerLogFollowerinagent_utils.pykeeps a cursor based on Docker's own log timestamps (timestamps=True). A time-based cursor still works when the container restarts or is recreated under the same name; a container-ID or byte-offset cursor would not. Docker'ssinceis inclusive and whole-second, so lines at or below the cursor are skipped only until the stream has passed what was already delivered. After that, a stderr line stamped slightly earlier than the stdout line before it is still delivered. Docker stamps stdout and stderr separately, so these lines are new and must not be dropped. With no cursor yet, the start point is the agent's start time, so history from before this agent is never forwarded. The net_client logger is now set up once.This continues the existing branch
agent/6216-work(c90032d, 99ae435, a813723) as the human asked. This round added no new commits: the branch was re-verified and handed off.User Impact
Agents that include this fix stop re-sending old sly-net-client log lines to worker-api on every net-client restart. The events.publish storm on API from a crash-looping net-client goes away. After an agent restart, net-client lines logged before that agent started are no longer forwarded. No configuration or migration is needed. It does not fix the stand-specific trigger (sly-net-server missing on sergey-dev), which is a deployment problem.
Evidence
pytest -q tests/test_net_client_logs.py -k restartingon a real Docker 28.3.3 daemon with a busybox net-client that crashes every second (restart=always), under the agent's real_run_daemon, drained bysubmit_loginto a recordedLogRPC. Result: FAILED. 15 lines were delivered more than once (Left contains 15 more items, first extra item: 'line-ad0609f5-...').pytest -q tests/test_net_client_logs.py tests/test_run_daemon.py→ 17 passed in 11.95s. This includes unit tests for: reconnect exactly-once, lines sharing a timestamp across a reconnect, out-of-order stderr lines, multibyte text split across chunks, and timestamp parsing.pytest -q tests(whole directory) fails at collection withKeyError: 'ACCESS_TOKEN'from tests/clean_functions and the import order that follows. It fails the same way on the pre-fix commit c78a8e2, so it was already broken and this change did not cause it.a81372305967in a fresh checkout.LoggRPC call to worker-api, which is where lines leave the agent. I did not measure events.publish counts on API; If the stream reconnects and a genuinely new stderr line carries a timestamp earlier than the cursor and arrives before the first line past the cursor, it is dropped. This only happens with interleaving within the same few microseconds at a reconnect; The Docker regression test skips itself when no Docker daemon is reachable or busybox:1.36 cannot be pulled; Running the whole tests/ directory in one pytest call was already broken (tests/clean_functions needs ACCESS_TOKEN at import), so the replay names the two test files explicitly; The deployment trigger (sly-net-server missing from sergey-dev) is a separate problem and was not changed here.