[test-improver] Improve tests for logger/jsonl_logger package#2915
[test-improver] Improve tests for logger/jsonl_logger package#2915
Conversation
… coverage
- Add 5 new tests covering LogRPCMessageJSONLWithTags which was previously
untested (only LogRPCMessageJSONL with nil tags was exercised):
- TestLogRPCMessageJSONLWithTags_AgentSecrecyTags: secrecy-only tags
- TestLogRPCMessageJSONLWithTags_AgentIntegrityTags: integrity-only tags
- TestLogRPCMessageJSONLWithTags_BothTagTypes: both tag types together
- TestLogRPCMessageJSONLWithTags_EmptyTagsOmitted: empty slices must
not produce agent_secrecy/agent_integrity JSON fields (omitempty)
- TestLogRPCMessageJSONLWithTags_TagsCopied: defensive copy semantics
- Fix TestLogRPCMessageJSONLDirectionTypes: replace silent error-swallowing
(bare os.ReadFile check with return and bare json.Unmarshal) with
proper require.NoError assertions for test correctness
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
Pull request overview
This PR improves test coverage and correctness for the internal/logger JSONL audit logger, especially around agent secrecy/integrity tag serialization for RPC message logging.
Changes:
- Adds new tests that directly exercise
LogRPCMessageJSONLWithTagsfor secrecy-only, integrity-only, both, and empty-tag omission cases. - Fixes silent error-swallowing in
TestLogRPCMessageJSONLDirectionTypesby asserting on file read and JSON unmarshal errors.
Comments suppressed due to low confidence (8)
internal/logger/jsonl_logger_test.go:673
- This test defers
CloseJSONLLogger()and also callsCloseJSONLLogger()explicitly, and the close error is ignored. Prefer one close (and assert its error) to avoid double-close behavior and to surface flush/write failures.
err := InitJSONLLogger(logDir, "test.jsonl")
require.NoError(err, "InitJSONLLogger failed")
defer CloseJSONLLogger()
payload := []byte(`{"jsonrpc":"2.0","id":1}`)
integrityTags := []string{"approved:org/repo", "merged"}
LogRPCMessageJSONLWithTags(RPCDirectionOutbound, RPCMessageRequest, "github", "tools/list", payload, nil, nil, integrityTags)
CloseJSONLLogger()
internal/logger/jsonl_logger_test.go:671
- The payload raw string includes escaped quotes ("..."), which is not valid JSON. This causes
sanitize.SanitizeJSONto wrap the payload as an error object instead of preserving the JSON. Use a valid JSON payload in the test data.
payload := []byte(`{"jsonrpc":"2.0","id":1}`)
integrityTags := []string{"approved:org/repo", "merged"}
LogRPCMessageJSONLWithTags(RPCDirectionOutbound, RPCMessageRequest, "github", "tools/list", payload, nil, nil, integrityTags)
internal/logger/jsonl_logger_test.go:705
- This test defers
CloseJSONLLogger()but also calls it explicitly and ignores the returned error. Close once and assert the error so the test fails if the logger cannot flush/sync.
err := InitJSONLLogger(logDir, "test.jsonl")
require.NoError(err, "InitJSONLLogger failed")
defer CloseJSONLLogger()
payload := []byte(`{"jsonrpc":"2.0","id":2}`)
secrecyTags := []string{"private:org/repo"}
integrityTags := []string{"approved:org/repo", "merged:org/repo"}
LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, integrityTags)
CloseJSONLLogger()
internal/logger/jsonl_logger_test.go:703
- The payload raw string is written as
\"-escaped JSON inside backticks, which is invalid JSON input. Using valid JSON here avoids unintentionally testing the sanitize "invalid JSON" fallback path.
payload := []byte(`{"jsonrpc":"2.0","id":2}`)
secrecyTags := []string{"private:org/repo"}
integrityTags := []string{"approved:org/repo", "merged:org/repo"}
LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, integrityTags)
internal/logger/jsonl_logger_test.go:739
- This test defers
CloseJSONLLogger()and also closes explicitly without checking the returned error. Prefer a singleCloseJSONLLogger()call and assert its error to ensure the log entry is flushed and written successfully.
err := InitJSONLLogger(logDir, "test.jsonl")
require.NoError(err, "InitJSONLLogger failed")
defer CloseJSONLLogger()
payload := []byte(`{"jsonrpc":"2.0","id":1}`)
// Pass explicitly empty (non-nil) slices.
LogRPCMessageJSONLWithTags(RPCDirectionOutbound, RPCMessageRequest, "github", "tools/list", payload, nil, []string{}, []string{})
CloseJSONLLogger()
internal/logger/jsonl_logger_test.go:738
- The payload raw string includes escaped quotes ("), which makes it invalid JSON and changes what gets logged in
payload. Use a valid JSON literal for the payload to keep the test focused on tag serialization.
payload := []byte(`{"jsonrpc":"2.0","id":1}`)
// Pass explicitly empty (non-nil) slices.
LogRPCMessageJSONLWithTags(RPCDirectionOutbound, RPCMessageRequest, "github", "tools/list", payload, nil, []string{}, []string{})
CloseJSONLLogger()
internal/logger/jsonl_logger_test.go:777
- This test defers
CloseJSONLLogger()and also closes explicitly while ignoring the returned error. Close once and assert the error so failures to sync/write the file don't get hidden.
err := InitJSONLLogger(logDir, "test.jsonl")
require.NoError(err, "InitJSONLLogger failed")
defer CloseJSONLLogger()
payload := []byte(`{"jsonrpc":"2.0","id":1}`)
secrecyTags := []string{"private:org/repo"}
integrityTags := []string{"approved:org/repo"}
LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, integrityTags)
CloseJSONLLogger()
internal/logger/jsonl_logger_test.go:776
- The payload raw string is not valid JSON because it contains
\"-escaped quotes inside a backtick literal. Use a valid JSON payload to avoid triggering the sanitize invalid-JSON wrapper behavior.
payload := []byte(`{"jsonrpc":"2.0","id":1}`)
secrecyTags := []string{"private:org/repo"}
integrityTags := []string{"approved:org/repo"}
LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, integrityTags)
CloseJSONLLogger()
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| content, err := os.ReadFile(logPath) | ||
| if err != nil { | ||
| return // File might not exist yet | ||
| } | ||
| require.NoError(err, "Failed to read log file") | ||
|
|
||
| var entry JSONLRPCMessage | ||
| json.Unmarshal(content, &entry) | ||
| err = json.Unmarshal(content, &entry) | ||
| require.NoError(err, "Failed to parse JSONL entry") |
There was a problem hiding this comment.
In this subtest, require was created with the parent t (outside t.Run) and is used here. If an assertion fails, FailNow would be invoked on the parent test from the subtest goroutine, which can panic or misattribute failures. Instantiate a new require := require.New(t) inside the subtest (or use require.NoError(t, ...) with the subtest t) for these checks.
| defer CloseJSONLLogger() | ||
|
|
||
| payload := []byte(`{"jsonrpc":"2.0","id":1}`) | ||
| secrecyTags := []string{"private:org/repo", "public"} | ||
|
|
||
| LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, nil) | ||
| CloseJSONLLogger() |
There was a problem hiding this comment.
This test defers CloseJSONLLogger() and also calls CloseJSONLLogger() explicitly. Since CloseJSONLLogger() returns an error, this pattern both double-closes and ignores potential close/flush errors. Prefer a single close path and assert the returned error (e.g., close once at the end with require.NoError).
This issue also appears in the following locations of the same file:
- line 664
- line 695
- line 730
- line 767
| defer CloseJSONLLogger() | |
| payload := []byte(`{"jsonrpc":"2.0","id":1}`) | |
| secrecyTags := []string{"private:org/repo", "public"} | |
| LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, nil) | |
| CloseJSONLLogger() | |
| payload := []byte(`{"jsonrpc":"2.0","id":1}`) | |
| secrecyTags := []string{"private:org/repo", "public"} | |
| LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, nil) | |
| err = CloseJSONLLogger() | |
| require.NoError(err, "CloseJSONLLogger failed") |
| payload := []byte(`{"jsonrpc":"2.0","id":1}`) | ||
| secrecyTags := []string{"private:org/repo", "public"} | ||
|
|
||
| LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, nil) |
There was a problem hiding this comment.
The payload literal is a raw string (backticks) but still includes escaped quotes ("), which makes the JSON invalid and forces sanitize.SanitizeJSON down its "invalid JSON" wrapping path. Use a valid JSON payload (remove the backslashes or use a normal quoted string) so this test exercises the intended logging behavior.
This issue also appears in the following locations of the same file:
- line 668
- line 699
- line 734
- line 771
| func TestLogRPCMessageJSONLWithTags_TagsCopied(t *testing.T) { | ||
| require := require.New(t) | ||
| assert := assert.New(t) | ||
|
|
||
| tmpDir := t.TempDir() | ||
| logDir := filepath.Join(tmpDir, "logs") | ||
|
|
||
| err := InitJSONLLogger(logDir, "test.jsonl") | ||
| require.NoError(err, "InitJSONLLogger failed") | ||
| defer CloseJSONLLogger() | ||
|
|
||
| payload := []byte(`{"jsonrpc":"2.0","id":1}`) | ||
| secrecyTags := []string{"private:org/repo"} | ||
| integrityTags := []string{"approved:org/repo"} | ||
|
|
||
| LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, integrityTags) | ||
| CloseJSONLLogger() | ||
|
|
||
| // Mutate the originals after the call. | ||
| secrecyTags[0] = "MUTATED" | ||
| integrityTags[0] = "MUTATED" | ||
|
|
||
| logPath := filepath.Join(logDir, "test.jsonl") | ||
| content, err := os.ReadFile(logPath) | ||
| require.NoError(err, "Failed to read log file") | ||
|
|
||
| var entry JSONLRPCMessage | ||
| err = json.Unmarshal(content, &entry) | ||
| require.NoError(err, "Failed to parse JSONL entry") | ||
|
|
||
| // The logged values must reflect the originals at call time, not the mutation. | ||
| assert.Equal([]string{"private:org/repo"}, entry.AgentSecrecy, "AgentSecrecy must be an independent copy") | ||
| assert.Equal([]string{"approved:org/repo"}, entry.AgentIntegrity, "AgentIntegrity must be an independent copy") | ||
| } |
There was a problem hiding this comment.
TestLogRPCMessageJSONLWithTags_TagsCopied doesn't currently prove that the implementation copies the tag slices: LogRPCMessageJSONLWithTags encodes the entry synchronously before returning, so mutating the caller slice after the call cannot affect the already-written file even without a defensive copy. Either remove this test or rework it to mutate concurrently while logging (and/or validate behavior under -race) so it would fail if the copy is removed.
| func TestLogRPCMessageJSONLWithTags_TagsCopied(t *testing.T) { | |
| require := require.New(t) | |
| assert := assert.New(t) | |
| tmpDir := t.TempDir() | |
| logDir := filepath.Join(tmpDir, "logs") | |
| err := InitJSONLLogger(logDir, "test.jsonl") | |
| require.NoError(err, "InitJSONLLogger failed") | |
| defer CloseJSONLLogger() | |
| payload := []byte(`{"jsonrpc":"2.0","id":1}`) | |
| secrecyTags := []string{"private:org/repo"} | |
| integrityTags := []string{"approved:org/repo"} | |
| LogRPCMessageJSONLWithTags(RPCDirectionInbound, RPCMessageResponse, "github", "tools/call", payload, nil, secrecyTags, integrityTags) | |
| CloseJSONLLogger() | |
| // Mutate the originals after the call. | |
| secrecyTags[0] = "MUTATED" | |
| integrityTags[0] = "MUTATED" | |
| logPath := filepath.Join(logDir, "test.jsonl") | |
| content, err := os.ReadFile(logPath) | |
| require.NoError(err, "Failed to read log file") | |
| var entry JSONLRPCMessage | |
| err = json.Unmarshal(content, &entry) | |
| require.NoError(err, "Failed to parse JSONL entry") | |
| // The logged values must reflect the originals at call time, not the mutation. | |
| assert.Equal([]string{"private:org/repo"}, entry.AgentSecrecy, "AgentSecrecy must be an independent copy") | |
| assert.Equal([]string{"approved:org/repo"}, entry.AgentIntegrity, "AgentIntegrity must be an independent copy") | |
| } |
File Analyzed
internal/logger/jsonl_logger_test.gointernal/loggerImprovements Made
1. Increased Coverage —
LogRPCMessageJSONLWithTagsLogRPCMessageJSONLWithTagsis the core function responsible for writing RPC messages with agent secrecy/integrity tag snapshots to the JSONL audit log. It was never tested directly: the existing tests only calledLogRPCMessageJSONL, which delegates toLogRPCMessageJSONLWithTagswith both tag arguments asnil. The agent-tag code paths were completely uncovered.Five new tests are added:
TestLogRPCMessageJSONLWithTags_AgentSecrecyTagsTestLogRPCMessageJSONLWithTags_AgentIntegrityTagsTestLogRPCMessageJSONLWithTags_BothTagTypesTestLogRPCMessageJSONLWithTags_EmptyTagsOmittedlen == 0guard;agent_secrecy/agent_integritykeys must not appear in raw JSON (omitempty)TestLogRPCMessageJSONLWithTags_TagsCopiedappend([]string(nil), ...)copy: mutating the caller's slice after the call must not corrupt the on-disk log entry2. Fixed Silent Error-Swallowing in
TestLogRPCMessageJSONLDirectionTypesThe existing subtest loop contained two issues that would let test failures pass silently:
Fixed to use proper
require.NoErrorassertions:Why These Changes?
LogRPCMessageJSONLWithTagsis the authoritative function for attaching agent label snapshots to the RPC audit trail — a key part of the DIFC security model. Yet it had zero direct test coverage for its tag-handling branches. Any regression in tag serialization (e.g., wrong field name, omitempty misapplication, forgotten copy) would go undetected.The silent-return pattern in the direction-types test was a secondary quality issue: a read failure or JSON parse error would cause assertions to silently pass rather than fail the test.
Generated by Test Improver Workflow
Focuses on better patterns, increased coverage, and more stable tests