Skip to content

Emit Audit Log Trail on Session Reject#62384

Open
21KennethTran wants to merge 6 commits intomasterfrom
kennethtran/ip-pinning-audit
Open

Emit Audit Log Trail on Session Reject#62384
21KennethTran wants to merge 6 commits intomasterfrom
kennethtran/ip-pinning-audit

Conversation

@21KennethTran
Copy link
Copy Markdown
Contributor

@21KennethTran 21KennethTran commented Dec 18, 2025

Currently, when the Authorizer rejects a connection (e.g., due to IP pinning), the Auth Server returns a gRPC error to the client but does not emit an audit event.

Added an auditing block within authz.Authorizer. This ensures that any trace.AccessDenied error returned when an authorization attempt fails is captured and emitted as a AuthAttemptFailure (T3007W) event.

Addresses #48123

Recreation Steps for IP Pinning (Local):

// create alias for local computer
sudo ifconfig lo0 alias 192.168.250.250

// login
tsh login --insecure --proxy=192.168.250.250:443 --auth=local --user=testuser --mfa-mode=otp

// delete the ipv6 loopback translation on Mac
sudo ifconfig lo0 inet6 ::1 delete

// try to tsh ssh; should get IP pinning error
tsh ssh --insecure --proxy=localhost:443 --user=testuser root@Kenneths-MacBook-Pro.local 

// add ipv6 loopback translation before logging in to test again
sudo ifconfig lo0 inet6 ::1 add

Note: With these changes, we now see multiple of these Session Rejected Events with the same contents, instead of just one. If we look at the usermessage of each of these events, we now see the individual RPC calls that are being called/rejected.

image
{
  "addr.remote": "127.0.0.1:58152",
  "cluster_name": "localhost",
  "code": "T3007W",
  "ei": 0,
  "error": "pinned IP doesn't match observed client IP",
  "event": "auth",
  "message": "access denied to method /proto.AuthService/CreateAuthenticateChallenge: pinned IP doesn't match observed client IP",
  "server_id": "",
  "server_version": "19.0.0-dev",
  "success": false,
  "time": "2026-02-09T17:18:04.791Z",
  "uid": "b6917ed4-7655-4cac-97e0-01b81200d30a",
  "user": "testuser"
}

{
  "addr.remote": "127.0.0.1:58157",
  "cluster_name": "localhost",
  "code": "T3007W",
  "ei": 0,
  "error": "pinned IP doesn't match observed client IP",
  "event": "auth",
  "message": "access denied to method /proto.AuthService/GetSSHTargets: pinned IP doesn't match observed client IP",
  "server_id": "",
  "server_version": "19.0.0-dev",
  "success": false,
  "time": "2026-02-09T17:18:04.795Z",
  "uid": "fb48c72d-91d0-47cc-b3a2-e100d6e35e75",
  "user": "testuser"
}

When failing a session due to locks:
image

{
  "addr.remote": "[::1]:57483",
  "cluster_name": "localhost",
  "code": "T3007W",
  "ei": 0,
  "error": "lock targeting User:\"testuser\" is in force: locking testuser",
  "event": "auth",
  "message": "access denied to method /proto.AuthService/CreateAuthenticateChallenge: lock targeting User:\"testuser\" is in force: locking testuser",
  "server_id": "",
  "server_version": "19.0.0-dev",
  "success": false,
  "time": "2026-02-09T17:06:56.645Z",
  "uid": "46775862-a13c-4824-87f0-be646fffe3ae",
  "user": "testuser"
}

{
  "addr.remote": "[::1]:57487",
  "cluster_name": "localhost",
  "code": "T3007W",
  "ei": 0,
  "error": "lock targeting User:\"testuser\" is in force: locking testuser",
  "event": "auth",
  "message": "access denied to method /proto.AuthService/GetSSHTargets: lock targeting User:\"testuser\" is in force: locking testuser",
  "server_id": "",
  "server_version": "19.0.0-dev",
  "success": false,
  "time": "2026-02-09T17:06:56.65Z",
  "uid": "9404d249-d9f6-4a56-8ef1-b9ae737508d1",
  "user": "testuser"
}

Test Plan

  • Locks
  • tsh login as testuser with access privileges to ssh onto a server
  • Create a lock targeting testuser
  • Attempt to tsh ssh onto a server
  • We should now see the two audit logs described above
    • Locks with database
    • Attempt to tsh db login to postgres database, and we should observe 1 audit log
    • "message": "access denied to method /proto.AuthService/ListResources: lock targeting User:\"testuser\" is in force: locking testuser"
  • IP Pinning
  • Follow recreation steps above, we should now see those two audit logs above as well
    • IP Pinning with database
    • Attempt to tsh db login after deleting ipv6 loopback, then we should also observe 1 audit log
    • IP Pinning with Kubernetes
    • tsh kube login, then delete ipv6 loopback, then kubectl get pods should give us 5 audit logs
  • Device Trust
  • Start Teleport with auth_service.device_trust.mode: off, then tsh login
  • Restart Teleport with auth_service.device_trust.mode: off
    • tsh ssh should reject session and leave an audit log
    • tsh app login should not reject session and should not leave audit log (global device trust does not affect app access unless user roles target the app)

@21KennethTran 21KennethTran requested a review from zmb3 December 18, 2025 23:47
Comment thread lib/auth/grpcserver.go Outdated
@21KennethTran 21KennethTran force-pushed the kennethtran/ip-pinning-audit branch from ac9cef1 to d6a2a61 Compare December 24, 2025 00:56
@21KennethTran 21KennethTran marked this pull request as ready for review January 5, 2026 17:25
Copy link
Copy Markdown
Collaborator

@zmb3 zmb3 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can confirm I'm now seeing auth attempt failures for things like IP pinning and device trust:

Image

I'm also seeing some new events for things I can't explain:

Image

These seem to happen when I tsh ssh zmb@host as Teleport user zac. I'm struggling to understand why I'm seeing activity from other users (admin, zac5, root-admin, and leaf-admin).

(Note: I'm sure you didn't introduce this behavior and it's just an artifact of the new audit logging, but I"d like to understand it)

Comment thread lib/auth/grpcserver.go Outdated
Comment thread lib/auth/grpcserver.go Outdated
@21KennethTran
Copy link
Copy Markdown
Contributor Author

Hey @zmb3, @fspmarshall, @rudream, Apologies for the unresponsiveness. I would like to pick back up on this PR.

A change I have been working on is moving emitters to authz.Authorize, meaning that this change would touch any services/integrations we would like to capture audit events for that uses authz.NewAuthorizer. My latest commit touches on auditing failures for lib/service/db.go, but I am also working on test scenarios for desktop and kubernetes as well as initApps() and initProxyEndpoint.

Let me know if there are any concerns with having audit event emission here.

Comment thread lib/authz/permissions.go Outdated
defer func() {
if err != nil {
if a.emitter != nil {
if user, _ := UserFromContext(ctx); user != nil {
Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Style nit - the more levels of nesting you create, the harder the code is to read.

We can use several techniques to improve this.

  1. Combine the if statements.

Instead of:

if foo {
    if bar {
        // stuff
    }
}

We can do:

if foo && bar {
    // stuff
}
  1. Invert the conditions and return early. This keeps the happy path left-aligned.
if err == nil || emitter == nil {
    return // nothing we can do
}

user, _ := UserFromContext()
if user == nil {
    return
}

Comment thread lib/authz/permissions.go Outdated
methodName = "unknown"
}

userMsg := fmt.Sprintf("access denied to method %s: %s", methodName, errorMsg)
Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
userMsg := fmt.Sprintf("access denied to method %s: %s", methodName, errorMsg)
userMsg := fmt.Sprintf("authorization failed for method %s: %s", methodName, errorMsg)

Copy link
Copy Markdown
Contributor

@fspmarshall fspmarshall left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I worry we might have a case of misleading naming here. A lot of what the Authorize method does isn't really authorization. And also I worry that we're setting ourselves up for serious event spam if we just bracket this entire method in a catch-all failure event. Have you considered a more targeted approach?

Comment thread lib/authz/permissions.go Outdated
Comment on lines +415 to +447
defer func() {
if err != nil {
err = a.convertAuthorizerError(err)
user, _ := UserFromContext(ctx)
if user == nil {
return
}

identity := user.GetIdentity()
username := identity.Username

// Filter out failures caused by system components so that we only audit events for real users or bots
if len(identity.SystemRoles) == 0 {
errorMsg := trace.UserMessage(err)
if errorMsg == "" {
errorMsg = err.Error()
}

methodName, _ := grpc.Method(ctx)
if methodName == "" {
// If no gRPC method is found in the context, attempt to get the request method from the context
// (e.g. for kube requests). If that also fails, default to "unknown".
if val := GetRequestMethod(ctx); val != "" {
methodName = val
} else {
methodName = "unknown"
}
}

userMsg := fmt.Sprintf("authorization failed for method %s: %s component %s", methodName, errorMsg, a.TEST)

event := &apievents.AuthAttempt{
Metadata: apievents.Metadata{
Type: events.AuthAttemptEvent,
Code: events.AuthAttemptFailureCode,
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Indentation appears pretty messed up here. And seems to be missing control flow that I'd assume some of this indentation aught to be related to, like I'd expect some of this to be wrapped in an if err != nil block, but it isn't. Looks like maybe this was pasted incompletely from somewhere else and not formatted?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

My bad, I was testing some changes/logs and decided to commit part of them. Not sure why the lines and indentation were malformed, but should be corrected now.

@21KennethTran 21KennethTran force-pushed the kennethtran/ip-pinning-audit branch from 1300331 to c99ac75 Compare February 11, 2026 19:34
@21KennethTran 21KennethTran force-pushed the kennethtran/ip-pinning-audit branch from c99ac75 to 67059ad Compare February 11, 2026 20:38
@21KennethTran 21KennethTran force-pushed the kennethtran/ip-pinning-audit branch from 576fba4 to 2eedcdf Compare February 12, 2026 22:15
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants