High number of 500 errors registered in the logs -when attempting to read/validate the token

[Neena Rodricks]

hi,

We recently started noticing issues with the Jira ITG instance where other apps are encountering issues while connecting using the REST API tokens.

<plugin>
      <key>com.wombatscorp.jira-tokens</key>
      <name>API Tokens for Jira</name>
      <version>1.4.6</version>
      <vendor>Wombats Corp</vendor>
      <status>ENABLED</status>
      <vendor-url>https://wombatscorp.com/</vendor-url>
      <framework-version>2</framework-version>
      <bundled>User installed</bundled>
    </plugin>

Atlassian Support has analyzed on May 12th and provided the following:

Upon reviewing the Jira logs, we identified a high number of 500 errors registered in the logs, which seem to be associated with the API Tokens for Jira app.
According to the stack traces, it seems that when attempting to read/validate the token (com.wombatscorp.jira.tokens.filters.TokenFilter.doFilter) upon accessing Jira, an 'ArrayIndexOutOfBoundsException' is thrown, which subsequently generates a 'NullPointerException' (on the same thread) due to the failure of getting the token during the user authentication to Jira (com.atlassian.jira.security.login.JiraSeraphAuthenticator.getUserFromBasicAuthentication).
Based on the provided details, this seems to be the most likely reason for the application's unavailability.

2023-05-11 09:10:04,304+0000 https-jsse-nio-8443-exec-75 ERROR      [o.a.c.c.C.[.[localhost].[/].[default]] Servlet.service() for servlet [default] in context with path [] threw exception
java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
    at com.wombatscorp.jira.tokens.filters.TokenFilter.doFilter(TokenFilter.java:120)
    at com.atlassian.plugin.servlet.filter.DelegatingPluginFilter.doFilter(DelegatingPluginFilter.java:62)
    at com.atlassian.plugin.servlet.filter.IteratingFilterChain.doFilter(IteratingFilterChain.java:37)
    at com.atlassian.plugin.servlet.filter.ServletFilterModuleContainerFilter.doFilter(ServletFilterModuleContainerFilter.java:56)
    at com.atlassian.plugin.servlet.filter.ServletFilterModuleContainerFilter.doFilter(ServletFilterModuleContainerFilter.java:44)
    ... 18 filtered
    at com.atlassian.jira.servermetrics.MetricsCollectorFilter.doFilter(MetricsCollectorFilter.java:25)
    ... 25 filtered
    at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
    at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Unknown Source)
2023-05-11 09:10:04,311+0000 https-jsse-nio-8443-exec-75 url: /internal-error ERROR   -   [c.a.j.web.servlet.InternalServerErrorServlet] Cannot render the 500 page for error b99fd550-9a38-4542-8ebd-25a1a5ad560e
java.lang.NullPointerException
    at com.atlassian.jira.security.login.JiraSeraphAuthenticator.getUserFromBasicAuthentication(JiraSeraphAuthenticator.java:150)
    at com.atlassian.seraph.auth.DefaultAuthenticator.getUser(DefaultAuthenticator.java:326)
    at com.atlassian.seraph.auth.AbstractAuthenticator.getUser(AbstractAuthenticator.java:45)
    at com.atlassian.jira.web.action.util.errors.SeraphUserRetriever.getLoggedInUser(SeraphUserRetriever.java:24)
    at com.atlassian.jira.web.servlet.InternalServerErrorHelper.<init>(InternalServerErrorHelper.java:98)
    at com.atlassian.jira.web.servlet.InternalServerErrorHelper.render500ResponsePage(InternalServerErrorHelper.java:52)
    at com.atlassian.jira.web.servlet.InternalServerErrorServlet.doRequest(InternalServerErrorServlet.java:14)
    at com.atlassian.jira.web.servlet.InternalServerErrorServlet.doPost(InternalServerErrorServlet.java:26)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:696)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:779)
    ... 7 filtered
    at com.atlassian.diagnostics.internal.platform.monitor.http.HttpRequestMonitoringFilter.doFilter(HttpRequestMonitoringFilter.java:54)
    ... 24 filtered
    at com.atlassian.troubleshooting.thready.filter.AbstractThreadNamingFilter.doFilter(AbstractThreadNamingFilter.java:46)
    ... 21 filtered
    at com.atlassian.plugins.authentication.impl.basicauth.filter.DisableBasicAuthFilter.doFilter(DisableBasicAuthFilter.java:70)
    ... 3 filtered
    at com.atlassian.troubleshooting.thready.filter.AbstractThreadNamingFilter.doFilter(AbstractThreadNamingFilter.java:46)
    ... 41 filtered
    at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
    at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Unknown Source)

2023-05-11 09:10:07,223+0000 https-jsse-nio-8443-exec-57 ERROR      [o.a.c.c.C.[.[localhost].[/].[default]] Servlet.service() for servlet [default] in context with path [] threw exception
java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
    at com.wombatscorp.jira.tokens.filters.TokenFilter.doFilter(TokenFilter.java:120)
    at com.atlassian.plugin.servlet.filter.DelegatingPluginFilter.doFilter(DelegatingPluginFilter.java:62)
    at com.atlassian.plugin.servlet.filter.IteratingFilterChain.doFilter(IteratingFilterChain.java:37)
    at com.atlassian.plugin.servlet.filter.ServletFilterModuleContainerFilter.doFilter(ServletFilterModuleContainerFilter.java:56)
    at com.atlassian.plugin.servlet.filter.ServletFilterModuleContainerFilter.doFilter(ServletFilterModuleContainerFilter.java:44)
    ... 18 filtered
    at com.atlassian.jira.servermetrics.MetricsCollectorFilter.doFilter(MetricsCollectorFilter.java:25)
    ... 25 filtered
    at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
    at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Unknown Source)
2023-05-11 09:10:07,230+0000 https-jsse-nio-8443-exec-57 url: /internal-error ERROR   -   [c.a.j.web.servlet.InternalServerErrorServlet] Cannot render the 500 page for error 60fb6c88-9878-4edd-a879-47dcd4d3b412
java.lang.NullPointerException
    at com.atlassian.jira.security.login.JiraSeraphAuthenticator.getUserFromBasicAuthentication(JiraSeraphAuthenticator.java:150)
    at com.atlassian.seraph.auth.DefaultAuthenticator.getUser(DefaultAuthenticator.java:326)
    at com.atlassian.seraph.auth.AbstractAuthenticator.getUser(AbstractAuthenticator.java:45)
    at com.atlassian.jira.web.action.util.errors.SeraphUserRetriever.getLoggedInUser(SeraphUserRetriever.java:24)
    at com.atlassian.jira.web.servlet.InternalServerErrorHelper.<init>(InternalServerErrorHelper.java:98)
    at com.atlassian.jira.web.servlet.InternalServerErrorHelper.render500ResponsePage(InternalServerErrorHelper.java:52)
    at com.atlassian.jira.web.servlet.InternalServerErrorServlet.doRequest(InternalServerErrorServlet.java:14)
    at com.atlassian.jira.web.servlet.InternalServerErrorServlet.doPost(InternalServerErrorServlet.java:26)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:696)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:779)
    ... 7 filtered
    at com.atlassian.diagnostics.internal.platform.monitor.http.HttpRequestMonitoringFilter.doFilter(HttpRequestMonitoringFilter.java:54)
    ... 24 filtered
    at com.atlassian.troubleshooting.thready.filter.AbstractThreadNamingFilter.doFilter(AbstractThreadNamingFilter.java:46)
    ... 21 filtered
    at com.atlassian.plugins.authentication.impl.basicauth.filter.DisableBasicAuthFilter.doFilter(DisableBasicAuthFilter.java:70)
    ... 3 filtered
    at com.atlassian.troubleshooting.thready.filter.AbstractThreadNamingFilter.doFilter(AbstractThreadNamingFilter.java:46)
    ... 41 filtered
    at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
    at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Unknown Source)

Next steps

Based on our limited evidence for this outage, it appears that the failure could have been caused by the 'ArrayIndexOutOfBoundsException' from API Tokens for Jira app.

That said, the current evidence is limited and does not allow us to say with certainty that this was the case. Nevertheless, it may be worth contacting Wobat's corp Technical Support Team to review those findings and advise on a solution for their app.

______________________________________________________________________

We reproduced today twice with logs enables for HTTP and support logs attached.

Can you please assist with this issue and let us know the root cause of this.

Thanks,

Neena

[Roma Bubyakin [Wombats Corp]]

Hi Neena,

Thank you for reaching out and providing detailed information about the issue.
I’m on in and will keep you noted.

Regards, Roman

[Roma Bubyakin [Wombats Corp]]

Hi Neena,

Current Results

I’m returning with the current investigation results.
As for now, I can say that the problem is that some clients missed the colon in Basic Auth header.

The standard header in this case would look like the following:
Authorization: Basic QWxhZGRpbjpvcGVuIHNlc2FtZQ==
Where QWxhZGRpbjpvcGVuIHNlc2FtZQ== stands for base64 encoded <username>:<password> string “Aladdin:open sesame“

Stacktrace from your logs related to the parsing <username>:<password> header based on colon(:) character, which is missed.

"constructs the user-pass by concatenating the user-id, a single colon (":") character, and the password"
The 'Basic' HTTP Authentication Scheme

---

Next steps

I’m trying to reproduce the case, create a bugfix version, and test it.
So it should be done in the next few days.

---

How it could be investigated from your side?

If you wish, you can investigate that also from your side by enabling TRACE logging level on package 'com.wombatscorp.jira.tokens.filters'.
It will show the invalid auth header with the following pattern in log file:

Decoded auth header: <decodedAuthHeader>

Please be aware that it will log auth string in plain text into the filesystem, which is not secure. It’s recommended to enable only on test instances and only if the system administrator understands the risks of storing plaintext passwords in logs.

‌

Best Regards,
Roman

[Roma Bubyakin [Wombats Corp]]

v1.4.7 Fixed #51 No more 500 on invalid basic auth headers

→ <<cset 374a522e77e2>>

[Roma Bubyakin [Wombats Corp]]

Hi Neena,

Fixed. Feel free to update to v.1.4.7

Regards, Roman