UserRoles getting cleared by cache flushing after 30 minutes

[jcl]

I have been working on a SecurityException that happens about 30 minutes into a stress test. The stress test basically keeps getting a bean
and invoking a method on that bean. Works great for about 30 minutes.
Then it fails. It isn't doing anything different at the 30 minute mark. I turned on jboss logging level for the login modules and it shows a logout which I believe is coming because the cache is set to clean
up at 30 minutes which causes a flush on this login. Hence the logout in the trace. The logout seems to remove the roles from the security realm l and the log shows that the prinicpal has no roles even though previous calls did have the roles. Has anyone else seen this?
I did some searching any all the hits say this is fixed but I am on jboss3.2.5 so I should have all those fixes.

Here is the log4j output:
2004-08-18 17:17:43,308 TRACE [org.jboss.security.auth.spi.UsersRolesLoginModule] logout
2004-08-18 17:17:43,318 ERROR [org.jboss.ejb.plugins.SecurityInterceptor] Insufficient method permissions, principal=test, method=process, interface=REMOTE, requiredRoles=[MyRole], principalRoles=null
2004-08-18 17:17:43,318 ERROR [org.jboss.ejb.plugins.LogInterceptor] EJBException, causedBy:......
.....
I am not going to total verify the logout is coming from the cache but I am pretty sure.

[jcl]

After trying to get a stack trace of where the logout is coming from
I have this problem now showing up in the jms database access.
Which seems to be the same problem with cache invalidating subject.
I do have a stack trace showing that the logout is coming from the cache flushing.
Any ideas on fixing this problem.
I have org.jboss.security trace level set. Plus I added an exception dump
in the logout of the Abstract...LoginModule just to see who was calling it.
It seems that after the cache does the logout the connection pool tries to look at the subjects credentials but logout has invalidated it.

2004-08-19 09:05:17,421 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] logout
2004-08-19 09:05:17,421 INFO [STDOUT] java.lang.Exception
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.security.auth.spi.AbstractServerLoginModule.logout(AbstractServerLoginModule.java:228)
2004-08-19 09:05:17,421 INFO [STDOUT] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2004-08-19 09:05:17,421 INFO [STDOUT] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
2004-08-19 09:05:17,421 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2004-08-19 09:05:17,421 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:324)
2004-08-19 09:05:17,421 INFO [STDOUT] at javax.security.auth.login.LoginContext.invoke(LoginContext.java:675)
2004-08-19 09:05:17,421 INFO [STDOUT] at javax.security.auth.login.LoginContext.access$000(LoginContext.java:129)
2004-08-19 09:05:17,421 INFO [STDOUT] at javax.security.auth.login.LoginContext$4.run(LoginContext.java:610)
2004-08-19 09:05:17,421 INFO [STDOUT] at java.security.AccessController.doPrivileged(Native Method)
2004-08-19 09:05:17,421 INFO [STDOUT] at javax.security.auth.login.LoginContext.invokeModule(LoginContext.java:607)
2004-08-19 09:05:17,421 INFO [STDOUT] at javax.security.auth.login.LoginContext.logout(LoginContext.java:575)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.security.plugins.JaasSecurityManager$DomainInfo.destroy(JaasSecurityManager.java:83)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.util.TimedCachePolicy.get(TimedCachePolicy.java:166)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.security.plugins.JaasSecurityManager.getCacheInfo(JaasSecurityManager.java:555)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:240)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:221)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.security.SecurityManager.authenticate(SecurityManager.java:199)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.security.ServerSecurityInterceptor.authenticate(ServerSecurityInterceptor.java:51)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.server.TracingInterceptor.authenticate(TracingInterceptor.java:781)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.server.JMSServerInvoker.authenticate(JMSServerInvoker.java:287)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.il.jvm.JVMServerIL.authenticate(JVMServerIL.java:301)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.Connection.authenticate(Connection.java:1153)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.Connection.(Connection.java:248)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.Connection.(Connection.java:325)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.SpyConnection.(SpyConnection.java:66)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.SpyConnectionFactory.createConnection(SpyConnectionFactory.java:87)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.mq.SpyConnectionFactory.createQueueConnection(SpyConnectionFactory.java:124)
2004-08-19 09:05:17,421 INFO [STDOUT] at my.QueueHelper.init(QueueHelper.java:59)
2004-08-19 09:05:17,421 INFO [STDOUT] at my.ProcessCommandHandler.qMsg(ProcessCommandHandler.java:253)
2004-08-19 09:05:17,421 INFO [STDOUT] at my.ProcessCommandHandler.handle(ProcessCommandHandler.java:79)
2004-08-19 09:05:17,421 INFO [STDOUT] at my.beans.ProcessHubSession.process(ProcessHubSession.java:120)
2004-08-19 09:05:17,421 INFO [STDOUT] at sun.reflect.GeneratedMethodAccessor144.invoke(Unknown Source)
2004-08-19 09:05:17,421 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2004-08-19 09:05:17,421 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:324)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)
2004-08-19 09:05:17,421 INFO [STDOUT] at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:185)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:315)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:148)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:120)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.ejb.Container.invoke(Container.java:723)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.reflect.GeneratedMethodAccessor104.invoke(Unknown Source)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2004-08-19 09:05:17,431 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:324)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.mx.server.ReflectedDispatcher.dispatch(ReflectedDispatcher.java:60)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.mx.server.Invocation.dispatch(Invocation.java:61)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.mx.server.Invocation.dispatch(Invocation.java:53)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:185)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:473)
2004-08-19 09:05:17,431 INFO [STDOUT] at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:360)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.reflect.GeneratedMethodAccessor140.invoke(Unknown Source)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2004-08-19 09:05:17,431 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:324)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.rmi.transport.Transport$1.run(Transport.java:148)
2004-08-19 09:05:17,431 INFO [STDOUT] at java.security.AccessController.doPrivileged(Native Method)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.rmi.transport.Transport.serviceCall(Transport.java:144)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
2004-08-19 09:05:17,431 INFO [STDOUT] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
2004-08-19 09:05:17,431 INFO [STDOUT] at java.lang.Thread.run(Thread.java:534)
2004-08-19 09:05:17,431 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] java.lang.Exception: Logout
2004-08-19 09:05:17,431 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] java.lang.Exception: Logout
2004-08-19 09:05:17,431 TRACE [org.jboss.security.plugins.JaasSecurityManager.jbossmq] updateCache, subject=Subject:
Principal: null

2004-08-19 09:05:17,431 TRACE [org.jboss.security.plugins.JaasSecurityManager.jbossmq] updateCache, subject=Subject:
Principal: null

2004-08-19 09:05:17,431 TRACE [org.jboss.security.plugins.JaasSecurityManager.HsqlDbRealm] updateCache, subject=Subject:
Principal: null

2004-08-19 09:05:17,431 TRACE [org.jboss.security.plugins.JaasSecurityManager.HsqlDbRealm] updateCache, subject=Subject:
Principal: null

2004-08-19 09:05:17,431 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.parentTraceEnabled=true
2004-08-19 09:05:17,441 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.nestedTraceEnabled=false
2004-08-19 09:05:17,441 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.detectDuplicateNesting=true
2004-08-19 09:05:17,431 WARN [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Throwable while attempting to get a new connection: null
org.jboss.resource.JBossResourceException: No matching credentials in Subject!

[jcl]

Well I think I solved a work around the problem.
It seems that an MDB in the system they had put some code
to set the jaas environment and call login on the module.
Removing this and using the unauthenticatedIdentity in the real module
allowed the cache cleanup to not affect anything. But I believe the cache
cleanup still shouldn't cause this to happen.
Wierd is that the session beans was using a different login domain.
And the mdb had the domain set explicitly to "other" which was different than the session bean. The mdb did access the session bean which
it let be access because I think the run-as was set with the correct role.
Anyhow the cache did a logout and it somehow affected a client that was accessing a session bean.

Code from mdb that was removed.
String userId = "test";
LoginContext lc= new LoginContext("other", callbackHandler);
lc.login();