<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=Windows-1252">
</head>
<body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; 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 id="OLK_SRC_BODY_SECTION">
<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">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">mitreid-connect@mit.edu</a>" <<a href="mailto:mitreid-connect@mit.edu">mitreid-connect@mit.edu</a>><br>
<span style="font-weight:bold">Subject: </span>Exception during cleanup<br>
</div>
<div><br>
</div>
<div>
<div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; 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 class="Apple-tab-span" style="white-space:pre"></span>@Override</div>
<div><span class="Apple-tab-span" style="white-space:pre"></span>public void clearExpiredTokens() {</div>
<div><span class="Apple-tab-span" style="white-space:pre"></span>logger.info("Cleaning out all expired tokens");</div>
<div><br>
</div>
<div><span class="Apple-tab-span" style="white-space:pre"></span>Collection<OAuth2AccessTokenEntity> accessTokens = getExpiredAccessTokens();</div>
<div><span class="Apple-tab-span" style="white-space:pre"></span>logger.info("Found " + accessTokens.size() + " expired access tokens");</div>
<div><span class="Apple-tab-span" style="white-space:pre"></span>for (OAuth2AccessTokenEntity oAuth2AccessTokenEntity : accessTokens) {</div>
<div><span class="Apple-tab-span" style="white-space:pre"></span>try {</div>
<div><span class="Apple-tab-span" style="white-space:pre"></span>revokeAccessToken(oAuth2AccessTokenEntity);</div>
<div><span class="Apple-tab-span" style="white-space:pre"></span>} catch (IllegalArgumentException e) {</div>
<div><span class="Apple-tab-span" style="white-space:pre"></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 class="Apple-tab-span" style="white-space:pre"></span>//nothing in place to distinguish it from any other.</div>
<div><span class="Apple-tab-span" style="white-space:pre"></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 class="Apple-tab-span" style="white-space:pre"></span>}</div>
<div><span class="Apple-tab-span" style="white-space:pre"></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>
</body>
</html>