I am indeed attempting to setup form-based login using the JDBCRealm and
custom login and registration pages.
I looked at the Log Levels settings in the admin console (I am on v3) but I
didn't see anything else related to security but these two, that I both have
set to FINEST:
com.sun.enterprise.security
javax.enterprise.system.core.security
I restarted the server just to be sure and then did the following requests:
1) Request a secured page (gets redirected to login page)
2) Entered credentials in the login page and submitted (fails, redirects to
login page again)
3) Entered credentials again and submitted again
Below is the full logging I get for these three requests... I see it says
"... 34 more" below the last "Caused by" in the stack trace, but I have no
idea how I can actually see those 34 more lines.
Maybe I am still missing some logger output and need to set some other log
level to FINEST?
Anyway, this basically was the reason for me wanting to debug the thing; I
can't seem to get any useful info in the log to help me determine the cause
of these failing logins.
I am still trying to get debugging to work, but I have no idea how to set a
class-level breakpoint in Eclipse. I have found the sources for both
JDBCRealm and JDBCLoginModule, but I can't set a breakpoint as I have no
idea how to open these in Eclipse in the way that it's attached to the
running Glassfish instance...
Thanks for your patience with me!
-Stijn
FINEST: JACC Policy Provider: PolicyWrapper.getPermissions(cs), context
(pv/pv) codesource ((file:/pv/pv <no signer certificates>)) permissions:
java.security.Permissions_at_1dac13b (
(javax.security.auth.PrivateCredentialPermission
javax.resource.spi.security.PasswordCredential * "*" read)
(java.lang.RuntimePermission getClassLoader)
(java.lang.RuntimePermission loadLibrary.*)
(java.lang.RuntimePermission accessDeclaredMembers)
(java.lang.RuntimePermission getProtectionDomain)
(java.lang.RuntimePermission modifyThreadGroup)
(java.lang.RuntimePermission stopThread)
(java.lang.RuntimePermission setContextClassLoader)
(java.lang.RuntimePermission queuePrintJob)
(javax.management.MBeanPermission [com.sun.messaging.jms.*:*] *)
(java.net.SocketPermission localhost:1024- listen,resolve)
(java.net.SocketPermission * connect,resolve)
(java.util.PropertyPermission line.separator read)
(java.util.PropertyPermission java.vm.version read)
(java.util.PropertyPermission java.vm.specification.version read)
(java.util.PropertyPermission java.vm.specification.vendor read)
(java.util.PropertyPermission java.vendor.url read)
(java.util.PropertyPermission java.vm.name read)
(java.util.PropertyPermission * read,write)
(java.util.PropertyPermission os.name read)
(java.util.PropertyPermission java.vm.vendor read)
(java.util.PropertyPermission path.separator read)
(java.util.PropertyPermission java.specification.name read)
(java.util.PropertyPermission os.version read)
(java.util.PropertyPermission os.arch read)
(java.util.PropertyPermission java.class.version read)
(java.util.PropertyPermission java.version read)
(java.util.PropertyPermission file.separator read)
(java.util.PropertyPermission java.vendor read)
(java.util.PropertyPermission java.vm.specification.name read)
(java.util.PropertyPermission java.specification.version read)
(java.util.PropertyPermission java.specification.vendor read)
(javax.management.MBeanTrustPermission register)
(java.io.FilePermission <<ALL FILES>> read,write)
(java.io.FilePermission C:\Program
Files\Glassfish\glassfish-v3-web\glassfish\domains\domain1\lib\databases\-
delete)
(java.io.FilePermission C:\Users\Stijn\AppData\Local\Temp\\- delete)
(unresolved javax.security.jacc.WebUserDataPermission /events/* null)
(unresolved javax.security.jacc.WebUserDataPermission /:/events/* null)
(unresolved com.sun.corba.ee.impl.presentation.rmi.DynamicAccessPermission
access null)
(unresolved javax.security.jacc.WebResourcePermission /:/events/* null)
(unresolved com.sun.enterprise.security.CORBAObjectPermission * *)
)
FINE: [Web-Security] Setting Policy Context ID: old = null ctxID = pv/pv
FINE: [Web-Security] hasUserDataPermission perm:
(javax.security.jacc.WebUserDataPermission /events/create GET)
FINE: [Web-Security] hasUserDataPermission isGranted: true
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] Generating a protection domain for Permission check.
FINE: [Web-Security] Codesource with Web URL: file:/pv/pv
FINE: [Web-Security] Checking Web Permission with Principals : null
FINE: [Web-Security] Web Permission =
(javax.security.jacc.WebResourcePermission /events/create GET)
FINEST: JACC Policy Provider: PolicyWrapper.implies, context (pv/pv)- result
was(false) permission ((javax.security.jacc.WebResourcePermission
/events/create GET))
FINE: [Web-Security] hasResource isGranted: false
FINE: [Web-Security] hasResource perm:
(javax.security.jacc.WebResourcePermission /events/create GET)
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] hasUserDataPermission perm:
(javax.security.jacc.WebUserDataPermission /auth/login GET)
FINE: [Web-Security] hasUserDataPermission isGranted: true
INFO: AuthorizationServlet#doGet: Starting...
INFO: AuthorizationServlet#doGet: action=login
INFO: AuthorizationServlet#doLoginForm: Starting...
INFO: AuthorizationServlet#doLoginForm: Done.
INFO: AuthorizationServlet#doGet: Done.
FINE: SecurityContext: setCurrentSecurityContext method called
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] hasUserDataPermission perm:
(javax.security.jacc.WebUserDataPermission /auth/j_security_check POST)
FINE: [Web-Security] hasUserDataPermission isGranted: true
FINEST: Processing login with credentials of type: class
com.sun.enterprise.security.auth.login.common.PasswordCredential
FINE: Logging in user [admin] into realm: PVPluimen using JAAS module:
jdbcRealm
FINE: Login module initialized: class
com.sun.enterprise.security.auth.login.JDBCLoginModule
SEVERE: [LoginContext]: original security exception with detail msg
replaced by new exception with empty detail msg
SEVERE: [LoginContext]: original security exception:
com.sun.enterprise.security.auth.login.common.LoginException: Failed jdbc
login for admin.
SEVERE: [LoginContext]: login REQUIRED failure
FINE: JAAS authentication aborted.
SEVERE: [LoginContext]: abort ignored
FINEST: doPasswordLogin fails
javax.security.auth.login.LoginException: Security Exception
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:856)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
at javax.security.auth.login.LoginContext.login(LoginContext.java:579)
at
com.sun.enterprise.security.auth.login.LoginContextDriver.doPasswordLogin(LoginContextDriver.java:341)
at
com.sun.enterprise.security.auth.login.LoginContextDriver.login(LoginContextDriver.java:199)
at
com.sun.enterprise.security.auth.login.LoginContextDriver.login(LoginContextDriver.java:152)
at com.sun.web.security.RealmAdapter.authenticate(RealmAdapter.java:478)
at com.sun.web.security.RealmAdapter.authenticate(RealmAdapter.java:417)
at
org.apache.catalina.authenticator.FormAuthenticator.authenticate(FormAuthenticator.java:265)
at
org.apache.catalina.authenticator.AuthenticatorBase.processSecurityCheck(AuthenticatorBase.java:970)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:575)
at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:615)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97)
at
com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:85)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:185)
at
org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:332)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:233)
at
com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:165)
at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954)
at
com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170)
at
com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135)
at
com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102)
at
com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88)
at
com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
at
com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
at
com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
at com.sun.grizzly.ContextTask.run(ContextTask.java:69)
at
com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330)
at
com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.SecurityException
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:857)
... 34 more
WARNING: Web login failed: Login failed:
javax.security.auth.login.LoginException: Security Exception
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] hasUserDataPermission perm:
(javax.security.jacc.WebUserDataPermission /auth/login GET)
FINE: [Web-Security] hasUserDataPermission isGranted: true
INFO: AuthorizationServlet#doGet: Starting...
INFO: AuthorizationServlet#doGet: action=login
INFO: AuthorizationServlet#doLoginForm: Starting...
INFO: AuthorizationServlet#doLoginForm: Done.
INFO: AuthorizationServlet#doGet: Done.
FINE: SecurityContext: setCurrentSecurityContext method called
FINE: [Web-Security] Setting Policy Context ID: old = null ctxID = pv/pv
FINE: [Web-Security] hasUserDataPermission perm:
(javax.security.jacc.WebUserDataPermission /style.css GET)
FINE: [Web-Security] hasUserDataPermission isGranted: true
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] hasResource isGranted: true
FINE: [Web-Security] hasResource perm:
(javax.security.jacc.WebResourcePermission /style.css GET)
FINE: SecurityContext: setCurrentSecurityContext method called
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] hasUserDataPermission perm:
(javax.security.jacc.WebUserDataPermission /auth/j_security_check POST)
FINE: [Web-Security] hasUserDataPermission isGranted: true
FINEST: Processing login with credentials of type: class
com.sun.enterprise.security.auth.login.common.PasswordCredential
FINE: Logging in user [admin] into realm: PVPluimen using JAAS module:
jdbcRealm
FINE: Login module initialized: class
com.sun.enterprise.security.auth.login.JDBCLoginModule
SEVERE: [LoginContext]: original security exception with detail msg
replaced by new exception with empty detail msg
SEVERE: [LoginContext]: original security exception:
com.sun.enterprise.security.auth.login.common.LoginException: Failed jdbc
login for admin.
SEVERE: [LoginContext]: login REQUIRED failure
FINE: JAAS authentication aborted.
SEVERE: [LoginContext]: abort ignored
FINEST: doPasswordLogin fails
javax.security.auth.login.LoginException: Security Exception
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:856)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
at javax.security.auth.login.LoginContext.login(LoginContext.java:579)
at
com.sun.enterprise.security.auth.login.LoginContextDriver.doPasswordLogin(LoginContextDriver.java:341)
at
com.sun.enterprise.security.auth.login.LoginContextDriver.login(LoginContextDriver.java:199)
at
com.sun.enterprise.security.auth.login.LoginContextDriver.login(LoginContextDriver.java:152)
at com.sun.web.security.RealmAdapter.authenticate(RealmAdapter.java:478)
at com.sun.web.security.RealmAdapter.authenticate(RealmAdapter.java:417)
at
org.apache.catalina.authenticator.FormAuthenticator.authenticate(FormAuthenticator.java:265)
at
org.apache.catalina.authenticator.AuthenticatorBase.processSecurityCheck(AuthenticatorBase.java:970)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:575)
at
org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:615)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97)
at
com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:85)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:185)
at
org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:332)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:233)
at
com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:165)
at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954)
at
com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170)
at
com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135)
at
com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102)
at
com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88)
at
com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
at
com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
at
com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
at com.sun.grizzly.ContextTask.run(ContextTask.java:69)
at
com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330)
at
com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.SecurityException
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:857)
... 34 more
WARNING: Web login failed: Login failed:
javax.security.auth.login.LoginException: Security Exception
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] hasUserDataPermission perm:
(javax.security.jacc.WebUserDataPermission /auth/login GET)
FINE: [Web-Security] hasUserDataPermission isGranted: true
INFO: AuthorizationServlet#doGet: Starting...
INFO: AuthorizationServlet#doGet: action=login
INFO: AuthorizationServlet#doLoginForm: Starting...
INFO: AuthorizationServlet#doLoginForm: Done.
INFO: AuthorizationServlet#doGet: Done.
FINE: SecurityContext: setCurrentSecurityContext method called
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] hasUserDataPermission perm:
(javax.security.jacc.WebUserDataPermission /style.css GET)
FINE: [Web-Security] hasUserDataPermission isGranted: true
FINE: [Web-Security] Policy Context ID was: pv/pv
FINE: [Web-Security] hasResource isGranted: true
FINE: [Web-Security] hasResource perm:
(javax.security.jacc.WebResourcePermission /style.css GET)
FINE: SecurityContext: setCurrentSecurityContext method called
----- Original Message -----
From: "Bobby Bissett" <bobby.bissett_at_oracle.com>
To: <dev_at_glassfish.dev.java.net>
Sent: Tuesday, May 04, 2010 9:29 PM
Subject: Re: Debugging Glassfish itself
> >
>> I am not so handy with all Glassfish config tools etc. So sorry if I do
>> things wrong, you will have to spell it out for me...
>>
>> I edited
>>
>> /domains/domain1/config/logging.properties
>>
>> .. and added this line:
>>
>> com.sun.enterprise.security.level=FINEST
>
> While that works, we don't generally recommend it. You stopped the server
> first, right? :) The easier way is, with the server running, head to
> http://localhost:4848 for the admin console. For v2.1, do:
>
> Application-Server (left panel) -> Logging (main panel) -> Log Levels
>
> For v3:
>
> Configuration->Logger Settings (left panel) -> Log Levels (main panel)
>
> Anyway, you can use the above to change the levels back safely. Ok, onto
> the log.... It may be that you need the section of the log just after
> this. When a user tries to access a protected resource, there should be
> some initial failure, and then I see the /auth/login page is successfully
> accessed (form-based login, right?). So this log may not capture the
> failure when the user tries to log in. Want to check what's right after
> this? There should be, hopefully, a caused- by...caused-by...caused-by
> train and a root cause that lets you know what's going on, such as
> unknown user, wrong password, can't connect to DB, table not found, etc.
> Sooooo many things!
>
> Cheers,
> Bobby
>