Mail Handlers stop pulling new emails due to an infinite timeout used to fetch Oauth 2.0 tokens

Problem

Mail Handlers stop processing new incoming emails due to an infinite timeout value used to fetch a new Oauth 2.0 access token. Similar to JSDSERVER-12620: The JSM Mail Handlers (channels) stop pulling new emails due to an infinite timeout used to fetch Oauth 2.0 tokens but this Bug is for regular mail handlers

Environment

• Theoretically it affects all version of Jira which supports OAuth 2 for incoming mail. Investigation was done on 8.20.11.
• At least 1 Mail Handler configured using Oauth 2.0 as the authorization method for the bug to be replicable

Steps to Reproduce

This issue has not been replicated in our environment since, to replicate it, we would need to create some "network latency" at the right time to trigger the bug.
Even though the steps to replicate the issue are not fully identified, they should look like the ones listed below:

1. Install Jira
2. Create a project
3. Configure a Mail Handler in Settings > Incoming Mail using Oauth 2.0 as the authentication method as per this documentation
4. Verify that the Mail Handler is able to fetch incoming emails from the mailbox
5. Wait for about 1h
   • This is usually the time when the Oauth 2.0 Access token expires (for Gmail and Microsoft)
   • The Mail Handler Job will try to fetch a new Oauth 2.0 Access token, using the Oauth 2.0 Refresh token
6. Create some "network latency/interruption" that will prevent Gmail or Microsoft (depending on which Mail Server is used for the test) from sending a response back to the Mail Puller Job

Expected Results

The HTTP request sent by the Mail Handler job should eventually timeout, since no reply was sent back from the Mail Server, and the Mail Puller job should stop its own execution, until it is scheduled again 1 minute later.

Then, 1 minute later, it should try again to request an Oauth 2.0 Access Token, get a new one, and pull new emails again.

Actual Results

The HTTP request does not timeout.

As a result:

• the Mail Handler job never completes its own execution
• the Mail Handler gets completely stuck and is no scheduled anymore
• No new emails are fetched by any Mail Handlers configured in any projects
• Depending on the situation, all other services might also stop running because all 4 Caesium threads are stuck in their Mail Handler job

Diagnosis steps to identify this bug

• All mail handler stops processing emails. No specific error in the logs. Looks like the incoming mail logs just stop printing.
• Other services (eg. outgoing mail, etc) might not be working as well
• When collecting thread dumps while the issue is happening, we should see a long running Caesium thread with the following stack trace:

  "Caesium-1-1" #341 daemon prio=5 os_prio=0 cpu=6418578.13ms elapsed=365662.90s tid=0x000000004af71000 nid=0x18ec runnable  [0x00000000772bd000]
     java.lang.Thread.State: RUNNABLE
  	at java.net.SocketInputStream.socketRead0(java.base@11.0.13/Native Method)
  	at java.net.SocketInputStream.socketRead(java.base@11.0.13/Unknown Source)
  	at java.net.SocketInputStream.read(java.base@11.0.13/Unknown Source)
  	at java.net.SocketInputStream.read(java.base@11.0.13/Unknown Source)
  	at sun.security.ssl.SSLSocketInputRecord.read(java.base@11.0.13/Unknown Source)
  	at sun.security.ssl.SSLSocketInputRecord.readFully(java.base@11.0.13/Unknown Source)
  	at sun.security.ssl.SSLSocketInputRecord.decodeInputRecord(java.base@11.0.13/Unknown Source)
  	at sun.security.ssl.SSLSocketInputRecord.decode(java.base@11.0.13/Unknown Source)
  	at sun.security.ssl.SSLTransport.decode(java.base@11.0.13/Unknown Source)
  	at sun.security.ssl.SSLSocketImpl.decode(java.base@11.0.13/Unknown Source)
  	at sun.security.ssl.SSLSocketImpl.readApplicationRecord(java.base@11.0.13/Unknown Source)
  	at sun.security.ssl.SSLSocketImpl$AppInputStream.read(java.base@11.0.13/Unknown Source)
  	at java.io.BufferedInputStream.fill(java.base@11.0.13/Unknown Source)
  	at java.io.BufferedInputStream.read1(java.base@11.0.13/Unknown Source)
  	at java.io.BufferedInputStream.read(java.base@11.0.13/Unknown Source)
  	- locked <0x00000006aac28990> (a java.io.BufferedInputStream)
  	at sun.net.www.http.HttpClient.parseHTTPHeader(java.base@11.0.13/Unknown Source)
  	at sun.net.www.http.HttpClient.parseHTTP(java.base@11.0.13/Unknown Source)
  	at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(java.base@11.0.13/Unknown Source)
  	- locked <0x00000006a814f0a0> (a sun.net.www.protocol.https.DelegateHttpsURLConnection)
  	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(java.base@11.0.13/Unknown Source)
  	- locked <0x00000006a814f0a0> (a sun.net.www.protocol.https.DelegateHttpsURLConnection)
  	at sun.net.www.protocol.https.HttpsURLConnectionImpl.getInputStream(java.base@11.0.13/Unknown Source)
  	- locked <0x00000006a814f190> (a sun.net.www.protocol.https.HttpsURLConnectionImpl)
  	at com.nimbusds.oauth2.sdk.http.HTTPRequest.send(HTTPRequest.java:899)
  	at com.atlassian.oauth2.client.lib.token.DefaultTokenService.getToken(DefaultTokenService.java:139)
  	at com.atlassian.oauth2.client.lib.token.DefaultTokenService.forceRefresh(DefaultTokenService.java:71)
  	at com.atlassian.oauth2.client.storage.DefaultTokenHandler.refreshToken(DefaultTokenHandler.java:144)
  	at com.atlassian.oauth2.client.storage.DefaultTokenHandler.refreshTokenIfNeeded(DefaultTokenHandler.java:131)
  	at com.atlassian.oauth2.client.storage.DefaultTokenHandler.lambda$getRefreshedToken$1(DefaultTokenHandler.java:110)
  	at com.atlassian.oauth2.client.storage.DefaultTokenHandler$$Lambda$3405/0x0000000803cb3c40.call(Unknown Source)
  	at com.atlassian.oauth2.client.util.concurrent.KeyedLocks.executeWithLock(KeyedLocks.java:33)
  	- locked <0x00000006a814f2a0> (a java.util.concurrent.atomic.AtomicInteger)
  	at com.atlassian.oauth2.client.storage.DefaultTokenHandler.getRefreshedToken(DefaultTokenHandler.java:109)
  	at com.atlassian.oauth2.client.storage.DefaultTokenHandler.getRefreshedToken(DefaultTokenHandler.java:102)
  	at com.atlassian.oauth2.client.storage.DefaultTokenHandler.getRefreshedToken(DefaultTokenHandler.java:95)
  	at com.atlassian.oauth2.client.storage.DefaultTokenHandler.getRefreshedToken(DefaultTokenHandler.java:35)
  	at com.atlassian.mail.auth.JiraOauth2AuthenticationContext.refreshAccessToken(JiraOauth2AuthenticationContext.java:104)
  	at com.atlassian.mail.auth.JiraOauth2AuthenticationContext.recoverOrRethrow(JiraOauth2AuthenticationContext.java:82)
  	at com.atlassian.mail.auth.JiraOauth2AuthenticationContext.connectService(JiraOauth2AuthenticationContext.java:75)
  	at com.atlassian.mail.server.AbstractMailServer.smartConnect(AbstractMailServer.java:164)
  	at com.atlassian.jira.service.services.mail.MailServicesHelper$$Lambda$3191/0x0000000803ac8840.connect(Unknown Source)
  	at com.atlassian.jira.service.services.mail.MailServicesHelper.lambda$connectUsing$2(MailServicesHelper.java:81)
  	at com.atlassian.jira.service.services.mail.MailServicesHelper$$Lambda$3195/0x0000000803ac9840.apply(Unknown Source)
  	at java.util.Optional.map(java.base@11.0.13/Unknown Source)
  	at com.atlassian.jira.service.services.mail.MailServicesHelper.handleAuthAwareMailServer(MailServicesHelper.java:52)
  	at com.atlassian.jira.service.services.mail.MailServicesHelper.getConnectedStore(MailServicesHelper.java:46)
  	at com.atlassian.jira.service.services.mail.MailFetcherService.getConnectedStore(MailFetcherService.java:424)
  	at com.atlassian.jira.service.services.mail.MailFetcherService$MessageProviderImpl.getAndProcessMail(MailFetcherService.java:144)
  	at com.atlassian.jira.service.services.mail.MailFetcherService.processMessages(MailFetcherService.java:388)
  	at com.atlassian.jira.service.services.mail.MailFetcherService.runImpl(MailFetcherService.java:380)
  	at com.atlassian.jira.service.services.file.AbstractMessageHandlingService.run(AbstractMessageHandlingService.java:229)
  	at com.atlassian.jira.service.JiraServiceContainerImpl.run(JiraServiceContainerImpl.java:68)
  	at com.atlassian.jira.service.ServiceRunner.runService(ServiceRunner.java:62)
  	at com.atlassian.jira.service.ServiceRunner.runServiceId(ServiceRunner.java:44)
  	at com.atlassian.jira.service.ServiceRunner.runJob(ServiceRunner.java:32)
  	at com.atlassian.scheduler.core.JobLauncher.runJob(JobLauncher.java:134)
  	at com.atlassian.scheduler.core.JobLauncher.launchAndBuildResponse(JobLauncher.java:106)
  	at com.atlassian.scheduler.core.JobLauncher.launch(JobLauncher.java:90)
  	at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.launchJob(CaesiumSchedulerService.java:435)
  	at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeClusteredJob(CaesiumSchedulerService.java:430)
  	at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeClusteredJobWithRecoveryGuard(CaesiumSchedulerService.java:454)
  	at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeQueuedJob(CaesiumSchedulerService.java:382)
  	at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService$$Lambda$3172/0x0000000803ab6040.accept(Unknown Source)
  	at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.executeJob(SchedulerQueueWorker.java:66)
  	at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.executeNextJob(SchedulerQueueWorker.java:60)
  	at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.run(SchedulerQueueWorker.java:35)
  	at java.lang.Thread.run(java.base@11.0.13/Unknown Source)
     Locked ownable synchronizers:
  	- <0x0000000638f7fd70> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
  	- <0x00000006aac215c8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
  	- <0x00000006aac22770> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
  

Root Cause

The reason behind this bug is the fact that the Mail Handler uses a function from an external library HTTPRequest.java to fetch a new Oauth 2.0 Access token after it expires.

By default, this function is not using any timeout value, which means that the timeout will be infinite (the request will never time out if no response is sent back).

To fix this issue, we should use the method setConnectTimeout() from the external library to explicitly set the Timetout value before we send the HTTP Request.

• It has been identified that a readTimeout value will need to be set as well in order to stop the hung process retrieving the refresh token. Due to this finding we are reopening this bug report for additional review.

Workaround

The only way to fix this issue is to reset the Mail Handler job by re-starting the Jira application.