Constant "Invalid session" errors in client

Troubleshooting
1

Summary
Server log contains Invalid session messages constantly (every couple of seconds)

Steps to reproduce
No idea how to reproduce. Seen on various versions, currently 7.8.4.

Expected behavior
A way to track down the reason for this appearing and eliminate it from the log spam

Observed behavior
Example:

info  [2023-07-28 13:05:49.397 +10:00] Invalid session                               caller="web/handlers.go:277" error="GetSession: Invalid session token=None, err="
warn  [2023-07-28 13:05:49.924 +10:00] Error while creating session for user access token caller="app/session.go:90" error="createSessionForUserAccessToken: Invalid or missing token., resource: UserAccessToken id: token=None"

This pattern repeats every couple of seconds or so, all the time.

Is there a way to track down why this is happening and eliminate it from the log spam?

2

I managed to get some insight here by looking at the source code, and logging requests directly in the proxy.

  1. token=None is relevant here - it’s logging that a request was received with the auth token set to the literal string None. That strongly implies a python client printing an auth header token string, from a None value.
  2. Logging the Authorization header on all incoming requests to the proxy did reveal cases of a user setting Authorization: Bearer None on their incoming webhook posts, leading to this error.

I think we could make this easier to track down by including the following in the logging:

  • the full request path
  • where the token was found (header or cookie)

In theory the full request path is logged, but it’s a debug log line and is from a defer call. With the server being so busy, the later deferred debug log line was mixed up with all the other requests constantly happening and I could not associate one with the other. Putting the details directly in the logged message would help.