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

    No ManagedConnections within a custom Login Module

    Bryan Cooper Newbie

      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