3 Replies Latest reply on Aug 17, 2005 10:25 AM by alexandre_correa

    No ManagedConnections within a custom Login Module

    cooperbry
    cooperbry Sep 20, 2004 3:32 PM

      Hi All,

      I'm using JBoss [WonderLand] 3.2.3 (build: CVSTag=JBoss_3_2_3 date=200311301445).
      I've written a custom server login module that does some jdbc database
      queries (extends AbstractServerLoginModule). Rather than extend the
      DatabaseServerLoginModule, I just wrote a method within the login
      module to access the database as follows:

       MyDAO myDAO = new myDAO();
 DataSource dataSource = null;
 Connection con = null;
 try {
 InitialContext ctxt = new InitialContext();
 dataSource =
 (DataSource)ctxt.lookup("java:/" + MyDAO.DS_JNDI_NAME);
 if (dataSource != null && !dataSource.getConnection().isClosed()) {
 con = dataSource.getConnection();
 userObj =
 myDAO.retrieveUser(
 con,
 userName);
 }
 } catch (Exception e) {
 logger.error(e);
 } finally {
 if (con != null) {
 try {
 con.close();
 logger.debug("Closing database connection.");
 } catch (SQLException se) {
 logger.error(se);
 }
 }
 }


      The server trace shows my "Closing database connection." message,
      but, doesn't show a JBoss trace that indicates that the connection has
      been returned. I would have expected to see (I think) a message from

      "[org.jboss.resource.connectionmanager...] Connection returned to
      pool." (something like that).

      The first time the login module executes, the following trace is displayed: 

      2004-09-20 15:03:44,937 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] internalRegisterPool: registering pool with interval 60000 old interval: 30000
2004-09-20 15:03:44,937 DEBUG [org.jboss.resource.adapter.jdbc.local.LocalManagedConnectionFactory] Using properties: {user=username, password=password}
2004-09-20 15:03:44,937 DEBUG [org.jboss.resource.adapter.jdbc.local.LocalManagedConnectionFactory] Checking driver for URL: jdbc:oracle:thin:@localhost:1521:phora01
2004-09-20 15:03:44,937 DEBUG [org.jboss.resource.adapter.jdbc.local.LocalManagedConnectionFactory] Driver already registered for url: jdbc:oracle:thin:@localhost:1521:phora01
2004-09-20 15:03:44,968 DEBUG [org.jboss.resource.adapter.jdbc.local.LocalManagedConnectionFactory] Using properties: {user=username, password=password}


      After the login module executes several times, ultimately, the result is a
      stack trace as follows: 

      2004-09-20 15:03:57,203 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Closing database connection.
2004-09-20 15:03:57,203 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing validatePassword method.
2004-09-20 15:03:57,203 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Validating securityUser role
2004-09-20 15:03:57,203 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Login success!
2004-09-20 15:03:57,203 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing commit method.
2004-09-20 15:03:57,203 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing getIdentity method.
2004-09-20 15:03:57,203 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing getRoleSets method.
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing commit method.
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing getIdentity method.
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing getRoleSets method.
2004-09-20 15:03:57,218 TRACE [org.jboss.security.plugins.JaasSecurityManager.trialBuilder] updateCache, subject=Subject:
 Principal: coopebr2
 Principal: Roles(members:eCRF Developer,login,coopebr2)
 Principal: 200 - coopebr2 isValid[true] isActive[true]

2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing getIdentity method.
2004-09-20 15:03:57,218 DEBUG [org.jboss.ejb.plugins.LogInterceptor] Invoke: openTrial(-1)
2004-09-20 15:03:57,218 TRACE [org.jboss.security.plugins.JaasSecurityManager.trialBuilder] validateCache, info=org.jboss.security.plugins.JaasSecurityManager$DomainInfo@1665a0d
2004-09-20 15:03:57,218 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] getAppConfigurationEntry(trialBuilder), authInfo=AppConfigurationEntry[]:
[0]
LoginModule Class: com.novartis.edms.jaas.server.EDMSServerLoginModule
ControlFlag: LoginModuleControlFlag: required
Options:
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] initialize method called
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing login method.
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Handling callback SecurityAssociationCallback
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] userName: coopebr2
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] password:·'kÙ¼Èv¸AE~ÂÂÂ� ¾Â€·Ø,ێc¤G¾ÃÂÂ�Fr
2004-09-20 15:03:57,218 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Validating securityUser name and password
2004-09-20 15:04:02,234 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.parentTraceEnabled=true
2004-09-20 15:04:02,234 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.nestedTraceEnabled=false
2004-09-20 15:04:02,234 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.detectDuplicateNesting=true
2004-09-20 15:04:02,234 ERROR [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] org.jboss.util.NestedSQLException: No ManagedConnections available within configured blocking timeout ( 5000 [ms] );
 - nested throwable: (javax.resource.ResourceException: No ManagedConnections available within configured blocking timeout ( 5000 [ms] ))
2004-09-20 15:04:02,234 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing validatePassword method.
2004-09-20 15:04:02,234 ERROR [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] java.lang.NullPointerException
2004-09-20 15:04:02,234 INFO [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Validation failed for securityUser null
2004-09-20 15:04:02,234 DEBUG [com.novartis.edms.jaas.server.ServerLoginModuleAdapter] Executing abort method.
2004-09-20 15:04:02,234 DEBUG [org.jboss.security.plugins.JaasSecurityManager.trialBuilder] Login failure
javax.security.auth.login.LoginException: java.lang.NullPointerException
 at com.novartis.edms.jaas.server.EDMSServerLoginModule.validateUser(EDMSServerLoginModule.java:229)
 at com.novartis.edms.jaas.server.EDMSServerLoginModule.authenticateOnServer(EDMSServerLoginModule.java:90)
 at com.novartis.edms.jaas.server.EDMSServerLoginModule.login(EDMSServerLoginModule.java:108)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:324)
 at javax.security.auth.login.LoginContext.invoke(LoginContext.java:675)
 at javax.security.auth.login.LoginContext.access$000(LoginContext.java:129)
 at javax.security.auth.login.LoginContext$4.run(LoginContext.java:610)
 at java.security.AccessController.doPrivileged(Native Method)
 at javax.security.auth.login.LoginContext.invokeModule(LoginContext.java:607)
 at javax.security.auth.login.LoginContext.login(LoginContext.java:534)
 at org.jboss.security.plugins.JaasSecurityManager.defaultLogin(JaasSecurityManager.java:487)
 at org.jboss.security.plugins.JaasSecurityManager.authenticate(JaasSecurityManager.java:442)
 at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:244)
 at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:219)
 at org.jboss.ejb.plugins.SecurityInterceptor.checkSecurityAssociation(SecurityInterceptor.java:160)
 at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:107)
 at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
 at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
 at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
 at org.jboss.ejb.Container.invoke(Container.java:700)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:324)
 at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
 at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:546)
 at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:367)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:324)
 at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261)
 at sun.rmi.transport.Transport$1.run(Transport.java:148)
 at java.security.AccessController.doPrivileged(Native Method)
 at sun.rmi.transport.Transport.serviceCall(Transport.java:144)
 at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
 at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
 at java.lang.Thread.run(Thread.java:534)

 at javax.security.auth.login.LoginContext.invoke(LoginContext.java:730)
 at javax.security.auth.login.LoginContext.access$000(LoginContext.java:129)
 at javax.security.auth.login.LoginContext$4.run(LoginContext.java:610)
 at java.security.AccessController.doPrivileged(Native Method)
 at javax.security.auth.login.LoginContext.invokeModule(LoginContext.java:607)
 at javax.security.auth.login.LoginContext.login(LoginContext.java:534)
 at org.jboss.security.plugins.JaasSecurityManager.defaultLogin(JaasSecurityManager.java:487)
 at org.jboss.security.plugins.JaasSecurityManager.authenticate(JaasSecurityManager.java:442)
 at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:244)
 at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:219)
 at org.jboss.ejb.plugins.SecurityInterceptor.checkSecurityAssociation(SecurityInterceptor.java:160)
 at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:107)
 at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
 at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
 at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
 at org.jboss.ejb.Container.invoke(Container.java:700)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:324)
 at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
 at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:546)
 at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:367)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:324)
 at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261)
 at sun.rmi.transport.Transport$1.run(Transport.java:148)
 at java.security.AccessController.doPrivileged(Native Method)
 at sun.rmi.transport.Transport.serviceCall(Transport.java:144)
 at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
 at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
 at java.lang.Thread.run(Thread.java:534)


      I've turned on the following attributes in the transaction-service.xml 
       <attribute name="SpecCompliant">true</attribute>
 <attribute name="Debug">true</attribute>

      and that didn't seem to do anything. I'm sure the resultSets,
      preparedStatements and connection are being closed because I write a
      trace for each of these.


      1) Is there some way that I can return a connection to the pool
      programatically?

      2) Should I be handling the connections differently?

      Thanks in advance for any help you could offer!
      Bryan Cooper

      • 3041 Views
      • Tags:
        • 1. Re: No ManagedConnections within a custom Login Module
          kdeboer Sep 20, 2004 3:58 PM (in response to cooperbry)

          Closing a connection retrieved from a datasource is equal to returning it to the pool. Looking at your code it seems you retrieve two connections from the pool.
          It is better to test the connection after you retrieved it from the datasource.
          Now you fetch it twice. Or am i completely wrong?

            • Actions
          • 2. Re: No ManagedConnections within a custom Login Module
            cooperbry
            cooperbry Sep 20, 2004 4:06 PM (in response to cooperbry)

             

             if (dataSource != null && !dataSource.getConnection().isClosed()) {
 con = dataSource.getConnection();
 userObj =
 myDAO.retrieveUser(
 con,
 userName);
 }


            You are correct! Thanks for the second pair of eyes and the quick reply!
            Bryan Cooper

              • Actions
            • 3. Re: No ManagedConnections within a custom Login Module
              alexandre_correa
              alexandre_correa Aug 17, 2005 10:25 AM (in response to cooperbry)

              I guess I'm facing the same problem, but I couldn't understand how did you get to solve it.

              When I get the connection from datasource, I'm not testing if it's closed or not, but I think there's no problem with that.

              The problem is when I close the connection, it is not being returned to the pool. And for my log I see that it's being correctly closed.

              In this way, I can perform as many requests as the number of connections I've setted as maximum.

              Could you both help me in this?

              Thanks,
              Alexandre

                • Actions