Inconsistent "The token supplied to the function is invalid" errors

[sjanssen1]

We're using the shiro implementation for waffle for many years now and the "The token supplied to the function is invalid" is no stranger to us. We've always been able to fix these errors by making sure to correctly configure the "setspn" configuration and by running as a service with the correct user. (See https://github.com/Waffle/waffle/blob/master/Docs/Troubleshooting.md)

But this time it's different... At random times the user is receiving a 401 due to the error below. But as soon as they refresh the authentication flow runs just fine.

We're seeing the roundtrip of requests happen, where some sort of continuation token is found in the roundtrip request and then all of a sudden we're receiving an error.

Any ideas?

Sep 27, 2022 2:28:09 PM CEST [pool-2-thread-26] [WARNING] error logging in user: The token supplied to the function is invalid
Sep 27, 2022 2:28:09 PM CEST [pool-2-thread-26] [FINE] Realm [waffle.shiro.negotiate.NegotiateAuthenticationRealm@2c6ee087] threw an exception during a multi-realm authentication attempt:
org.apache.shiro.authc.AuthenticationException: com.sun.jna.platform.win32.Win32Exception: The token supplied to the function is invalid
at waffle.shiro.negotiate.NegotiateAuthenticationRealm.doGetAuthenticationInfo(NegotiateAuthenticationRealm.java:90)
at org.apache.shiro.realm.AuthenticatingRealm.getAuthenticationInfo(AuthenticatingRealm.java:568)
at org.apache.shiro.authc.pam.ModularRealmAuthenticator.doMultiRealmAuthentication(ModularRealmAuthenticator.java:219)
at org.apache.shiro.authc.pam.ModularRealmAuthenticator.doAuthenticate(ModularRealmAuthenticator.java:269)
at org.apache.shiro.authc.AbstractAuthenticator.authenticate(AbstractAuthenticator.java:198)
at org.apache.shiro.mgt.AuthenticatingSecurityManager.authenticate(AuthenticatingSecurityManager.java:106)
at org.apache.shiro.mgt.DefaultSecurityManager.login(DefaultSecurityManager.java:270)
at org.apache.shiro.subject.support.DelegatingSubject.login(DelegatingSubject.java:256)
at org.apache.shiro.web.filter.authc.AuthenticatingFilter.executeLogin(AuthenticatingFilter.java:53)
at waffle.shiro.negotiate.NegotiateAuthenticationFilter.onAccessDenied(NegotiateAuthenticationFilter.java:224)
at org.apache.shiro.web.filter.AccessControlFilter.onAccessDenied(AccessControlFilter.java:133)
at org.apache.shiro.web.filter.AccessControlFilter.onPreHandle(AccessControlFilter.java:162)
at org.apache.shiro.web.filter.PathMatchingFilter.isFilterChainContinued(PathMatchingFilter.java:203)
at org.apache.shiro.web.filter.PathMatchingFilter.preHandle(PathMatchingFilter.java:178)
at com.id.security.authmethod.waffle.filter.WaffleNegotiateAuthenticationFilter.preHandle(WaffleNegotiateAuthenticationFilter.java:41)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:131)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)
at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)
at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)
at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1676)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524)
at id.security.auth.util.IDSecurityHandler.handle(IDSecurityHandler.java:80)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1174)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1106)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524)
at id.security.auth.util.IDSecurityHandler.handle(IDSecurityHandler.java:80)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
at org.eclipse.jetty.server.Server.handle(Server.java:524)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:319)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:253)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.sun.jna.platform.win32.Win32Exception: The token supplied to the function is invalid
at waffle.windows.auth.impl.WindowsAuthProviderImpl.acceptSecurityToken(WindowsAuthProviderImpl.java:167)
at waffle.shiro.negotiate.NegotiateAuthenticationRealm.doGetAuthenticationInfo(NegotiateAuthenticationRealm.java:86)
... 56 more

[dblock]

Any correlation to traffic/volume of authentication requests?

[sjanssen1]

There seems to be no correlation. Happens at random times :/

[hazendaz]

What version of waffle are you using?

[sjanssen1]

We've originally encountered the issue while using 1.8.2. I've then looked into the release notes for potentially related fixes and tried out 1.9.1 but the issue persisted.

We're having compatibility issues when upgrading to the latest waffle release (3.3.0) so that's why we opted for the older release.

[hazendaz]

@sjanssen1 What compatibility issue were you having with newer one? The ones noted are quite old.

[sjanssen1]

The compatibility issues seemed to be related to our application still using an older version of Apache Shiro (1.2.x)
We've tried upgrading the shiro dependency on our legacy app to 1.12.0 but ran into a bunch of dependency/classloading problems which we are unable to fix at this time. We're also not sure if it would have any effect on the issue we are having based on the release notes. (Between waffle 1.8.x and 1.9.x there were some notes mildly related to the problem we seem to be having)

I realise this is anything but an ideal situation but if you have any debug tips or tools that would be greatly appreciated. Still trying to figure out the random behavior where the invalid token error would pop up and disappear after refreshing the application and doing the same request again.

[tomdausyup]

Can you have a look the last comment of @sjanssen1 asking for some debug tips or tools to investigate the issue further.
It would be appreciated.

[hazendaz]

not a lot I can do here. The versions noted in use are far too old. I don't have a lot of time available to this app and generally speaking users need to be on latest releases. Because this is on top of JNA and JNA made significant changes in more recent versions its quite possible that is causing issues. Its best to be on latest and go from there. I don't personally use the shiro piece so I don't have very much to offer on it. One could try to go back through commit history and try reaching out to the original author on it in hopes they can help but again being up to date would be best approach.