Audit Logging 

Bitbucket provides an audit log which allows tracking authentication related events with built-in functionality already.
To enable audit logging for authentication events, you need to set the Coverage level for the Security category to Full.

Audit-logging authentication events can lead to a rapidly growing audit log database table and might cause performance issues.
Please be careful and monitor your instance for any negative impact.

Logfile

You can still see a record in the regular log file.
Messages are logged on INFO level and from de.resolution.apitokenauth.platform.auth.ApiTokenAuthSharedBase


Please refer to this article to see how to change the log level in a persistent way.

You'll then see the below authentication-related entries in the log file. These entries contain:

  • a description of the event
  • the token description (if applicable for the event)
  • the token scope (if applicable for the event) 
  • the username
  • the path of the REST endpoint for the call

Successful Authentication

2021-01-07 08:52:38,540 INFO [http-nio-8080-exec-2] @A6X2OXx532x2669x0 79.209.73.23,100.120.0.11 "GET /rest/ssh/1.0/keys HTTP/1.1" d.r.a.p.auth.ApiTokenAuthSharedBase Found a matching token "API Token from 2021-01-06" with Read Only scope and authenticated user automation-user. Token was created on Jan 6, 2021 2:14:46 PM. REST endpoint: /rest/ssh/1.0/keys

Failed Authentication Attempts

Only if basic authentication with a regular password is disabled in the app settings, it's safe to tell if a token provided was wrong, causing the below message in the log file:

2021-01-07 09:16:33,541 INFO [http-nio-8080-exec-10] @16JTB8Nx556x10x0 79.209.73.23,100.120.0.11 "GET /rest/ssh/1.0/keys HTTP/1.1" d.r.a.p.auth.ApiTokenAuthSharedBase Token verification for user automation-user failed: No valid API token was provided and basic auth with password or personal access token is disabled. REST endpoint: /rest/ssh/1.0/keys


Another reason for a failed authentication attempt might be an IP restriction:

2021-01-07 09:22:04,950 INFO [http-nio-8080-exec-1] @16JTB8Nx562x42x0 79.209.73.23,100.120.0.11 "GET /rest/ssh/1.0/keys HTTP/1.1" d.r.a.p.auth.ApiTokenAuthSharedBase Token verification for user auomation-user failed: IP address 79.209.73.23 of request is not allowed to access the REST API and basic auth with password or personal access token is disabled. REST endpoint: /rest/ssh/1.0/keys

If basic authentication with a regular password or personal access tokens is enabled, it might still be a valid password (or personal) access token which is accepted by the Bitbucket authenticator. Hence, the log message reads like this:

2021-01-07 11:02:37,820 INFO [http-nio-8080-exec-2] @16JTB8Nx662x69x0 79.209.73.23,100.120.0.11 "GET /rest/ssh/1.0/keys HTTP/1.1" d.r.a.p.auth.ApiTokenAuthSharedBase User automation-user tried to authenticate with an invalid token or regular password. Passing the request further to the default authenticator. REST endpoint: /rest/ssh/1.0/keys

Permission Denied Events

If a token with a "Read Only" scope is used during a write operation, a 403 error is returned as REST response and leaving a log file entry like the below.

2021-01-07 12:06:02,366 INFO [http-nio-8080-exec-9] @16JTB8Nx726x114x0 79.209.73.23,100.120.0.11 "POST /rest/ssh/1.0/keys HTTP/1.1" d.r.a.p.auth.ApiTokenAuthSharedBase Token verification for automation-user user failed: The token scope is read-only and only covers GET, HEAD and OPTIONS requests. Request method type was POST. REST endpoint: /rest/ssh/1.0/keys

Rate Limited Requests

If rate-limiting is enabled, logging the package de.resolution.apitokenauth.platform.auth.ApiTokenRateLimiter on INFO level provides the below record in the log file. This has been added in version 1.9.4.

2022-02-08 13:42:51,024 INFO  [http-nio-8080-exec-8] @MKNCWMx822x1697x0 kpe4a4 79.209.73.23,100.100.0.45 "GET /rest/ssh/1.0/keys HTTP/1.1" d.r.a.p.auth.ApiTokenRateLimiter User admin has been rate limited. The API token allows executing 5 requests within 5 minutes.