Close workflow audit log writers - #6110
Conversation
jerm-dro
left a comment
There was a problem hiding this comment.
Thanks for taking this on — the diagnosis and the design are right. Retaining the writer, factoring out the shared close helper, and catching the stdout trap rather than inheriting it are all exactly what #6094 asked for, and putting the auditor's lifecycle on coreVMCP (next to stopStore and healthMonitor) is the correct owner.
Two blockers, both mechanical, both about the tests rather than the fix:
- The two stdout tests pass against the unfixed code —
os.Stdout.Close()returnsnil, sorequire.NoErrorcan't distinguish fixed from broken. As written they'd stay green if the guard were removed. - The
coreVMCPchange is the code that actually plugs the leak, and it has no coverage — including the threeNewerror paths.
Details and suggested code in the line comments.
46bd4b0 to
812b3ed
Compare
|
Addressed the two mechanical blockers in Changes:
Local verification:
I also started |
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #6110 +/- ##
==========================================
- Coverage 78.98% 78.91% -0.07%
==========================================
Files 782 782
Lines 78065 78093 +28
==========================================
- Hits 61658 61629 -29
- Misses 16402 16459 +57
Partials 5 5 ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
|
Follow-up on the local
I re-ran both failures in isolation and at package scope with the same race/ldflags shape, and they passed:
So I don't see evidence that those two full-suite failures are caused by the workflow-auditor close changes. |
812b3ed to
17d4e5b
Compare
|
Added one more focused core close-path regression in The new subtest pre-closes the retained workflow auditor and then calls Verification:
|
jerm-dro
left a comment
There was a problem hiding this comment.
Both original blockers are resolved — verified locally against 17d4e5ba: the stdout tests now observe the descriptor (they fail against unfixed code, which was the whole point), and TestNew_CloseReleasesWorkflowAuditLogFile passes. Thanks for going further than asked on the error paths and the close-error branch.
One remaining issue, on the new /proc/self/fd helper — details in the line comment. It's a test portability problem, not a problem with your fix; the fix itself behaves correctly on macOS. Everything else looks good.
|
Addressed in Local verification on Linux: PATH=/tmp/go1.26/bin:$PATH go test -ldflags=-extldflags=-Wl,-w -v ./pkg/vmcp/core -run 'TestNew_ErrorPathsCloseWorkflowAuditLogFile|TestNew_CloseReleasesWorkflowAuditLogFile' -count=1Result: PASS ( Note: full |
8f1f426 to
f8b41d9
Compare
|
Refreshed this PR branch onto current No code changes beyond the existing two PR commits; this was a rebase-only maintenance update to keep the branch current after upstream moved. Local verification in this cron environment: git diff --check origin/main..HEAD
# passed
git log --format='%h %s%n%b' origin/main..HEAD
# f8b41d9e Guard Linux-only fd test helper
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
# ab2f7aa7 Close workflow audit log writers
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>I attempted to re-run the previous focused Go checks, but this cron shell currently resolves GitHub CI has been triggered on the refreshed branch; I will rely on those current CI results for the full ToolHive task/test/lint matrix. |
|
Current rebase CI has finished successfully on Follow-up status:
Local evidence from the rebase environment is still the same as above:
I think this is ready for re-review when you have a chance. |
f8b41d9 to
79c345e
Compare
|
Refreshed this PR branch onto current No code changes beyond replaying the existing two PR commits on top of the current branch. Local verification in this cron environment: git diff --check origin/main..HEAD
# passed
git log --format='%h %s%n%b' origin/main..HEAD
# 79c345e8 Guard Linux-only fd test helper
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
# 7ed0068b Close workflow audit log writers
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>I also retried the previously focused Go checks, but this cron shell still resolves GitHub CI has been triggered for the refreshed head; I'll rely on that current CI matrix for Go/test/lint validation. |
|
Current refreshed head Status snapshot:
Local evidence from the rebase remains:
I believe this is ready for re-review now that the post-rebase CI is fully green. |
79c345e to
ed493c8
Compare
|
Refreshed this PR branch onto current No code changes beyond replaying the existing two PR commits on top of current upstream. This keeps the branch current while it is waiting on re-review for the previously addressed Local verification after the refresh: git diff --check origin/main..HEAD
# passed
PATH=/usr/local/go/bin:/root/go/bin:$PATH go test -ldflags=-extldflags=-Wl,-w -run 'Test(Auditor_CloseDoesNotCloseStdout|WorkflowAuditor_Close)$' ./pkg/audit
# ok github.com/stacklok/toolhive/pkg/audit 0.023s
PATH=/usr/local/go/bin:/root/go/bin:$PATH go test -run 'TestNew_(CloseReleasesWorkflowAuditLogFile|ErrorPathsCloseWorkflowAuditLogFile|ValidatesWorkflows)$' ./pkg/vmcp/core
# ok github.com/stacklok/toolhive/pkg/vmcp/core 0.092s
git log --format='%h %s%n%b' origin/main..HEAD
# ed493c812 Guard Linux-only fd test helper
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
# 195535102 Close workflow audit log writers
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>I also ran the repo-level lint task; it still fails before reaching this PR's touched files on the pre-existing gci findings in PATH=/usr/local/go/bin:/root/go/bin:$PATH task lint
# pkg/authserver/server/provider.go:391:1: File is not properly formatted (gci)
# pkg/authserver/server_impl.go:194:1: File is not properly formatted (gci)
# task: Failed to run task "lint": exit status 1GitHub CI has been retriggered on the refreshed head. |
JAORMX
left a comment
There was a problem hiding this comment.
Panel review of ed493c81286ef57c81184ebd8e3c989e3a165733 against main cdb04c94f2462553fc27572bc8db9bb88a0c3c78 and #6094.
Blocking — VMCP close discards the newly exposed audit-close failure
pkg/vmcp/core/core_vmcp.go:559-573 logs a workflowAuditor.Close() error but always returns nil. That makes the newly owned file's close/flush failure unobservable to callers of the public VMCP.Close() error contract. Preserve the first close's error under sync.Once and return it; join it with any other teardown failure as appropriate, while retaining the documented nil result on later calls.
Blocking — constructor cleanup also loses audit-close failures
pkg/vmcp/core/core_vmcp.go:145-152 logs and discards a workflow-auditor close error on subsequent New failures (for example newWorkflowInstruments at :180-184). Return or join that cleanup error with the triggering construction error so neither cause is hidden.
The fix otherwise meets #6094's core goal: it retains the writer, avoids closing stdout/stderr, and covers the file-backed close path. Reuse and duplication reviewers found no additional issues.
ed493c8 to
c545425
Compare
|
Addressed the new close-error propagation blockers in What changed:
Local verification: export PATH=/usr/local/go/bin:/root/go/bin:$PATH
go version
# go version go1.26.5 linux/amd64
git diff --check origin/main..HEAD
# passed
go test -run 'TestNew_(CloseReleasesWorkflowAuditLogFile|ErrorPathsCloseWorkflowAuditLogFile|ValidatesWorkflows)$' ./pkg/vmcp/core
# ok github.com/stacklok/toolhive/pkg/vmcp/core 0.063s
go test -race -run 'TestNew_(CloseReleasesWorkflowAuditLogFile|ErrorPathsCloseWorkflowAuditLogFile|ValidatesWorkflows)$' ./pkg/vmcp/core
# ok github.com/stacklok/toolhive/pkg/vmcp/core 1.251s
go test -race ./pkg/vmcp/core -count=1
# ok github.com/stacklok/toolhive/pkg/vmcp/core 1.318s
golangci-lint run --allow-parallel-runners ./pkg/vmcp/core
# 0 issues.Repo-level lint was also attempted and is still blocked before this PR's touched package by the pre-existing/out-of-scope gci findings in task lint
# pkg/authserver/server/provider.go:391:1: File is not properly formatted (gci)
# pkg/authserver/server_impl.go:194:1: File is not properly formatted (gci)
# task: Failed to run task "lint": exit status 1GitHub CI has been retriggered on the pushed head and was queued at the time of this comment. |
|
Follow-up status on the pushed review-fix head
This is the same head from my previous comment that addressed the close-error propagation blockers; no additional code changes were made in this status-only follow-up. |
c545425 to
2a9c805
Compare
|
Refreshed this PR branch onto current No code changes beyond replaying the existing three PR commits on top of current upstream. Local verification after the refresh: git diff --check upstream/main..HEAD
# passed
export PATH=/usr/local/go/bin:/root/go/bin:$PATH
go version
# go version go1.26.5 linux/amd64
go test -ldflags=-extldflags=-Wl,-w -run 'Test(Auditor_CloseDoesNotCloseStdout|WorkflowAuditor_Close)$' ./pkg/audit
# ok github.com/stacklok/toolhive/pkg/audit 0.025s
go test -run 'TestNew_(CloseReleasesWorkflowAuditLogFile|ErrorPathsCloseWorkflowAuditLogFile|ValidatesWorkflows)$' ./pkg/vmcp/core
# ok github.com/stacklok/toolhive/pkg/vmcp/core 0.072s
go test -race ./pkg/vmcp/core -count=1
# ok github.com/stacklok/toolhive/pkg/vmcp/core 1.305s
golangci-lint run --allow-parallel-runners ./pkg/audit ./pkg/vmcp/core
# 0 issues.I also attempted the repo-level Taskfile lint: task lint
# task: [lint] golangci-lint run --allow-parallel-runners ./...
# task: Failed to run task "lint": exit status 137So full repo lint was blocked by the runner killing the repo-wide |
|
Follow-up on the current red CI after the refresh to
I re-ran the relevant local evidence on the current PR head: PATH=/usr/local/go/bin:/root/go/bin:$PATH go test -v -race ./pkg/audit ./pkg/vmcp/core
# pkg/audit passed; pkg/vmcp/core also passed when run without the CI ldflags below.
PATH=/usr/local/go/bin:/root/go/bin:$PATH go test -v -race ./pkg/vmcp/core
# ok github.com/stacklok/toolhive/pkg/vmcp/core 1.299s
PATH=/usr/local/go/bin:/root/go/bin:$PATH go test -v -race ./pkg/vmcp/server -run '^TestForwarding_Logging_RealBackend$' -count=1
# ok github.com/stacklok/toolhive/pkg/vmcp/server 31.305s
git diff --check HEAD~3..HEAD
# passedOne local environment note: the repo |
2a9c805 to
7e11c57
Compare
|
Refreshed this PR branch onto current No code changes beyond replaying the existing three PR commits on top of upstream. This should also rerun the previously red Local validation on this runner: git rebase origin/main
git diff --check origin/main..HEAD
Current GitHub status after the push: checks have started on |
|
CI/status follow-up for the rebased head
Command evidence: gh pr checks 6110 --repo stacklok/toolhive
# all listed checks returned pass, including Tests / Test Go Code and Linting / Lint Go Code
gh pr view 6110 --repo stacklok/toolhive --json mergeable,mergeStateStatus,reviewDecision
# mergeable=MERGEABLE, mergeStateStatus=BLOCKED, reviewDecision=CHANGES_REQUESTEDNo new code changes in this follow-up; this is just the completed CI snapshot after the branch refresh. |
|
Follow-up validation for the current head
Local validation from this branch: I also attempted the repo-preferred targeted command: That failure was local toolchain setup only: the existing GitHub check-runs on |
Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
7e11c57 to
11f3a31
Compare
|
Refreshed this PR branch onto current No code changes beyond replaying the existing three PR commits on top of upstream; DCO sign-offs are preserved. Local verification after the refresh: git diff --check upstream/main..HEAD
# passed
git log --format='%h %s%n%b' upstream/main..HEAD
# 11f3a315 Return workflow auditor close errors
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
# f5fcfa11 Guard Linux-only fd test helper
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
# 005de1ec Close workflow audit log writers
# Signed-off-by: Emre K <110906681+kocaemre@users.noreply.github.com>
export PATH=/usr/local/go/bin:/root/go/bin:$PATH
go version
# go version go1.27.0 linux/amd64
go test ./pkg/vmcp/core ./pkg/audit
# ok github.com/stacklok/toolhive/pkg/vmcp/core 0.092s
# ok github.com/stacklok/toolhive/pkg/audit 0.133s
go test -race ./pkg/vmcp/core -count=1
# ok github.com/stacklok/toolhive/pkg/vmcp/core 1.281sRepo-preferred wrapper checks attempted: task test -- pkg/vmcp/core
# blocked during `task gen`: existing mockgen binary reports it was built with Go 1.26 while repo deps require Go 1.27
task lint
# blocked before package analysis: golangci-lint binary was built with Go 1.26 while the repo targets Go 1.27.0GitHub CI has been retriggered on the refreshed head; at the immediate snapshot the check rollup was queued (16 checks), with no failures reported yet. |
|
Current refreshed head Status snapshot:
Local evidence from the refresh remains:
No new code changes in this follow-up; this is the completed CI snapshot after the branch refresh. |
|
Sorry for taking so long to get back to this! Thanks for sticking with it and keeping the branch up to date. I'm going through the latest changes now, including the close-error handling from my last review. |
JAORMX
left a comment
There was a problem hiding this comment.
Thanks for sticking with this! The concerns from my previous review are addressed: the first core Close returns cleanup errors, later calls remain idempotent, and core construction failures preserve both the original error and any audit-close error. The descriptor tests and Linux-only guard are in place too.
I did a fresh pass over 11f3a31. There are two surrounding server-lifecycle cases we should fix in a follow-up PR: preserving core.Close errors in server-construction rollback, and ensuring workflows finish their final audit logging before the writer closes when graceful HTTP shutdown times out. These are worth addressing, but I don't think we should hold this focused leak fix for that broader lifecycle work.
All 42 GitHub checks are green. My local task test run exceeded its execution timeout, so I'm not counting that as a local pass.
Looks good to merge. Thanks!
Summary
Config.LogFileis set becauseNewWorkflowAuditoropens a log writer but the returned auditor does not retain or expose a way to close it.WorkflowAuditor.Close(), and close the optional workflow auditor fromcoreVMCP.Close()and core construction error paths.os.Stdout/os.Stderrwhen audit logging uses default output.Fixes #6094
Type of change
Test plan
task test)task test-e2e)task lint-fix)Manual testing:
PATH=/usr/local/go/bin:/root/go/bin:$PATH task lintPATH=/usr/local/go/bin:/root/go/bin:$PATH go test -race ./pkg/audit ./pkg/vmcp/corePATH=/usr/local/go/bin:/root/go/bin:$PATH go test ./pkg/vmcp/composerAPI Compatibility
v1beta1API, OR theapi-break-allowedlabel is applied and the migration guidance is described above.Changes
pkg/audit/auditor.gopkg/audit/workflow_auditor.goClose().pkg/audit/workflow_auditor_test.gopkg/vmcp/core/core_vmcp.goDoes this introduce a user-facing change?
No. This releases an internal audit log file descriptor when the workflow auditor owner is closed.