Skip to content

hostagent: don't fsync every log record - #5418

Open
chrisanderton wants to merge 1 commit into
lima-vm:masterfrom
chrisanderton:fsync-drop
Open

hostagent: don't fsync every log record#5418
chrisanderton wants to merge 1 commit into
lima-vm:masterfrom
chrisanderton:fsync-drop

Conversation

@chrisanderton

@chrisanderton chrisanderton commented Aug 17, 2026

Copy link
Copy Markdown

syncWriter calls Sync() after every write to the hostagent log. This change removes syncWriter in its entirety.

Once removed, hostagent writes to the log file directly (this reverts 722b7d1 - the rationale for which wasn't stated at the time so I cannot be sure of intent).

The processes that read the logs run on the same host as the hostagent. They see writes through the page cache whether or not the writes are synced. The data also survives the death of the hostagent process. Only a power loss
or a kernel panic can lose data that is not synced.

logrus holds its output mutex across Out.Write. Each record therefore held that mutex for the time of one fsync. This limited all logging in the hostagent process to about 240 records a second on my local machine.

The gRPC port forwarder writes several debug records for each tunnel that closes. A burst of closed connections puts thousands of records in the queue. Every other goroutine that logs must wait. This includes the callback for
guest agent events, which GuestAgentClient.Events calls inline on the only event-receive loop. While that callback waits, the host does not read events. The host therefore does not publish the next forwarded port until the queue
drains.

Measurements

Host: macOS 14.8.5, Apple Silicon, vz driver, APFS.

Reproduction from #5410.

Build Time until the new port accepts Records written
v2.2.0 as released 11,050 ms 3,214
With this change 208 ms 3,211

A microbenchmark writes the same records to a file:

Method Rate
Write and fsync each record 242 lines/s
Write only 709,143 lines/s

Alternative

Given the initial intent of 722b7d1 is not clear, an alternative is to keep the flush and limit it to one per x ms instead. In the same benchmark conditions with a 100ms flush, it measures 553,599 lines/s.

Assisted-by: Codex and Claude

@chrisanderton
chrisanderton marked this pull request as ready for review August 17, 2026 16:48
@AkihiroSuda

Copy link
Copy Markdown
Member

Please rebase to pass the CI

@AkihiroSuda AkihiroSuda added this to the v2.3.0 milestone Aug 21, 2026
The sync is unnecessary: the log is read by other processes on the same
host, which see writes through the page cache whether synced or not.

Fixes lima-vm#5410

Signed-off-by: Chris Anderton <chris@cga.io>
@chrisanderton

Copy link
Copy Markdown
Author

Please rebase to pass the CI

Rebased onto master. The two remaining failures look unrelated to this change:

Windows tests (QEMU) - teardown fails to remove cidata.iso ("being used by another process"). This also fails on master, e.g. run 32467979330 on 626c8dc.

Windows tests (WSL2) - "The wsl2 driver process seems already stopped" and no /var/log/cloud-init-output.log, so the guest never booted. The hostagent itself was healthy throughout (Time sync entries every 10s until the timeout), and the diagnostic dump of ha.stdout.log shows the status events were written and readable. Happy to look further if you'd rather re-run it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants