Authenication through LoginModule works, but access denied

[kcturner]

I have resorted to the most basic test to try to get JAAS authentication and authorization to work with the container declared security. I have changed the auth-method to basic and tried to access a simple html file in the secured directory. The browser login form is displayed and the DatabaseServerLoginModule is initialized. As far as I can tell by stepping through the DatabaseServerLoginModule code theuser is being authenticated successfully and the roles are captured, but access to the secured page is denied. Any suggestions on where to look next would be greatly appreciated.

[kcturner]

Here an excert from the log that may help:

2006-01-07 14:08:54,059 DEBUG [org.apache.catalina.loader.WebappClassLoader] Loading class from parent
2006-01-07 14:08:54,059 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] initialize, instance=@8671341
2006-01-07 14:08:54,059 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] DatabaseServerLoginModule, dsJndiName=java:/HRSI_DS
2006-01-07 14:08:54,059 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] principalsQuery=select password from users where user_id=?
2006-01-07 14:08:54,059 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] rolesQuery=select role, user_group from user_roles where user_id=?
2006-01-07 14:08:54,059 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] suspendResume=true
2006-01-07 14:08:54,059 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] login
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] loadClass(org.jboss.tm.TransactionManagerService, false)
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] Searching local repositories
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] findClass(org.jboss.tm.TransactionManagerService)
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] findClassInternal(org.jboss.tm.TransactionManagerService)
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] --> Passing on ClassNotFoundException
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] Delegating to parent classloader at end: java.net.FactoryURLClassLoader@1c6fed0
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] Loading class from parent
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] loadClass(org.jboss.util.naming.NonSerializableFactory, false)
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] Searching local repositories
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] findClass(org.jboss.util.naming.NonSerializableFactory)
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] findClassInternal(org.jboss.util.naming.NonSerializableFactory)
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] --> Passing on ClassNotFoundException
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] Delegating to parent classloader at end: java.net.FactoryURLClassLoader@1c6fed0
2006-01-07 14:08:54,075 DEBUG [org.apache.catalina.loader.WebappClassLoader] Loading class from parent
2006-01-07 14:08:54,169 DEBUG [org.jboss.cache.eviction.LRUAlgorithm] processing the node events in region: Regions--- fqn: /_default_/ maxNodes 1000000 TimeToIdleSeconds 300current eviction queue size is 0
2006-01-07 14:08:54,169 DEBUG [org.jboss.cache.eviction.LRUAlgorithm] processed 0 node events
2006-01-07 14:08:54,309 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] User 'kcturner' authenticated, loginOk=true
2006-01-07 14:08:54,309 DEBUG [org.apache.catalina.loader.WebappClassLoader] loadClass(org.jboss.security.ClientLoginModule, false)
2006-01-07 14:08:54,309 DEBUG [org.apache.catalina.loader.WebappClassLoader] Searching local repositories
2006-01-07 14:08:54,309 DEBUG [org.apache.catalina.loader.WebappClassLoader] findClass(org.jboss.security.ClientLoginModule)
2006-01-07 14:08:54,309 DEBUG [org.apache.catalina.loader.WebappClassLoader] findClassInternal(org.jboss.security.ClientLoginModule)
2006-01-07 14:08:54,309 DEBUG [org.apache.catalina.loader.WebappClassLoader] --> Passing on ClassNotFoundException
2006-01-07 14:08:54,309 DEBUG [org.apache.catalina.loader.WebappClassLoader] Delegating to parent classloader at end: java.net.FactoryURLClassLoader@1c6fed0
2006-01-07 14:08:54,309 DEBUG [org.jboss.mx.loading.UnifiedClassLoader] New jmx UCL with url null
2006-01-07 14:08:54,309 DEBUG [org.jboss.mx.loading.RepositoryClassLoader] setRepository, repository=org.jboss.mx.loading.HeirarchicalLoaderRepository3@1dd0fe7, cl=org.jboss.mx.loading.UnifiedClassLoader3@71edc8{ url=null ,addedOrder=0}
2006-01-07 14:08:54,309 DEBUG [org.apache.catalina.loader.WebappClassLoader] Loading class from parent
2006-01-07 14:08:54,325 TRACE [org.jboss.security.ClientLoginModule] Begin login
2006-01-07 14:08:54,325 TRACE [org.jboss.security.ClientLoginModule] Obtained login: kcturner, credential.class: [C
2006-01-07 14:08:54,325 TRACE [org.jboss.security.ClientLoginModule] End login
2006-01-07 14:08:54,325 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] commit, loginOk=true
2006-01-07 14:08:54,575 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] Assign user to role admin
2006-01-07 14:08:54,575 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] Assign user to role authorizedUser
2006-01-07 14:08:54,575 TRACE [org.jboss.security.ClientLoginModule] commit, subject=Subject:
Principal: kcturner
Principal: admin(members:admin,authorizedUser)

2006-01-07 14:08:54,575 TRACE [org.jboss.security.SecurityAssociation] pushSubjectContext, subject=Subject:
Principal: kcturner
Principal: admin(members:admin,authorizedUser)
, sc=org.jboss.security.SecurityAssociation$SubjectContext@c54b3b{principal=kcturner,subject=13514993}
2006-01-07 14:08:54,575 TRACE [org.jboss.security.plugins.JaasSecurityManager.rms] defaultLogin, lc=javax.security.auth.login.LoginContext@fc61e9, subject=Subject(13514993).principals=org.jboss.security.SimplePrincipal@2460788(kcturner)org.jboss.security.SimpleGroup@6184850(admin(members:admin,authorizedUser))
2006-01-07 14:08:54,575 TRACE [org.jboss.security.plugins.JaasSecurityManager.rms] updateCache, inputSubject=Subject(13514993).principals=org.jboss.security.SimplePrincipal@2460788(kcturner)org.jboss.security.SimpleGroup@6184850(admin(members:admin,authorizedUser)), cacheSubject=Subject(25175878).principals=org.jboss.security.SimplePrincipal@2460788(kcturner)org.jboss.security.SimpleGroup@6184850(admin(members:admin,authorizedUser))
2006-01-07 14:08:54,575 TRACE [org.jboss.security.plugins.JaasSecurityManager.rms] Inserted cache info: org.jboss.security.plugins.JaasSecurityManager$DomainInfo@92949f[Subject(25175878).principals=org.jboss.security.SimplePrincipal@2460788(kcturner)org.jboss.security.SimpleGroup@6184850(admin(members:admin,authorizedUser)),credential.class=java.lang.String@18019860,expirationTime=1136662734075]
2006-01-07 14:08:54,575 TRACE [org.jboss.security.plugins.JaasSecurityManager.rms] End isValid, true
2006-01-07 14:08:54,575 TRACE [org.jboss.web.tomcat.security.JBossSecurityMgrRealm] User: kcturner is authenticated
2006-01-07 14:08:54,575 TRACE [org.jboss.security.SecurityAssociation] pushSubjectContext, subject=Subject:
Principal: kcturner
Principal: admin(members:admin,authorizedUser)
, sc=org.jboss.security.SecurityAssociation$SubjectContext@3e0b62{principal=kcturner,subject=22897028}
2006-01-07 14:08:54,575 TRACE [org.jboss.security.plugins.JaasSecurityManager.rms] getPrincipal, cache info: org.jboss.security.plugins.JaasSecurityManager$DomainInfo@92949f[Subject(25175878).principals=org.jboss.security.SimplePrincipal@2460788(kcturner)org.jboss.security.SimpleGroup@6184850(admin(members:admin,authorizedUser)),credential.class=java.lang.String@18019860,expirationTime=1136662734075]
2006-01-07 14:08:54,575 TRACE [org.jboss.web.tomcat.security.JBossSecurityMgrRealm] Mapped from input principal: kcturnerto: kcturner
2006-01-07 14:08:54,590 TRACE [org.jboss.security.SecurityAssociation] getSubject, sc=org.jboss.security.SecurityAssociation$SubjectContext@3e0b62{principal=kcturner,subject=22897028}
2006-01-07 14:08:54,590 TRACE [org.jboss.security.plugins.JaasSecurityManager.rms] getUserRoles, subject: Subject:
Principal: kcturner
Principal: admin(members:admin,authorizedUser)

2006-01-07 14:08:54,590 TRACE [org.jboss.web.tomcat.security.JBossSecurityMgrRealm] End authenticate, principal=GenericPrincipal[kcturner()]
2006-01-07 14:08:54,590 DEBUG [org.apache.catalina.authenticator.AuthenticatorBase] Authenticated 'kcturner' with type 'BASIC'
2006-01-07 14:08:54,590 DEBUG [org.apache.catalina.authenticator.AuthenticatorBase] Calling accessControl()
2006-01-07 14:08:54,590 DEBUG [org.apache.catalina.realm.RealmBase] Checking roles GenericPrincipal[kcturner()]
2006-01-07 14:08:54,590 DEBUG [org.apache.catalina.realm.RealmBase] Username kcturner does NOT have role authorizedUser
2006-01-07 14:08:54,590 DEBUG [org.apache.catalina.realm.RealmBase] No role found: authorizedUser
2006-01-07 14:08:54,590 DEBUG [org.apache.catalina.authenticator.AuthenticatorBase] Failed accessControl() test
2006-01-07 14:08:54,606 TRACE [org.jboss.security.SecurityAssociation] clear, server=true