search

Talent-Catalog / talentcatalog

https://tctalent.org
GNU Affero General Public License v3.0
10 stars 4 forks source link

Expired JWT token errors #963

Open sadatmalik opened 3 months ago

sadatmalik commented 3 months ago

As a developer I want to understand why I am seeing so many of these errors logged And to resolve the underlying issue or improve logging So that I can see pertinent log information making it is easier to trouble shoot issues

2024-05-07 13:31:45.761 ERROR 27684 --- [nio-8080-exec-7] o.t.server.security.JwtTokenProvider : Expired JWT token 2024-05-07 13:31:45.763 ERROR 27684 --- [nio-8080-exec-8] o.s.w.s.m.StompSubProtocolHandler : Failed to send message to MessageChannel in session 9dde458e-9903-8f60-b455-2c64d6104aa5:Failed to send message to ExecutorSubscribableChannel[clientInboundChannel]; nested exception is org.springframework.security.access.AccessDeniedException: Access is denied 2024-05-07 13:31:51.537 ERROR 27684 --- [io-8080-exec-10] o.t.server.security.JwtTokenProvider : Expired JWT token 2024-05-07 13:31:51.539 ERROR 27684 --- [nio-8080-exec-3] o.s.w.s.m.StompSubProtocolHandler : Failed to send message to MessageChannel in session d5bbe918-3542-4e1c-0d9a-19781d7f3929:Failed to send message to ExecutorSubscribableChannel[clientInboundChannel]; nested exception is org.springframework.security.access.AccessDeniedException: Access is denied 2024-05-07 13:31:57.523 ERROR 27684 --- [nio-8080-exec-2] o.t.server.security.JwtTokenProvider : Expired JWT token 2024-05-07 13:31:57.524 ERROR 27684 --- [nio-8080-exec-1] o.s.w.s.m.StompSubProtocolHandler : Failed to send message to MessageChannel in session f0639373-36c3-a1c1-0973-fa33ba36413b:Failed to send message to ExecutorSubscribableChannel[clientInboundChannel]; nested exception is org.springframework.security.access.AccessDeniedException: Access is denied

sadatmalik commented 2 months ago

The issue seems related to a STOMP heartbeat occurring every 6 seconds (10 times per minute). To reproduce this:

  1. Leave a TC window open in your browser until the JWT token naturally expires (after 24 hours or 86400000ms).
  2. Once the token expires, the message begins logging in my local environment.
  3. Terminating the TC tab stops the logging.

For further local testing, I will:

  1. Change the JWT token expiration time to a shorter duration.
  2. Wait for a TC tab to have an expired JWT token.
  3. Reactivate the tab and check if the logging stops, which it should.

Proposed Solution: Stop the STOMP heartbeat for inactive or stale application tabs

camerojo commented 1 month ago

I think that the STOMP heartbeat does look like the issue here.

However there is another way that this might occur - to do with Spring's multicast functionality.

When a chat post is received by the Spring controller (ChatPublishApi), we store it in the database and then return a modified version of the post which is then multicast to all subscribers to that chat. This is all done using the @SendTo annotation on the controller method.

Under the hood this multicasting is supported by Spring's default message broker https://docs.spring.io/spring-framework/reference/web/websocket/stomp/handle-simple-broker.html

That message broker manages queued messages in memory. Theoretically when it gets an error trying to send on a websocket (eg because the token has expired) it should throw away the queue for that socket - rather than retrying. Maybe it already does that - but maybe not, and we need to add the logic to clear the queue for timed out websockets.