dev@glassfish.java.net

Re: Debugging Glassfish itself

From: Bobby Bissett <bobby.bissett_at_oracle.com>
Date: Tue, 4 May 2010 15:29:09 -0400

>
> 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


>
> .. then I did a new request for my secured page and on the JAAS
> login page entered my credentials and submitted.
> There is a lot of logging, but to be honest I still have no idea
> what is going wrong.
>
> Here is the logging output:
>
> 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
>
>
> The AuthorizationServlet is mine. It accepts incoming requests on
> the URL I configured in web-xml and forwards the request to the
> login.jsp using request.getRequestDispatcher("/WEB-INF/jsp/auth/
> login.jsp").forward(request, response)
>
> Relevant config in web.xml:
>
> <servlet>
> <servlet-name>AuthorizationServlet</servlet-name>
> <servlet-class>nl.planon.pv.auth.AuthorizationServlet</servlet-class>
> </servlet>
>
> <servlet-mapping>
> <servlet-name>AuthorizationServlet</servlet-name>
> <url-pattern>/auth/*</url-pattern>
> </servlet-mapping>
>
> <login-config>
> <auth-method>FORM</auth-method>
> <realm-name>PVPluimen</realm-name>
> <form-login-config>
> <form-login-page>/auth/login</form-login-page>
> <form-error-page>/auth/login?error=true</form-error-page>
> </form-login-config>
> </login-config>
>
>
>
>
>
> ----- Original Message ----- From: "Bobby Bissett" <bobby.bissett_at_oracle.com
> >
> To: <dev_at_glassfish.dev.java.net>
> Sent: Tuesday, May 04, 2010 7:55 PM
> Subject: Re: Debugging Glassfish itself
>
>
>> On May 4, 2010, at 12:52 PM, Stijn de Witt wrote:
>>>
>>> The issue I have is that my JDBCRealm setup seems Ok (I see realm
>>> being loaded) but I am unable to login. I have manually inserted
>>> a username and password in the DB (and set digest to none) but
>>> still it will not let me in with those credentials. The error
>>> messages are really vague (basically it just throws generic
>>> LoginException) so that is why I wanted to debug.
>>
>> In many cases, the fastest way to solve this isn't with the
>> debugger. Head on over to your friendly admin console, go to the
>> logging page, and turn the security logging up to finest. Then try
>> to log in again and quickly turn the logging back down to info.
>> Check the server log and you'll see what specific error caused the
>> problem.
>>
>> Cheers,
>> Bobby
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>