Log the user and project on the gitlab-sshd access line
What does this MR do and why?
Closes #879 (closed)
The access: finish line gitlab-sshd logs when a connection ends carries neither the user nor the project: meta is always {} and there is no username field. Three things cause it.
- Each command stores its
command.LogDatain its context under a key type of its own (logDataKey{},logData{},logInfo{}), and gitlab-sshd reads it back undersshd.logInfo{}, a type none of them uses, so the lookup never finds it.command.LogDataKeyalready exists for this andgit-lfs-transferuses it, but gitlab-sshd did not read it. - The line logs
metaandwritten_bytesonly. The username was part ofmetauntil it moved toLogData.Username, and nothing added it back. handleShellreturned the context it was given when a command failed, so a command that got past its access check and then failed logged none of what it had recorded, written bytes included.
The commits, each building and passing the suite and make lint on its own:
- gitlab-sshd reads and stores the log data under
command.LogDataKeyand dropssshd.logInfo{}. The key's doc comment now says commands must store their log data under it. From this commitgit-lfs-transfersessions get theirmeta. - discover stores it there too. The session test now checks the username survives
handleShell. git-upload-pack,git-receive-packandgit-upload-archivestore it there too. A new test runsgit-receive-packover a real SSH connection and checks themetaof theaccess: finishline.setupServerWithContexttakes extra request handlers so that test can answer/api/v4/internal/allowed.git-lfs-authenticatestores it there too. No per-package key type is left.- The line logs the username as
gl_user_name, the LabKit field gitlab-shell already uses for the username on its other log lines, somake validate-log-fieldsstays clean. It used to bemeta.username(!783 (merged)) until !832 (merged) moved it out ofLogMetadata; I log it at the top level under the LabKit name rather than putting it back undermeta, as the field standardisation in.gitlab/duo/mr-review-instructions.yamlasks. - A command that fails keeps its log data.
handleShellreturns the context holding the log data on its error path too.TestAccessFinishLogsCommandLogDatabecomes table-driven and gains a case whose Gitaly address does not exist.
Each test fails on the commit before the one that fixes it (output below).
Screenshots or screen recordings
The access: finish line for the same git-receive-pack session, before and after (from the test in the issue):
| Before | After |
|---|---|
"written_bytes":31,"meta":{} |
"gl_user_name":"alex-doe","written_bytes":31,"meta":{"project":"flightjs/Flight","root_namespace":"flightjs","project_id":1,"root_namespace_id":2} |
How to set up and validate locally
-
Run the tests this MR adds or changes:
go test ./internal/sshd/ ./internal/command/... -count=1 -
To see the line itself, save the test from the issue as
internal/sshd/access_finish_repro_test.goand rungo test ./internal/sshd/ -run TestAccessFinishRepro -count=1 -vonmainand on this branch.
What I ran
All of it in registry.gitlab.com/gitlab-org/gitlab-build-images/debian-trixie-golang-1.25:latest, the image the tests job uses for Go 1.25, on every commit of the branch:
make build,make verify,gofmt -s -l,go vetandgo test -count=1 ./...with the job's build tags (tracer_static tracer_static_jaeger continuous_profiler_stackdriver gssapi): pass.make lint(golangci-lint 2.12.2 against the emptysupport/lint_last_known_acceptable.txt): pass.
On the last commit, also:
go test -count=1 ./...with the same tags in the Go 1.26 and 1.27 images of the job's matrix (go1.26.7, go1.27.2): pass.make validate-log-fields:No deprecated logging field usages found.make test_race, as theracejob runs it, andgo test -race -count=30 -run 'TestAccessFinishLogsCommandLogData|TestHandleShell|TestExtractMetaDataFromContext' ./internal/sshd/: pass.nilawayat the version.gitlab-ci.ymlpins: no findings.
Each new or changed assertion, run against the commit before the one that makes it pass:
commit 1 (on main):
--- FAIL: TestExtractMetaDataFromContext
expected: command.LogData{Username:"alex-doe", WrittenBytes:0, Meta:command.LogMetadata{Project:"flightjs/Flight", RootNamespace:"flightjs", ProjectID:1, RootNamespaceID:2}}
actual : command.LogData{Username:"", WrittenBytes:0, Meta:command.LogMetadata{Project:"", RootNamespace:"", ProjectID:0, RootNamespaceID:0}}
commit 2 (without the discover change):
--- FAIL: TestHandleShell/parses_command
expected: "test-user"
actual : ""
--- FAIL: TestExecute (discover)
panic: interface conversion: interface {} is nil, not command.LogData
commit 3 (without the three Git command changes):
--- FAIL: TestAccessFinishLogsCommandLogData
expected: map[string]interface {}{"project":"flightjs/Flight", "project_id":1, "root_namespace":"flightjs", "root_namespace_id":2}
actual : map[string]interface {}{}
--- FAIL: TestAllowedAccess (uploadpack, receivepack, uploadarchive)
panic: interface conversion: interface {} is nil, not command.LogData
commit 4 (without the git-lfs-authenticate change):
--- FAIL: TestLfsAuthenticateRequests
panic: interface conversion: interface {} is nil, not command.LogData
commit 5 (without the gl_user_name field):
--- FAIL: TestAccessFinishLogsCommandLogData
expected: string("alex-doe")
actual : <nil>(<nil>)
commit 6 (without the handleShell change):
--- FAIL: TestAccessFinishLogsCommandLogData/the_command_fails_after_its_access_check
expected: "alex-doe"
actual : ""The branch sits on main at fcd1db8e, after !1595 (merged). It merges with !1597 (merged), the open merge request that touches discover.go and discover_test.go, without conflicts (git merge-tree).
MR acceptance checklist
Evaluate this MR against the MR acceptance checklist. It helps you analyze changes to reduce risks in quality, performance, reliability, security, and maintainability.