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.
A way to track down the reason for this appearing and eliminate it from the log spam
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?
I managed to get some insight here by looking at the source code, and logging requests directly in the proxy.
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
- 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.