<div dir="ltr">Hi Luiz,<div><br></div><div>Check out <a href="https://github.com/mitreid-connect/OpenID-Connect-Java-Spring-Server/issues/862">https://github.com/mitreid-connect/OpenID-Connect-Java-Spring-Server/issues/862</a>, it seems to be exactly the problem you're having.</div><div><br></div><div>Regards,</div><div>Mark</div><br><div class="gmail_quote"><div dir="ltr">On Tue, 1 Sep 2015 at 16:50 Luiz Omori <<a href="mailto:luiz.omori@duke.edu">luiz.omori@duke.edu</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div style="word-wrap:break-word;color:rgb(0,0,0);font-size:14px;font-family:Calibri,sans-serif">
<div>OK, I managed to reproduce the problem: it’s related to duplicated ID tokens being created when multiple
<b>similar</b> requests are received within the same second. In our case we use the Resource Owner flow for some legacy web services calls and that exacerbates the problem. At some point the code does a select on the access_token table using the token_value
column and checks for number of rows returned, enforcing 1.</div>
<div><br>
</div>
<div>This token appears 38 times in the access_token table when we ran a stress test that makes 50 parallel Resource Owner requests (test environment):</div>
<div><br>
</div>
<div>eyJraWQiOiJyc2ExIiwiYWxnIjoiUlMyNTYifQ.eyJpc3MiOiJodHRwOlwvXC9sb2NhbGhvc3Q6ODA4MFwvbGRhcC1vcGVuaWQtY29ubmVjdC1zZXJ2ZXJcLyIsInN1YiI6IkNBVFNfZGFzaHNydiIsImF1ZCI6WyJncm93dGhfY2hhcnQiXSwiZXhwIjoxNDQxMTE0NTMzLCJpYXQiOjE0NDExMTQ0NzMsImtpZCI6InJzYTEifQ.NVSFBd9onhEUgMDC46KAJx5M_CaBy-INuy0MqodLqOCO7YQ5N9ZARG9BKemjv8G0Aj8aIYOa-CJeUYycv6Uk1qqVTcXX9jgpX7-f9xK4T4MxcOhhTwRqkvT8l7yWL5uAm1uG7lcKKHw6h2RGed4x9zej1Zb0PFiHTZHkPRl6OWwJvmaZySd0CZM3VVVtW4HIB45vNURE--ee5zkH1ezoJOfR0JlFFEaQfcTnW-PGBcNri6huk1fosUwLxoZE8-YGjwWVzKyy_1qmZBhS9Yg1ch6uXuxaXjG96_ITZQVoIyFwWyMi3rXOiwdgAzN_7aZOt8HSxNm7OUqFxZEr6JChbw</div>
<div><br>
</div>
<div>The concern is the growth of that table and since at least in MySQL version the token_value is not indexed (we could fix it locally) potential slow down over time.</div>
<div><br>
</div>
<div>Is there any workaround that we could use on our production system? Unfortunately, as opposed to my local system, our production environment is using HSSQLDB which most likely will prevent us from running delete SQL commands while the system is running. </div>
<div><br>
</div>
<div>Maybe we can add JTI to the ID tokens to make them unique?</div>
<div><br>
</div>
<div>Regards,</div>
<div>Luiz</div>
<div><br>
</div>
<span>
<div style="font-family:Calibri;font-size:11pt;text-align:left;color:black;BORDER-BOTTOM:medium none;BORDER-LEFT:medium none;PADDING-BOTTOM:0in;PADDING-LEFT:0in;PADDING-RIGHT:0in;BORDER-TOP:#b5c4df 1pt solid;BORDER-RIGHT:medium none;PADDING-TOP:3pt">
<span style="font-weight:bold">From: </span>Luiz Omori <<a href="mailto:luiz.omori@dm.duke.edu" target="_blank">luiz.omori@dm.duke.edu</a>><br>
<span style="font-weight:bold">Date: </span>Monday, August 31, 2015 at 4:50 PM<br>
<span style="font-weight:bold">To: </span>"<a href="mailto:mitreid-connect@mit.edu" target="_blank">mitreid-connect@mit.edu</a>" <<a href="mailto:mitreid-connect@mit.edu" target="_blank">mitreid-connect@mit.edu</a>><br>
<span style="font-weight:bold">Subject: </span>Exception during cleanup<br>
</div></span></div><div style="word-wrap:break-word;color:rgb(0,0,0);font-size:14px;font-family:Calibri,sans-serif"><span>
<div><br>
</div>
<div>
<div style="word-wrap:break-word;color:rgb(0,0,0);font-size:14px;font-family:Calibri,sans-serif">
<div>Hi,</div>
<div><br>
</div>
<div>We have a system in production that is logging some exceptions. This is happening in DefaultOAuth2ProviderTokenService.clearExpiredTokens. I’ve been trying to track that down but so far no luck reproducing it on my development environment. Has anybody
seem this? Is it benign or something we should be concerned about? </div>
<div><br>
</div>
<div>
<div><span style="white-space:pre-wrap"></span>@Override</div>
<div><span style="white-space:pre-wrap"></span>public void clearExpiredTokens() {</div>
<div><span style="white-space:pre-wrap"></span><a href="http://logger.info" target="_blank">logger.info</a>("Cleaning out all expired tokens");</div>
<div><br>
</div>
<div><span style="white-space:pre-wrap"></span>Collection<OAuth2AccessTokenEntity> accessTokens = getExpiredAccessTokens();</div>
<div><span style="white-space:pre-wrap"></span><a href="http://logger.info" target="_blank">logger.info</a>("Found " + accessTokens.size() + " expired access tokens");</div>
<div><span style="white-space:pre-wrap"></span>for (OAuth2AccessTokenEntity oAuth2AccessTokenEntity : accessTokens) {</div>
<div><span style="white-space:pre-wrap"></span>try {</div>
<div><span style="white-space:pre-wrap"></span>revokeAccessToken(oAuth2AccessTokenEntity);</div>
<div><span style="white-space:pre-wrap"></span>} catch (IllegalArgumentException e) {</div>
<div><span style="white-space:pre-wrap"></span>//An ID token is deleted with its corresponding access token, but then the ID token is on the list of expired tokens as well and there is</div>
<div><span style="white-space:pre-wrap"></span>//nothing in place to distinguish it from any other.</div>
<div><span style="white-space:pre-wrap"></span>//An attempt to delete an already deleted token returns an error, stopping the cleanup dead. We need it to keep going.</div>
<div><span style="white-space:pre-wrap"></span>}</div>
<div><span style="white-space:pre-wrap"></span>}</div>
<div>…</div>
</div>
<div><br>
</div>
<div>
<div>2015Aug27 16:38:49,564: ERROR: org.springframework.scheduling.support.TaskUtils$LoggingErrorHandler - Unexpected error occurred in scheduled task.</div>
<div>java.lang.IllegalStateException: Expected single result, got 2</div>
<div> at org.mitre.util.jpa.JpaUtil.getSingleResult(JpaUtil.java:36)</div>
<div> at org.mitre.oauth2.repository.impl.JpaOAuth2TokenRepository.getAccessTokenByValue(JpaOAuth2TokenRepository.java:62)</div>
<div> at org.mitre.oauth2.repository.impl.JpaOAuth2TokenRepository.removeAccessToken(JpaOAuth2TokenRepository.java:79)</div>
<div> at org.mitre.oauth2.repository.impl.JpaOAuth2TokenRepository$$FastClassBySpringCGLIB$$145026dd.invoke(<generated>)</div>
<div> at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)</div>
<div> at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:700)</div>
<div> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)</div>
<div> at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)</div>
<div> at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)</div>
<div> at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)</div>
<div> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)</div>
<div> at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:633)</div>
<div> at org.mitre.oauth2.repository.impl.JpaOAuth2TokenRepository$$EnhancerBySpringCGLIB$$e7092f0b.removeAccessToken(<generated>)</div>
<div> at org.mitre.oauth2.service.impl.DefaultOAuth2ProviderTokenService.revokeAccessToken(DefaultOAuth2ProviderTokenService.java:380)</div>
<div> at org.mitre.oauth2.service.impl.DefaultOAuth2ProviderTokenService.clearExpiredTokens(DefaultOAuth2ProviderTokenService.java:411)</div>
<div> at sun.reflect.GeneratedMethodAccessor210.invoke(Unknown Source)</div>
<div> at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)</div>
<div> at java.lang.reflect.Method.invoke(Unknown Source)</div>
<div> at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:64)</div>
<div> at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:53)</div>
<div> at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)</div>
<div> at java.util.concurrent.FutureTask.runAndReset(Unknown Source)</div>
<div> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source)</div>
<div> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)</div>
<div> at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)</div>
<div> at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)</div>
<div> at java.lang.Thread.run(Unknown Source)</div>
</div>
<div><br>
</div>
<div>Regards,</div>
<div>Luiz</div>
</div>
</div>
</span></div>
_______________________________________________<br>
mitreid-connect mailing list<br>
<a href="mailto:mitreid-connect@mit.edu" target="_blank">mitreid-connect@mit.edu</a><br>
<a href="http://mailman.mit.edu/mailman/listinfo/mitreid-connect" rel="noreferrer" target="_blank">http://mailman.mit.edu/mailman/listinfo/mitreid-connect</a><br>
</blockquote></div></div>