10 Replies Latest reply on Jun 15, 2004 6:09 PM by gturner

    Yet another principal=null case

    lbasili

      Hello,
      I have recently moved from jboss-3.2.0 to jboss-3.2.3. I have the problem of a null principal when using ClientLoginModule.
      I read several message about this problem, but I was not able to find a solution there.

      Can you help me ?
      Thank you very much.


      To isolate the problem, I wrote the following jsp that performs login and executes a method on an EJB:

      <%@ page import="java.io.*" %>
      <%@ page import="javax.naming.*" %>
      <%@ page import="javax.rmi.PortableRemoteObject" %>
      <%@ page import="javax.security.auth.callback.Callback" %>
      <%@ page import="javax.security.auth.callback.CallbackHandler" %>
      <%@ page import="javax.security.auth.callback.NameCallback" %>
      <%@ page import="javax.security.auth.callback.PasswordCallback" %>
      <%@ page import="javax.security.auth.callback.UnsupportedCallbackException" %>
      <%@ page import="javax.security.auth.login.LoginContext" %>
      <%@ page import="javax.security.auth.login.LoginException" %>
      <%@ page import="ztc.ejb.interfaces.sc.*" %>
      <%@ page import="ztc.vo.PostLoginData" %>
      
       <%
       CallbackHandler callback = new CallbackHandler() {
       public void handle(Callback[] callbacks)
       throws IOException, UnsupportedCallbackException {
       for (int i=0;i<callbacks.length;i++){
       if (callbacks instanceof NameCallback)
       {
       NameCallback nc =
       (NameCallback) callbacks;
       nc.setName("root");
       }
       else if (callbacks instanceof PasswordCallback)
       {
       PasswordCallback pc =
       (PasswordCallback) callbacks;
       String pwd = "changeme";
       pc.setPassword(pwd.toCharArray());
       }
       }
       }
       };
       try {
       LoginContext lc = new LoginContext(
       "other"
       ,callback
       );
       lc.login();
       }catch(LoginException neverThrown){
       }
      
       Context ctx = new InitialContext();
       Object ref = ctx.lookup("SessionController");
       SessionControllerHome home = (SessionControllerHome)
       PortableRemoteObject.narrow(ref,SessionControllerHome.class);
       SessionController sc = home.create();
       PostLoginData data = sc.getPostLoginData();
      %>
      Data is <%=data%>
      


      I obtain the exception:

      java.rmi.ServerException: EJBException:; nested exception is:
      javax.ejb.EJBException: checkSecurityAssociation; CausedByException is:
      Authentication exception, principal=null
      at org.jboss.ejb.plugins.LogInterceptor.handleException(LogInterceptor.java:347)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:195)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
      at org.jboss.ejb.StatefulSessionContainer.internalInvoke(StatefulSessionContainer.java:416)
      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.local.LocalInvoker.invoke(LocalInvoker.java:101)
      at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:90)
      at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
      at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:45)
      at org.jboss.proxy.ejb.StatefulSessionInterceptor.invoke(StatefulSessionInterceptor.java:104)
      at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:85)
      at $Proxy50.getPostLoginData(Unknown Source)
      at org.apache.jsp.prova_jsp._jspService(prova_jsp.java:100)
      at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:137)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
      at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:210)
      at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295)
      at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
      at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
      at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
      at org.jboss.web.tomcat.security.JBossSecurityMgrRealm.invoke(JBossSecurityMgrRealm.java:220)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      at org.apache.catalina.valves.CertificatesValve.invoke(CertificatesValve.java:246)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      at org.jboss.web.tomcat.tc4.statistics.ContainerStatsValve.invoke(ContainerStatsValve.java:76)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
      at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
      at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2417)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
      at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:577)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
      at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)
      at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
      at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
      at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
      at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:197)
      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:781)
      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:549)
      at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:605)
      at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:677)
      at java.lang.Thread.run(Thread.java:534)
      Caused by: javax.ejb.EJBException: checkSecurityAssociation; CausedByException is:
      Authentication exception, principal=null
      at org.jboss.ejb.plugins.SecurityInterceptor.checkSecurityAssociation(SecurityInterceptor.java:165)
      at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:107)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:185)
      at org.jboss.ejb.plugins.StatefulSessionInstanceInterceptor.invoke(StatefulSessionInstanceInterceptor.java:269)
      at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
      at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
      at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
      ... 62 more


      Here is my application policy (into login-config.xml)

      <application-policy name = "other">

      <login-module code = "org.jboss.security.ClientLoginModule"
      flag = "required">
      <module-option name="multi-threaded" >true</module-option>
      </login-module>
      <login-module
      code = "ztc.security.auth.jboss.EnhancedLdapLoginModule"
      flag = "required" >
      <module-option name="java.naming.factory.initial" >com.sun.jndi.ldap.LdapCtxFa
      ctory</module-option>
      <module-option name="java.naming.provider.url" >ldap://localhost</module-option>
      <module-option name="java.naming.security.authentication" >simple</module-option>
      </login-module>

      </application-policy>


      Here is a part of the jboss.xml


      <!-- All bean containers use this security manager by default -->
      <security-domain>java:/jaas/other</security-domain>
      <enterprise-beans>

      <ejb-name>SessionController</ejb-name>
      <resource-ref>
      <res-ref-name>eis/ldap</res-ref-name>
      <res-type>ztc.dao.DAOFactory</res-type>
      <jndi-name>java:/NoTransLDAP</jndi-name>
      </resource-ref>




      Here is a part of ejb-jar.xml

      <?xml version="1.0" ?>
      <!DOCTYPE ejb-jar PUBLIC
      "-//Sun Microsystems, Inc.//DTD Enterprise JavaBeans 2.0//EN"
      "http://java.sun.com/j2ee/dtds/ejb-jar_2_0.dtd">

      <ejb-jar>
      <assembly-descriptor>
      <security-role>
      <role-name>root</role-name>
      The root of the ZTC Server
      </security-role>
      <security-role>
      <role-name>authenticated</role-name>
      Any authenticated user
      </security-role>
      <security-role>
      <role-name>viewers</role-name>
      Users that can view
      </security-role>
      <security-role>
      <role-name>cmodifiers</role-name>
      Users that can modify configurations
      </security-role>
      <security-role>
      <role-name>smodifiers</role-name>
      Users that can modify struct nodes
      </security-role>
      <security-role>
      <role-name>cadders</role-name>
      Users that can add config nodes
      </security-role>
      <security-role>
      <role-name>sadders</role-name>
      Users that can add struct nodes
      </security-role>
      <security-role>
      <role-name>cdeleters</role-name>
      Users that can delete config nodes
      </security-role>
      <security-role>
      <role-name>sdeleters</role-name>
      Users that can delete struct nodes
      </security-role>
      <security-role>
      <role-name>internal</role-name>
      Internal user not assigned to remote clients
      </security-role>

      <method-permission>
      <role-name>authenticated</role-name>

      <ejb-name>SessionController</ejb-name>
      <method-name>*</method-name>


      <ejb-name>PostLogger</ejb-name>
      <method-name>*</method-name>

      </method-permission>
      </assembly-descriptor>
      ZTC Server EJB Objects
      <display-name>ZTC Server EJB Objects</display-name>
      <enterprise-beans>

      <display-name>SessionController</display-name>
      Session facade for the ZTC Server application
      <ejb-name>SessionController</ejb-name>
      ztc.ejb.interfaces.sc.SessionControllerHome
      ztc.ejb.interfaces.sc.SessionController
      <ejb-class>ztc.ejb.beanimpl.sc.SessionControllerBean</ejb-class>
      <session-type>Stateful</session-type>
      <transaction-type>Container</transaction-type>
      true
      <allow-concurrent-calls>true</allow-concurrent-calls>
      <env-entry>
      <env-entry-name>DeployEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.DeployEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>EchoEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.EchoEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>UserMngEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.UserMngEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>UserPermEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.UserPermEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>ConfigRequestEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.ConfigRequestEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>ConfigTestEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.ConfigTestEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>ConfigUpdateEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.ConfigUpdateEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>LoginEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.LoginEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>DataModelUpdateEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.DataModelEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>DataDefinitionEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.DataDefinitionEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>ViewUpdateEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.ViewUpdateEventHandler</env-entry-value>
      </env-entry>
      <env-entry>
      <env-entry-name>ViewReadEvent</env-entry-name>
      <env-entry-type>java.lang.String</env-entry-type>
      <env-entry-value>ztc.event.handlers.ViewReadEventHandler</env-entry-value>
      </env-entry>
      <resource-ref>
      <res-ref-name>eis/ldap</res-ref-name>
      <res-type>ztc.dao.DAOFactory</res-type>
      <res-auth>Container</res-auth>
      <res-sharing-scope>Unshareable</res-sharing-scope>
      </resource-ref>


      <display-name>PostLogger</display-name>
      A Session Bean that performs post-login actions
      <ejb-name>PostLogger</ejb-name>
      ztc.ejb.interfaces.postlogger.PostLoggerHome
      ztc.ejb.interfaces.postlogger.PostLogger
      <ejb-class>ztc.ejb.beanimpl.postlogger.PostLoggerBean</ejb-class>
      <session-type>Stateless</session-type>
      <transaction-type>Container</transaction-type>
      <resource-ref>
      <res-ref-name>eis/ldap</res-ref-name>
      <res-type>ztc.dao.DAOFactory</res-type>
      <res-auth>Container</res-auth>
      <res-sharing-scope>Unshareable</res-sharing-scope>
      </resource-ref>

      </enterprise-beans>
      </ejb-jar>



        • 1. Re: Yet another principal=null case
          gturner

          Thanks for your reply jburugupalli, I believe I understand the thread local nature of JAAS, and have coded the logout exactly as you have suggested.

          Each request to the servlet I have is:


          Instantiating a LoginContext along with newly instantiated username/password CallbackHandler.

          Invoking LoginContext.login().

          Performing an external JNDI lookup of the remote home interface of a Stateless Session Bean.

          Creating the session bean instance.

          Invoking one method on the session bean.

          Removing the session bean enclosed in a finally block with try starting at the previous step.

          Invoking LoginContext.logout() enclosed in a finally block with try starting all the way back to JNDI lookup.


          Here is the method which is doing all of the above:

           public Prequalification prequalify(User user,
           Address address,
           String phone,
           String serviceType,
           String interfaceType)
           throws SimilarAddressesFoundException,
           AddressNotFoundException {
          
           LoginContext loginContext;
           try {
           loginContext =
           WaveAuth.createLoginContext(user.getUsername(),
           user.getPassword());
           }
           catch (Exception e) {
           String message = "Failed to begin authentication of User "
           + user + " to Wave: " + Strings.exceptionToString(e);
           throw new AddressNotFoundException(message, e);
           }
          
           try {
           loginContext.login();
           }
           catch (Exception e) {
           String message = "Failed to login User " + user + " to Wave"
           + ": " + Strings.exceptionToString(e);
           throw new AddressNotFoundException(message, e);
           }
          
           PrequalifyAddressRequest request = new PrequalifyAddressRequest();
           PrequalificationAddress requestAddress = new PrequalificationAddress();
           request.setAddress(requestAddress);
           requestAddress.setStreet(address.getStreet1());
           requestAddress.setCity(address.getCity());
           requestAddress.setState(StateAbbreviation.getEnum(address.getState()));
           requestAddress.setZip(address.getZip());
           PrequalificationPhone requestPhone = new PrequalificationPhone();
           request.setPhone(requestPhone);
           String[] phones = Strings.parsePhone(phone);
           if (phones.length > 0)
           requestPhone.setAreaCode(phones[0]);
           if (phones.length > 1)
           requestPhone.setExchangeCode(phones[1]);
           if (phones.length > 2)
           requestPhone.setLine(phones[2]);
          
           PrequalifyAddressResponse response = null;
           try {
           Properties environment = null;
           try {
           environment =
           Jndi.getProperties(Constants.ENV_WAVE_CONTEXT_ENVIRONMENT);
           }
           catch (Exception ignore) {
           log.error("prequalify: Failed to get environment entry "
           + Constants.ENV_WAVE_CONTEXT_ENVIRONMENT, ignore);
           environment = new Properties();
           }
          
           PrequalificationHome prequalificationHome = null;
           try {
           prequalificationHome =
           (PrequalificationHome) Jndi.getObject
           (environment,
           PrequalificationHome.JNDI_NAME);
           }
           catch (Exception e) {
           String message =
           "Failed to lookup Prequalification: " + e.getMessage();
           throw new AddressNotFoundException(message, e);
           }
          
           com.newedgenetworks.phoenix.ejb.session.Prequalification
           prequalificationBean = null;
           boolean removeFailureExpected = false;
           try {
           prequalificationBean = prequalificationHome.create();
           response = prequalificationBean.prequalifyAddress(request);
           }
           catch (Exception e) {
           removeFailureExpected = true;
           throw new AddressNotFoundException(e.getMessage(), e);
           }
           finally {
           if (prequalificationBean != null)
           try {
           prequalificationBean.remove();
           }
           catch (Exception e) {
           String message = "Failed to remove Prequalification: "
           + Strings.exceptionToString(e);
           if (removeFailureExpected)
           log.warn("prequalify: " + message);
           else
           log.error("prequalify: " + message, e);
           }
           }
           }
           finally {
           try {
           loginContext.logout();
           }
           catch (Exception e) {
           String message = "Failed to logout User " + user
           + "from Wave: " + Strings.exceptionToString(e);
           log.error("prequalify: " + message, e);
           }
           }
          
           if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
           Prequalification prequalification = new Prequalification();
           prequalification.setPhone(phone);
           prequalification.setServiceType(serviceType);
           prequalification.setInterfaceType(interfaceType);
           if (response.getDistance() != null)
           prequalification.setDistance
           ((int) response.getDistance().doubleValue());
           Address prequalificationAddress = new Address();
           prequalification.setAddress(prequalificationAddress);
           prequalificationAddress.setValidated(Boolean.TRUE);
           prequalificationAddress.setValidationDate(new Date());
           PrequalificationAddress responseAddress =
           response.getQualifiedAddress();
           prequalificationAddress.setStreet1(responseAddress.getStreet());
           prequalificationAddress.setCity(responseAddress.getCity());
           if (responseAddress.getState() != null)
           prequalificationAddress.setState
           (responseAddress.getState().getValue());
           prequalificationAddress.setZip(responseAddress.getZip());
           CentralOffice prequalificationCentralOffice = new CentralOffice();
           prequalification.setCentralOffice(prequalificationCentralOffice);
           prequalificationCentralOffice.setClli
           (response.getWirecenterCode());
          
           return prequalification;
           }
           else if (PrequalificationStatus.SIMILAR_ADDRESSES_FOUND
           .equals(response.getStatus())) {
           Address[] addresses = null;
           if (response.getSimilarAddresses() != null)
           addresses =
           new Address[response.getSimilarAddresses().length];
           else
           addresses = new Address[0];
          
           for (int index = 0; index < addresses.length; index++) {
           Address prequalificationAddress = new Address();
           addresses[index] = prequalificationAddress;
           PrequalificationAddress responseAddress =
           response.getSimilarAddresses()[index];
           prequalificationAddress.setStreet1
           (responseAddress.getStreet());
           prequalificationAddress.setCity(responseAddress.getCity());
           if (responseAddress.getState() != null)
           prequalificationAddress.setState
           (responseAddress.getState().getValue());
           prequalificationAddress.setZip(responseAddress.getZip());
           }
          
           throw new SimilarAddressesFoundException(addresses);
           }
           else {
           throw new AddressNotFoundException("Address not found");
           }
          
           }
          


          The remote Tomcat 4.0 (where the above code is executed) has a copy of the JBoss auth.conf and is used by System property java.security.auth.login.config, however I am using "client-login" instead of "other" which lbasili is using in the code he posted, I forgot what the purpose of that was, but it's been runing for years, growing from JBoss 3.0 to 3.2!

          The Tomcat and JBoss processes happen to be running on the same server in this test (different servers in production), different VMs though, the server is clunkly old Sun SMP hardware (2 CPUs).

          Maybe this is of interest: The method of the Stateless Session bean that is being invoked (Prequalification.prequalifyAddress) has "unchecked" security declaration, however Entity Beans that are being invoked (finders and getters) do have security declarations. In the rare circumstance when the "principal=null" SecurityException is thrown, the violation occurs at the first Entity Bean finder invoked within the prequalify method.

          Here is the exception being thrown on the JBoss side:

          2004-05-28 02:41:57,492 32361464 ERROR [org.jboss.ejb.plugins.LogInterceptor] (RMI TCP Connection(2891)-192.168.30.24:) EJBException, causedBy:
          java.lang.SecurityException: Insufficient method permissions, principal=null, method=findByLongitudeAndLatitude, interface=LOCALHOME, requiredRoles=[Administrator, WireCenter View], principalRoles=[]
           at org.jboss.ejb.plugins.SecurityInterceptor.checkSecurityAssociation(SecurityInterceptor.java:229)
           at org.jboss.ejb.plugins.SecurityInterceptor.invokeHome(SecurityInterceptor.java:81)
           at org.jboss.ejb.plugins.LogInterceptor.invokeHome(LogInterceptor.java:120)
           at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invokeHome(ProxyFactoryFinderInterceptor.java:93)
           at org.jboss.ejb.EntityContainer.internalInvokeHome(EntityContainer.java:483)
           at org.jboss.ejb.Container.invoke(Container.java:720)
           at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invokeHome(BaseLocalProxyFactory.java:293)
           at org.jboss.ejb.plugins.local.LocalHomeProxy.invoke(LocalHomeProxy.java:110)
           at $Proxy185.findByLongitudeAndLatitude(Unknown Source)
           at com.newedgenetworks.phoenix.ejb.session.PrequalificationBean.prequalifyAddress(PrequalificationBean.java:375)
           at sun.reflect.GeneratedMethodAccessor82.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
           at java.lang.reflect.Method.invoke(Method.java:324)
           at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)
           at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:185)
           at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
           at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
           at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
           at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
           at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:118)
           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.GeneratedMethodAccessor67.invoke(Unknown Source)
           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.GeneratedMethodAccessor70.invoke(Unknown Source)
           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)
          
          
          Here is the method in the Stateless Session Bean:
          
          
           /**
           * Prequalify an address.
           *
           * @ejb.interface-method
           *
           * @jboss-net.web-method
           */
           public PrequalifyAddressResponse prequalifyAddress
           (PrequalifyAddressRequest request)
           throws PrequalificationException {
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: Request " + request);
          
           if (request == null)
           throw new PrequalificationException("Request required");
          
           PrequalificationAddress address = request.getAddress();
           if (address == null)
           throw new PrequalificationException("Address required");
           if (StringUtils.isBlank(address.getStreet()))
           throw new PrequalificationException("Street required");
           if (StringUtils.isBlank(address.getCity()))
           throw new PrequalificationException("City required");
           if (address.getState() == null)
           throw new PrequalificationException("State required");
           if (StringUtils.isBlank(address.getZip()))
           throw new PrequalificationException("Zip required");
          
           PrequalificationPhone phone = request.getPhone();
           if (phone == null)
           throw new PrequalificationException("Phone required");
           if (StringUtils.isBlank(phone.getAreaCode()))
           throw new PrequalificationException("Area Code required");
           if (StringUtils.isBlank(phone.getExchangeCode()))
           throw new PrequalificationException("Exchange Code required");
          
           String phoneString =
           phone.getAreaCode()
           + "-" + phone.getExchangeCode()
           + "-" + (StringUtils.isBlank(phone.getLine())
           ? "0000"
           : phone.getLine());
          
           PrequalifyAddressResponse response =
           new PrequalifyAddressResponse();
           response.setStatus(PrequalificationStatus.ADDRESS_NOT_FOUND);
          
           InetAddress host = BeanUtil.getInetAddress("MapMarkerHost");
           MapMarkerClient client;
           try {
           client = new MapMarkerClient(host, OncRpcProtocols.ONCRPC_TCP);
           OncRpcTcpClient innerClient = (OncRpcTcpClient) client.getClient();
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: ONC/RPC timeout was "
           + innerClient.getTimeout() + "ms and "
           + "transmission timeout was "
           + innerClient.getTransmissionTimeout() + "ms");
          
           innerClient.setTimeout(ONCRPC_TIMEOUT);
           innerClient.setTransmissionTimeout(ONCRPC_TIMEOUT);
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: ONC/RPC timeout is now "
           + innerClient.getTimeout() + "ms and "
           + "transmission timeout is now "
           + innerClient.getTransmissionTimeout() + "ms");
           }
           catch (Exception e) {
           String message =
           "Failed to establish MapMarker connection with " + host
           + ": " + e.getMessage();
           log.error("prequalifyAddress: " + message, e);
           throw new PrequalificationException(message, e);
           }
          
           try {
           Handle handle = new Handle();
           handle.geocode = 1;
           handle.server = RandomUtils.nextLong();
          
           GeocodeAddressRequest geocodeRequest =
           new GeocodeAddressRequest();
           geocodeRequest.handle = handle;
           geocodeRequest.relaxFlags = RelaxFlags.DEFAULT;
           geocodeRequest.linearInset = 0.0;
           geocodeRequest.perpendicularSetback = 0.0;
           geocodeRequest.distUnit = -1;
           geocodeRequest.relaxDistance = -1;
           geocodeRequest.firm = "";
           geocodeRequest.street = address.getStreet();
           geocodeRequest.city = address.getCity();
           geocodeRequest.state = address.getState().getValue();
           geocodeRequest.zip = address.getZip();
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: MapMarker request: "
           + ToStringBuilder.reflectionToString
           (geocodeRequest));
          
           GeocodeAddressResponse geocodeResponse;
           try {
           geocodeResponse =
           client.geocodeAddress_1(geocodeRequest);
           }
           catch (Exception e) {
           String message =
           "Failed to geocode address: " + e.getMessage();
           log.error("prequalifyAddress: " + message, e);
           throw new PrequalificationException(message, e);
           }
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: MapMarker response: "
           + ToStringBuilder.reflectionToString
           (geocodeResponse));
          
           if (geocodeResponse.numCandidates.length != 1
           || geocodeResponse.numCloseCandidates.length != 1)
           log.error("prequalifyAddress: Expected numCandidates and "
           + "numCloseCandidates fields in MapMarker "
           + "GeocodeAddressResponse to contain only one "
           + "element: "
           + ToStringBuilder.reflectionToString
           (geocodeResponse));
          
           if ((geocodeResponse.numCloseCandidates.length > 0
           && geocodeResponse.numCloseCandidates[0] > 0)
           || (geocodeResponse.numCandidates.length > 0
           && geocodeResponse.numCandidates[0] > 0)) {
           PrequalificationAddress[] addresses = null;
           int addressesLength = 0
          
           if (geocodeResponse.numCloseCandidates[0] > 0)
           addressesLength = geocodeResponse.numCloseCandidates[0];
           else
           addressesLength = geocodeResponse.numCandidates[0];
          
           if (addressesLength > 10)
           addressesLength = 10;
          
           addresses = new PrequalificationAddress[addressesLength];
          
           for (int index = 0; index < addressesLength; index++) {
           CandidateRequest candidateRequest = new CandidateRequest();
           candidateRequest.handle = geocodeResponse.handle;
           candidateRequest.candidateNumber = index;
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: MapMarker request: "
           + ToStringBuilder.reflectionToString
           (candidateRequest));
          
           CandidateResponse candidateResponse;
           try {
           candidateResponse =
           client.getCandidate_1(candidateRequest);
           }
           catch (Exception e) {
           String message =
           "Failed to retrieve candidate: " + e.getMessage();
           log.error("prequalifyAddress: " + message, e);
           throw new PrequalificationException(message, e);
           }
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: MapMarker response: "
           + ToStringBuilder.reflectionToString
           (candidateResponse));
          
           if (candidateResponse.status != 0) {
           String message =
           "Invalid status while retrieving candidate: "
           + candidateResponse.status + "; "
           + "MapMarker resonse: "
           + ToStringBuilder.reflectionToString
           (candidateResponse);
           log.error("prequalifyAddress: " + message);
           throw new PrequalificationException(message);
           }
          
           PrequalificationAddress candidateAddress =
           new PrequalificationAddress();
           addresses[index] = candidateAddress;
          
           candidateAddress.setStreet(candidateResponse.street);
           candidateAddress.setCity(candidateResponse.city);
           candidateAddress.setState
           (StateAbbreviation.getEnum(candidateResponse.state));
           if (candidateResponse.zip != null)
           candidateAddress.setZip
           (candidateResponse.zip
           + (StringUtils.isNotBlank
           (candidateResponse.plus4)
           ? "-" + candidateResponse.plus4
           : ""));
          
           boolean qualified = false;
           if (index == 0) {
           if (BEST_RESULT_CODE.equals
           (candidateResponse.resultCode)
           && geocodeResponse.numCloseCandidates[0] > 0) {
           qualified = true;
           }
           else if (match(address, candidateAddress)) {
           qualified = true;
          
           if (!BEST_RESULT_CODE.equals
           (candidateResponse.resultCode))
           log.warn("prequalifyAddress: Probably "
           + "allowing approximate match too "
           + "soon; "
           + request + "; "
           + ToStringBuilder.reflectionToString
           (geocodeResponse) + "; "
           + ToStringBuilder.reflectionToString
           (candidateResponse));
           }
           }
          
           if (qualified) {
           response.setStatus(PrequalificationStatus.SUCCESS);
          
           response.setQualifiedAddress(candidateAddress);
          
           if (candidateResponse.longitude.length != 1)
           log.error("prequalifyAddress: Expected longitude "
           + "field in MapMarker CandidateResponse "
           + "to contain only one element: "
           + ToStringBuilder.reflectionToString
           (candidateResponse));
          
           if (candidateResponse.longitude.length > 0)
           response.setAddressLongitude
           (new Double(candidateResponse.longitude[0]));
          
           if (candidateResponse.latitude.length != 1)
           log.error("prequalifyAddress: Expected latitude "
           + "field in MapMarker CandidateResponse "
           + "to contain only one element: "
           + ToStringBuilder.reflectionToString
           (candidateResponse));
          
           if (candidateResponse.latitude.length > 0)
           response.setAddressLatitude
           (new Double(candidateResponse.latitude[0]));
          
           break;
           }
           }
          
           if (!PrequalificationStatus.SUCCESS.equals
           (response.getStatus())) {
           response.setStatus
           (PrequalificationStatus.SIMILAR_ADDRESSES_FOUND);
           response.setSimilarAddresses(addresses);
           }
           }
           }
           finally {
           if (client != null)
           try {
           client.close();
           client = null;
           }
           catch (Exception e) {
           log.error("prequalifyAddress: Failed to close MapMarker "
           + "connection with " + host
           + ": " + e.getMessage(), e);
           }
           }
          
           boolean wireCenterDifferent = false;
           WireCenterLocal wireCenter = null;
           if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
           try {
           WireCenterLocalHome wireCenterHome =
           WireCenterUtil.getLocalHomeEjb();
          
           Collection wireCenters =
           wireCenterHome.findByLongitudeAndLatitude
           (response.getAddressLongitude(),
           response.getAddressLatitude());
          
           if (wireCenters.size() == 1) {
           wireCenter =
           (WireCenterLocal) wireCenters.iterator().next();
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: Wire Center with "
           + "boundary containing longitude "
           + response.getAddressLongitude() + " and "
           + "latitude "
           + response.getAddressLatitude() + " of "
           + "address "
           + response.getQualifiedAddress() + " "
           + "found: " + wireCenter.getClli() + " "
           + "(" + wireCenter.getId() + ")");
           }
           else if (wireCenters.size() > 1) {
           String wireCentersFound = "";
           for (Iterator iterator = wireCenters.iterator();
           iterator.hasNext();) {
           WireCenterLocal currentWireCenter =
           (WireCenterLocal) iterator.next();
          
           if (wireCenter == null) {
           wireCenter = currentWireCenter;
           }
           else {
           if (!StringUtils.equals
           (wireCenter.getClli(),
           currentWireCenter.getClli()))
           wireCenterDifferent = true;
           }
          
           if (wireCentersFound.length() > 0)
           wireCentersFound += ", ";
          
           wireCentersFound +=
           currentWireCenter.getClli()
           + " (" + currentWireCenter.getId() + ")";
           }
          
           String message =
           "Too many Wire Centers with "
           + "boundary containing longitude "
           + response.getAddressLongitude() + " and "
           + "latitude " + response.getAddressLatitude() + " of "
           + "address " + response.getQualifiedAddress() + " "
           + "found: " + wireCentersFound + "; ";
          
           if (wireCenterDifferent)
           message +=
           "Trusting LERG6 lookup with phone number "
           + phoneString + " instead of this ambiguous "
           + "geographic lookup, however in the event the "
           + "phone number cannot be found in LERG6, the "
           + "first ";
           else
           message +=
           "Although the geographic lookup was ambiguous, "
           + "each CLLI code was the same so ";
          
           message +=
           "Wire Center " + wireCenter.getClli() + " "
           + "(" + wireCenter.getId() + ") will be used";
          
           if (wireCenterDifferent)
           log.error("prequalifyAddress: " + message);
           else
           log.debug("prequalifyAddress: " + message);
           }
           else {
           log.error("prequalifyAddress: Wire Center with "
           + "boundary containing longitude "
           + response.getAddressLongitude() + " and "
           + "latitude "
           + response.getAddressLatitude() + " of "
           + "address "
           + response.getQualifiedAddress() + " "
           + "not found, please ensure all "
           + "MapInfo ExchangeInfo has been loaded "
           + "into SpatialDS");
           }
           }
           catch (Exception e) {
           String message =
           "Failed to find Wire Center with boundary containing "
           + "longitude " + response.getAddressLongitude() + " and "
           + "latitude " + response.getAddressLatitude() + " of "
           + "address " + response.getQualifiedAddress()
           + ": " + e.getMessage();
           log.error("prequalifyAddress: " + message, e);
           throw new PrequalificationException(message, e);
           }
           }
          
           ExchangeBlockAssignmentLocal blockAssignment = null;
           if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
           try {
           ExchangeBlockAssignmentLocalHome blockAssignmentHome =
           ExchangeBlockAssignmentUtil.getLocalHomeEjb();
          
           Collection blockAssignments =
           blockAssignmentHome.findByAreaAndExchangeCodes
           (phone.getAreaCode(),
           phone.getExchangeCode());
          
           Character lineBlock = null;
           if (StringUtils.isNotBlank(phone.getLine()))
           lineBlock = new Character(phone.getLine().charAt(0));
          
           ExchangeBlockAssignmentLocal wildcardBlockAssignment = null;
          
           for (Iterator iterator = blockAssignments.iterator();
           iterator.hasNext();) {
           ExchangeBlockAssignmentLocal currentBlockAssignment =
           (ExchangeBlockAssignmentLocal) iterator.next();
          
           if (currentBlockAssignment.isWildcardLineBlockCode())
           wildcardBlockAssignment = currentBlockAssignment;
          
           Character currentLineBlock =
           currentBlockAssignment.getLineBlockCode();
          
           if (lineBlock == null)
           break;
          
           if (lineBlock.equals
           (currentBlockAssignment.getLineBlockCode())) {
           blockAssignment =
           currentBlockAssignment;
           }
           }
          
           if (blockAssignment == null && wildcardBlockAssignment != null)
           blockAssignment = wildcardBlockAssignment;
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: LERG6 Block Assignment: "
           + blockAssignment);
           }
           catch (Exception e) {
           String message =
           "Failed to find LERG6 Block Assignment for " + phoneString
           + ": " + e.getMessage();
           log.error("prequalifyAddress: " + message, e);
           throw new PrequalificationException(message, e);
           }
          
           if (blockAssignment == null)
           log.error("prequalifyAddress: Failed to find LERG6 "
           + "Block Assignment for " + phoneString);
           }
          
           if (wireCenter == null && blockAssignment == null
           && PrequalificationStatus.SUCCESS.equals(response.getStatus()))
           response.setStatus(PrequalificationStatus.ADDRESS_NOT_FOUND);
          
           ExchangeSwitchLocal exchangeSwitch = null;
           if ((wireCenter == null || wireCenterDifferent)
           && blockAssignment != null
           && PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
           exchangeSwitch = blockAssignment.getSwitchLocal();
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: LERG7 Switch: "
           + exchangeSwitch);
          
           if (exchangeSwitch == null) {
           if (wireCenter == null) {
           log.error("prequalifyAddress: Failed to find LERG7 "
           + "Switch for " + blockAssignment + ", however "
           + "Wire Center " + wireCenter.getClli() + " "
           + "(" + wireCenter + ") will be used even "
           + "though it is ambiguous");
           }
           else {
           response.setStatus
           (PrequalificationStatus.ADDRESS_NOT_FOUND);
          
           log.error("prequalifyAddress: Failed to find LERG7 "
           + "Switch for " + blockAssignment);
           }
           }
           }
          
           CentralOfficeLocal centralOffice = null;
           if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
           ArrayList wirecenterCodes = new ArrayList(2);
           if (exchangeSwitch != null)
           wirecenterCodes.add(exchangeSwitch.getClli());
           if (wireCenter != null)
           wirecenterCodes.add(wireCenter.getClli());
          
           CentralOfficeLocalHome centralOfficeHome =
           CentralOfficeUtil.getLocalHomeEjb();
           String firstErrorMessage = null;
           Exception firstException = null;
           for (Iterator iterator = wirecenterCodes.iterator();
           iterator.hasNext();) {
           String wirecenterCode = (String) iterator.next();
          
           if (StringUtils.isNotBlank(wirecenterCode)) {
           if (wirecenterCode.length() > 8)
           wirecenterCode = wirecenterCode.substring(0, 8);
          
           try {
           centralOffice =
           centralOfficeHome.findByCode(wirecenterCode);
           response.setWirecenterCode(wirecenterCode);
           if (centralOffice.getLongitude() != null
           || centralOffice.getLatitude() != null)
           break;
           }
           catch (Exception e) {
           if (firstErrorMessage != null) {
           firstErrorMessage =
           "Failed to find Central Office "
           + wirecenterCode;
           firstException = e;
           }
           }
           }
           }
          
           if (centralOffice != null) {
           response.setWirecenterLongitude(centralOffice.getLongitude());
           response.setWirecenterLatitude(centralOffice.getLatitude());
           }
           else {
           response.setStatus(PrequalificationStatus.ADDRESS_NOT_FOUND);
          
           if (firstErrorMessage != null) {
           log.error("prequalifyAddress: " + firstErrorMessage,
           firstException);
           if (firstException instanceof ObjectNotFoundException)
           throw new PrequalificationException
           (firstErrorMessage, firstException);
           }
           else {
           log.error("prequalifyAddress: Failed to find Central "
           + "Office in list "
           + ArrayUtils.toString
           (wirecenterCodes.toArray()));
           }
           }
           }
          
           if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
           if (response.getAddressLongitude() != null
           && response.getAddressLatitude() != null
           && response.getWirecenterLongitude() != null
           && response.getWirecenterLatitude() != null) {
           double addressLongitude =
           response.getAddressLongitude().doubleValue();
           double addressLatitude =
           response.getAddressLatitude().doubleValue();
           double wirecenterLongitude =
           response.getWirecenterLongitude().doubleValue();
           double wirecenterLatitude =
           response.getWirecenterLatitude().doubleValue();
          
           response.setDistance(new Double(distance(addressLongitude,
           addressLatitude,
           wirecenterLongitude,
           wirecenterLatitude)
           * 5280));
           }
           else {
           response.setStatus(PrequalificationStatus.ADDRESS_NOT_FOUND);
          
           log.error("prequalifyAddress: CentralOffice is missing "
           + "longitude and latitude coordinates: "
           + response);
           }
           }
          
           if (log.isDebugEnabled())
           log.debug("prequalifyAddress: Response " + response);
          
           return response;
          
           }
          
          
          


          • 2. Re: Yet another principal=null case
            starksm64

            Then prove that the LoginException neverThrown is in fact never thrown. I would say it is being thrown and therefore you have no security context, thus you have a null principal. No magic there.

            • 3. Re: Yet another principal=null case
              lbasili

              Hello,
              thank you for your response. I removed the catch block, but actually that exception is not thrown.
              Notice that both create() and getPostLoginData() methods of the invoked EJB require authentication, and that only the second one fails.
              IMVHO somewhere I overwrite the SecurityAssociation settings (but where ? and why does it work with jboss-3-2-0 ?).


              I put a System.out.println and a stack trace dump in the SecurityAssociation.setPrincipal method, and what I can see is that this method is called 9 times.
              The first six times are OK, and the correct principal is set. These calls are related to the create() call, that invokes nested EJBs and a MBean, and each time sets the principal again.
              Notice that in the log dump "NULL" actually stands for a null principal, while "null" is
              new SimplePrincipal(null).



              [root@ztc5 ZTC-Server]# grep 'Set principal' output
              2004-05-27 16:24:20,956 INFO [STDOUT] Set principal to root
              2004-05-27 16:24:21,060 INFO [STDOUT] Set principal to root
              2004-05-27 16:24:21,137 INFO [STDOUT] Set principal to root
              2004-05-27 16:24:21,157 INFO [STDOUT] Set principal to root
              2004-05-27 16:24:21,189 INFO [STDOUT] Set principal to root
              2004-05-27 16:24:22,884 INFO [STDOUT] Set principal to root
              2004-05-27 16:24:22,965 INFO [STDOUT] Set principal to NULL
              2004-05-27 16:24:22,993 INFO [STDOUT] Set principal to null
              2004-05-27 16:24:23,034 INFO [STDOUT] Set principal to NULL


              In the last three calls something goes bad. The first time it is the StatefulSessionInstanceInterceptor that sets the principal to null.

              The second one, the ClientLoginModule.login method is called, but it do not invoke my callback handler to retrieve the principal/credential values.

              Have you got any idea ?

              Thank you very much.

              Here I append the log with the stacktraces of the last three calls


              2004-05-27 16:24:22,965 INFO [STDOUT] Set principal to NULL
              2004-05-27 16:24:22,965 INFO [STDOUT] --------- STACKTRACE ----------
              2004-05-27 16:24:22,966 ERROR [STDERR] java.lang.Exception
              2004-05-27 16:24:22,966 ERROR [STDERR] at org.jboss.security.SecurityAssociation.setPrincipal(SecurityAssociation.java:184)
              2004-05-27 16:24:22,966 ERROR [STDERR] at org.jboss.ejb.plugins.StatefulSessionInstanceInterceptor.invoke(StatefulSessionInstanceInterceptor.java:206)
              2004-05-27 16:24:22,966 ERROR [STDERR] at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
              2004-05-27 16:24:22,966 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
              2004-05-27 16:24:22,967 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
              2004-05-27 16:24:22,967 ERROR [STDERR] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
              2004-05-27 16:24:22,967 ERROR [STDERR] at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
              2004-05-27 16:24:22,967 ERROR [STDERR] at org.jboss.ejb.StatefulSessionContainer.internalInvoke(StatefulSessionContainer.java:416)
              2004-05-27 16:24:22,967 ERROR [STDERR] at org.jboss.ejb.Container.invoke(Container.java:700)
              2004-05-27 16:24:22,967 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
              2004-05-27 16:24:22,967 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
              2004-05-27 16:24:22,967 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              2004-05-27 16:24:22,967 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
              2004-05-27 16:24:22,967 ERROR [STDERR] at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:546)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:101)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:90)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:45)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.jboss.proxy.ejb.StatefulSessionInterceptor.invoke(StatefulSessionInterceptor.java:104)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:85)
              2004-05-27 16:24:22,968 ERROR [STDERR] at $Proxy50.getPostLoginData(Unknown Source)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.apache.jsp.prova_jsp._jspService(prova_jsp.java:98)
              2004-05-27 16:24:22,968 ERROR [STDERR] at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:137)
              2004-05-27 16:24:22,969 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
              2004-05-27 16:24:22,969 ERROR [STDERR] at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:210)
              2004-05-27 16:24:22,969 ERROR [STDERR] at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295)
              2004-05-27 16:24:22,969 ERROR [STDERR] at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241)
              2004-05-27 16:24:22,969 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
              2004-05-27 16:24:22,969 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247)
              2004-05-27 16:24:22,970 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)
              2004-05-27 16:24:22,970 ERROR [STDERR] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256)
              2004-05-27 16:24:22,970 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:22,970 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:22,970 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:22,971 ERROR [STDERR] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
              2004-05-27 16:24:22,971 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:22,971 ERROR [STDERR] at org.jboss.web.tomcat.security.JBossSecurityMgrRealm.invoke(JBossSecurityMgrRealm.java:220)
              2004-05-27 16:24:22,971 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:22,971 ERROR [STDERR] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494)
              2004-05-27 16:24:22,972 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:22,972 ERROR [STDERR] at org.apache.catalina.valves.CertificatesValve.invoke(CertificatesValve.java:246)
              2004-05-27 16:24:22,972 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:22,972 ERROR [STDERR] at org.jboss.web.tomcat.tc4.statistics.ContainerStatsValve.invoke(ContainerStatsValve.java:76)
              2004-05-27 16:24:22,972 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:22,972 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:22,973 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:22,973 ERROR [STDERR] at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2417)
              2004-05-27 16:24:22,973 ERROR [STDERR] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)
              2004-05-27 16:24:22,973 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:22,973 ERROR [STDERR] at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171)
              2004-05-27 16:24:22,973 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:22,973 ERROR [STDERR] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)
              2004-05-27 16:24:22,974 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:22,974 ERROR [STDERR] at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:577)
              2004-05-27 16:24:22,980 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:22,980 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:22,980 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:22,981 ERROR [STDERR] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)
              2004-05-27 16:24:22,981 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:22,981 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:22,987 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:22,988 ERROR [STDERR] at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:197)
              2004-05-27 16:24:22,988 ERROR [STDERR] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:781)
              2004-05-27 16:24:22,988 ERROR [STDERR] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:549)
              2004-05-27 16:24:22,988 ERROR [STDERR] at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:605)
              2004-05-27 16:24:22,988 ERROR [STDERR] at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:677)
              2004-05-27 16:24:22,988 ERROR [STDERR] at java.lang.Thread.run(Thread.java:534)
              2004-05-27 16:24:22,988 INFO [STDOUT] ------ END-OF-STACKTRACE ------
              2004-05-27 16:24:22,993 INFO [STDOUT] Callback handler=javax.security.auth.login.LoginContext$SecureCallbackHandler@198a654
              2004-05-27 16:24:22,993 INFO [STDOUT] Set principal to null
              2004-05-27 16:24:22,993 INFO [STDOUT] --------- STACKTRACE ----------
              2004-05-27 16:24:22,994 ERROR [STDERR] java.lang.Exception
              2004-05-27 16:24:22,994 ERROR [STDERR] at org.jboss.security.SecurityAssociation.setPrincipal(SecurityAssociation.java:184)
              2004-05-27 16:24:22,995 ERROR [STDERR] at org.jboss.security.ClientLoginModule.login(ClientLoginModule.java:132)
              2004-05-27 16:24:22,995 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
              2004-05-27 16:24:22,995 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
              2004-05-27 16:24:22,995 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              2004-05-27 16:24:22,995 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
              2004-05-27 16:24:22,995 ERROR [STDERR] at javax.security.auth.login.LoginContext.invoke(LoginContext.java:675)
              2004-05-27 16:24:22,996 ERROR [STDERR] at javax.security.auth.login.LoginContext.access$000(LoginContext.java:129)
              2004-05-27 16:24:22,996 ERROR [STDERR] at javax.security.auth.login.LoginContext$4.run(LoginContext.java:610)
              2004-05-27 16:24:22,996 ERROR [STDERR] at java.security.AccessController.doPrivileged(Native Method)
              2004-05-27 16:24:22,996 ERROR [STDERR] at javax.security.auth.login.LoginContext.invokeModule(LoginContext.java:607)
              2004-05-27 16:24:22,996 ERROR [STDERR] at javax.security.auth.login.LoginContext.login(LoginContext.java:534)
              2004-05-27 16:24:22,996 ERROR [STDERR] at org.jboss.security.plugins.JaasSecurityManager.defaultLogin(JaasSecurityManager.java:487)
              2004-05-27 16:24:22,996 ERROR [STDERR] at org.jboss.security.plugins.JaasSecurityManager.authenticate(JaasSecurityManager.java:442)
              2004-05-27 16:24:22,997 ERROR [STDERR] at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:244)
              2004-05-27 16:24:22,997 ERROR [STDERR] at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:219)
              2004-05-27 16:24:23,001 ERROR [STDERR] at org.jboss.ejb.plugins.SecurityInterceptor.checkSecurityAssociation(SecurityInterceptor.java:160)
              2004-05-27 16:24:23,001 ERROR [STDERR] at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:107)
              2004-05-27 16:24:23,007 ERROR [STDERR] at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:185)
              2004-05-27 16:24:23,008 ERROR [STDERR] at org.jboss.ejb.plugins.StatefulSessionInstanceInterceptor.invoke(StatefulSessionInstanceInterceptor.java:269)
              2004-05-27 16:24:23,008 ERROR [STDERR] at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
              2004-05-27 16:24:23,008 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
              2004-05-27 16:24:23,008 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
              2004-05-27 16:24:23,008 ERROR [STDERR] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
              2004-05-27 16:24:23,008 ERROR [STDERR] at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
              2004-05-27 16:24:23,008 ERROR [STDERR] at org.jboss.ejb.StatefulSessionContainer.internalInvoke(StatefulSessionContainer.java:416)
              2004-05-27 16:24:23,009 ERROR [STDERR] at org.jboss.ejb.Container.invoke(Container.java:700)
              2004-05-27 16:24:23,009 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
              2004-05-27 16:24:23,009 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
              2004-05-27 16:24:23,009 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              2004-05-27 16:24:23,009 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
              2004-05-27 16:24:23,009 ERROR [STDERR] at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
              2004-05-27 16:24:23,009 ERROR [STDERR] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:546)
              2004-05-27 16:24:23,010 ERROR [STDERR] at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:101)
              2004-05-27 16:24:23,010 ERROR [STDERR] at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:90)
              2004-05-27 16:24:23,010 ERROR [STDERR] at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
              2004-05-27 16:24:23,010 ERROR [STDERR] at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:45)
              2004-05-27 16:24:23,010 ERROR [STDERR] at org.jboss.proxy.ejb.StatefulSessionInterceptor.invoke(StatefulSessionInterceptor.java:104)
              2004-05-27 16:24:23,010 ERROR [STDERR] at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:85)
              2004-05-27 16:24:23,011 ERROR [STDERR] at $Proxy50.getPostLoginData(Unknown Source)
              2004-05-27 16:24:23,011 ERROR [STDERR] at org.apache.jsp.prova_jsp._jspService(prova_jsp.java:98)
              2004-05-27 16:24:23,011 ERROR [STDERR] at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:137)
              2004-05-27 16:24:23,011 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
              2004-05-27 16:24:23,011 ERROR [STDERR] at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:210)
              2004-05-27 16:24:23,011 ERROR [STDERR] at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295)
              2004-05-27 16:24:23,011 ERROR [STDERR] at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241)
              2004-05-27 16:24:23,012 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
              2004-05-27 16:24:23,012 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247)
              2004-05-27 16:24:23,012 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)
              2004-05-27 16:24:23,012 ERROR [STDERR] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256)
              2004-05-27 16:24:23,012 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:23,012 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:23,013 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:23,013 ERROR [STDERR] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
              2004-05-27 16:24:23,013 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:23,013 ERROR [STDERR] at org.jboss.web.tomcat.security.JBossSecurityMgrRealm.invoke(JBossSecurityMgrRealm.java:220)
              2004-05-27 16:24:23,013 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,013 ERROR [STDERR] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494)
              2004-05-27 16:24:23,013 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,014 ERROR [STDERR] at org.apache.catalina.valves.CertificatesValve.invoke(CertificatesValve.java:246)
              2004-05-27 16:24:23,014 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,014 ERROR [STDERR] at org.jboss.web.tomcat.tc4.statistics.ContainerStatsValve.invoke(ContainerStatsValve.java:76)
              2004-05-27 16:24:23,014 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,014 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:23,014 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:23,015 ERROR [STDERR] at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2417)
              2004-05-27 16:24:23,015 ERROR [STDERR] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)
              2004-05-27 16:24:23,015 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:23,015 ERROR [STDERR] at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171)
              2004-05-27 16:24:23,015 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,015 ERROR [STDERR] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)
              2004-05-27 16:24:23,015 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,016 ERROR [STDERR] at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:577)
              2004-05-27 16:24:23,016 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,016 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:23,016 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:23,016 ERROR [STDERR] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)
              2004-05-27 16:24:23,016 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:23,016 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:23,017 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:23,017 ERROR [STDERR] at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:197)
              2004-05-27 16:24:23,017 ERROR [STDERR] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:781)
              2004-05-27 16:24:23,017 ERROR [STDERR] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:549)
              2004-05-27 16:24:23,017 ERROR [STDERR] at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:605)
              2004-05-27 16:24:23,017 ERROR [STDERR] at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:677)
              2004-05-27 16:24:23,018 ERROR [STDERR] at java.lang.Thread.run(Thread.java:534)
              2004-05-27 16:24:23,018 INFO [STDOUT] ------ END-OF-STACKTRACE ------
              at org.jboss.ejb.plugins.SecurityInterceptor.checkSecurityAssociation(SecurityInterceptor.java:164)
              javax.ejb.EJBException: checkSecurityAssociation; CausedByException is:
              javax.ejb.EJBException: checkSecurityAssociation; CausedByException is:
              Caused by: javax.ejb.EJBException: checkSecurityAssociation; CausedByException is:
              at org.jboss.ejb.plugins.SecurityInterceptor.checkSecurityAssociation(SecurityInterceptor.java:165)
              2004-05-27 16:24:23,034 INFO [STDOUT] Set principal to NULL
              2004-05-27 16:24:23,034 INFO [STDOUT] --------- STACKTRACE ----------
              2004-05-27 16:24:23,034 ERROR [STDERR] java.lang.Exception
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.jboss.security.SecurityAssociation.setPrincipal(SecurityAssociation.java:184)
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.jboss.web.tomcat.security.JBossSecurityMgrRealm.invoke(JBossSecurityMgrRealm.java:224)
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494)
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.apache.catalina.valves.CertificatesValve.invoke(CertificatesValve.java:246)
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.jboss.web.tomcat.tc4.statistics.ContainerStatsValve.invoke(ContainerStatsValve.java:76)
              2004-05-27 16:24:23,035 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2417)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:577)
              2004-05-27 16:24:23,036 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:197)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:781)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:549)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:605)
              2004-05-27 16:24:23,037 ERROR [STDERR] at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:677)
              2004-05-27 16:24:23,038 ERROR [STDERR] at java.lang.Thread.run(Thread.java:534)
              2004-05-27 16:24:23,038 INFO [STDOUT] ------ END-OF-STACKTRACE ------









              • 4. Re: Yet another principal=null case
                starksm64

                If you are using the RMIAdaptor to do any invocations this clears the security association from the calling thread as its meant to be used by external clients and whatever thread pool is dispatching the invocation should not be leaking the security context.

                From within the server MBean invocations need to be done using the standard JMX MBeanServerFactory to obtain the MBeanServer.

                • 5. Re: Yet another principal=null case
                  gturner

                  Scott, could you please elaborate on what you mean by "whatever thread pool is dispatching the invocation should not be leaking the security context"? I have been using JBoss 3.2.3 in production for several months and it has an external RMI client (running on Tomcat 4.0) that is invoking session beans and is using the same kind of LoginContext code that lbasili has put in a JSP. Occasionally I notice an error emitted by our system with principal=null, I haven't really looked into it too deep because it doesn't seem to be very often. However today I've been working on a new session bean that is going to get called by this remote client with heavy utilization. While stress testing this error occurrs about once over 10 invocations.

                  Could the remote Tomcat be doing something mysterious with threads that it occasionally looses the security context?

                  • 6. Re: Yet another principal=null case
                    jburugupalli

                    Hi,
                    I think the awnswer for your question is given in different posts but any way i repeat...

                    that the tomcat some how looses the LoginContext information while handling its threads ....

                    Suppose servlet1 calling a bean has a correct context while executing in thread1 but the same servlet calling the same bean will not work in another thread..

                    The fix for this is for each and every call irrespective of threads you should make a LoginContext.login() and after the call is finished you make a call LoginContext.logout(). This can be easily done by using filters in case of servlets and jsps's.

                    hope u got the point
                    regards
                    jani

                    • 7. Re: Yet another principal=null case
                      lbasili

                      Hi Scott,
                      actually there was a call to a MBean through the RMIAdaptor in the create() method of the SessionController. I commented out it and now it is ok !

                      Thank you very much for your help.

                      Bye,

                      --
                      L.

                      • 8. Re: Yet another principal=null case
                        gturner

                        Thanks for your reply jburugupalli, I believe I understand the thread local nature of JAAS, and have coded the logout exactly as you have suggested.

                        Each request to the servlet I have is:


                        Instantiating a LoginContext along with newly instantiated username/password CallbackHandler.

                        Invoking LoginContext.login().

                        Performing an external JNDI lookup of the remote home interface of a Stateless Session Bean.

                        Creating the session bean instance.

                        Invoking one method on the session bean.

                        Removing the session bean enclosed in a finally block with try starting at the previous step.

                        Invoking LoginContext.logout() enclosed in a finally block with try starting all the way back to JNDI lookup.


                        Here is the method which is doing all of the above:

                         public Prequalification prequalify(User user,
                         Address address,
                         String phone,
                         String serviceType,
                         String interfaceType)
                         throws SimilarAddressesFoundException,
                         AddressNotFoundException {
                        
                         LoginContext loginContext;
                         try {
                         loginContext =
                         WaveAuth.createLoginContext(user.getUsername(),
                         user.getPassword());
                         }
                         catch (Exception e) {
                         String message = "Failed to begin authentication of User "
                         + user + " to Wave: " + Strings.exceptionToString(e);
                         throw new AddressNotFoundException(message, e);
                         }
                        
                         try {
                         loginContext.login();
                         }
                         catch (Exception e) {
                         String message = "Failed to login User " + user + " to Wave"
                         + ": " + Strings.exceptionToString(e);
                         throw new AddressNotFoundException(message, e);
                         }
                        
                         PrequalifyAddressRequest request = new PrequalifyAddressRequest();
                         PrequalificationAddress requestAddress = new PrequalificationAddress();
                         request.setAddress(requestAddress);
                         requestAddress.setStreet(address.getStreet1());
                         requestAddress.setCity(address.getCity());
                         requestAddress.setState(StateAbbreviation.getEnum(address.getState()));
                         requestAddress.setZip(address.getZip());
                         PrequalificationPhone requestPhone = new PrequalificationPhone();
                         request.setPhone(requestPhone);
                         String[] phones = Strings.parsePhone(phone);
                         if (phones.length > 0)
                         requestPhone.setAreaCode(phones[0]);
                         if (phones.length > 1)
                         requestPhone.setExchangeCode(phones[1]);
                         if (phones.length > 2)
                         requestPhone.setLine(phones[2]);
                        
                         PrequalifyAddressResponse response = null;
                         try {
                         Properties environment = null;
                         try {
                         environment =
                         Jndi.getProperties(Constants.ENV_WAVE_CONTEXT_ENVIRONMENT);
                         }
                         catch (Exception ignore) {
                         log.error("prequalify: Failed to get environment entry "
                         + Constants.ENV_WAVE_CONTEXT_ENVIRONMENT, ignore);
                         environment = new Properties();
                         }
                        
                         PrequalificationHome prequalificationHome = null;
                         try {
                         prequalificationHome =
                         (PrequalificationHome) Jndi.getObject
                         (environment,
                         PrequalificationHome.JNDI_NAME);
                         }
                         catch (Exception e) {
                         String message =
                         "Failed to lookup Prequalification: " + e.getMessage();
                         throw new AddressNotFoundException(message, e);
                         }
                        
                         com.newedgenetworks.phoenix.ejb.session.Prequalification
                         prequalificationBean = null;
                         boolean removeFailureExpected = false;
                         try {
                         prequalificationBean = prequalificationHome.create();
                         response = prequalificationBean.prequalifyAddress(request);
                         }
                         catch (Exception e) {
                         removeFailureExpected = true;
                         throw new AddressNotFoundException(e.getMessage(), e);
                         }
                         finally {
                         if (prequalificationBean != null)
                         try {
                         prequalificationBean.remove();
                         }
                         catch (Exception e) {
                         String message = "Failed to remove Prequalification: "
                         + Strings.exceptionToString(e);
                         if (removeFailureExpected)
                         log.warn("prequalify: " + message);
                         else
                         log.error("prequalify: " + message, e);
                         }
                         }
                         }
                         finally {
                         try {
                         loginContext.logout();
                         }
                         catch (Exception e) {
                         String message = "Failed to logout User " + user
                         + "from Wave: " + Strings.exceptionToString(e);
                         log.error("prequalify: " + message, e);
                         }
                         }
                        
                         if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
                         Prequalification prequalification = new Prequalification();
                         prequalification.setPhone(phone);
                         prequalification.setServiceType(serviceType);
                         prequalification.setInterfaceType(interfaceType);
                         if (response.getDistance() != null)
                         prequalification.setDistance
                         ((int) response.getDistance().doubleValue());
                         Address prequalificationAddress = new Address();
                         prequalification.setAddress(prequalificationAddress);
                         prequalificationAddress.setValidated(Boolean.TRUE);
                         prequalificationAddress.setValidationDate(new Date());
                         PrequalificationAddress responseAddress =
                         response.getQualifiedAddress();
                         prequalificationAddress.setStreet1(responseAddress.getStreet());
                         prequalificationAddress.setCity(responseAddress.getCity());
                         if (responseAddress.getState() != null)
                         prequalificationAddress.setState
                         (responseAddress.getState().getValue());
                         prequalificationAddress.setZip(responseAddress.getZip());
                         CentralOffice prequalificationCentralOffice = new CentralOffice();
                         prequalification.setCentralOffice(prequalificationCentralOffice);
                         prequalificationCentralOffice.setClli
                         (response.getWirecenterCode());
                        
                         return prequalification;
                         }
                         else if (PrequalificationStatus.SIMILAR_ADDRESSES_FOUND
                         .equals(response.getStatus())) {
                         Address[] addresses = null;
                         if (response.getSimilarAddresses() != null)
                         addresses =
                         new Address[response.getSimilarAddresses().length];
                         else
                         addresses = new Address[0];
                        
                         for (int index = 0; index < addresses.length; index++) {
                         Address prequalificationAddress = new Address();
                         addresses[index] = prequalificationAddress;
                         PrequalificationAddress responseAddress =
                         response.getSimilarAddresses()[index];
                         prequalificationAddress.setStreet1
                         (responseAddress.getStreet());
                         prequalificationAddress.setCity(responseAddress.getCity());
                         if (responseAddress.getState() != null)
                         prequalificationAddress.setState
                         (responseAddress.getState().getValue());
                         prequalificationAddress.setZip(responseAddress.getZip());
                         }
                        
                         throw new SimilarAddressesFoundException(addresses);
                         }
                         else {
                         throw new AddressNotFoundException("Address not found");
                         }
                        
                         }
                        


                        The remote Tomcat 4.0 (where the above code is executed) has a copy of the JBoss auth.conf and is used by System property java.security.auth.login.config, however I am using "client-login" instead of "other" which lbasili is using in the code he posted, I forgot what the purpose of that was, but it's been runing for years, growing from JBoss 3.0 to 3.2!

                        The Tomcat and JBoss processes happen to be running on the same server in this test (different servers in production), different VMs though, the server is clunkly old Sun SMP hardware (2 CPUs).

                        Maybe this is of interest: The method of the Stateless Session bean that is being invoked (Prequalification.prequalifyAddress) has "unchecked" security declaration, however Entity Beans that are being invoked (finders and getters) do have security declarations. In the rare circumstance when the "principal=null" SecurityException is thrown, the violation occurs at the first Entity Bean finder invoked within the prequalify method.

                        Here is the exception being thrown on the JBoss side:

                        2004-05-28 02:41:57,492 32361464 ERROR [org.jboss.ejb.plugins.LogInterceptor] (RMI TCP Connection(2891)-192.168.30.24:) EJBException, causedBy:
                        java.lang.SecurityException: Insufficient method permissions, principal=null, method=findByLongitudeAndLatitude, interface=LOCALHOME, requiredRoles=[Administrator, WireCenter View], principalRoles=[]
                         at org.jboss.ejb.plugins.SecurityInterceptor.checkSecurityAssociation(SecurityInterceptor.java:229)
                         at org.jboss.ejb.plugins.SecurityInterceptor.invokeHome(SecurityInterceptor.java:81)
                         at org.jboss.ejb.plugins.LogInterceptor.invokeHome(LogInterceptor.java:120)
                         at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invokeHome(ProxyFactoryFinderInterceptor.java:93)
                         at org.jboss.ejb.EntityContainer.internalInvokeHome(EntityContainer.java:483)
                         at org.jboss.ejb.Container.invoke(Container.java:720)
                         at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invokeHome(BaseLocalProxyFactory.java:293)
                         at org.jboss.ejb.plugins.local.LocalHomeProxy.invoke(LocalHomeProxy.java:110)
                         at $Proxy185.findByLongitudeAndLatitude(Unknown Source)
                         at com.newedgenetworks.phoenix.ejb.session.PrequalificationBean.prequalifyAddress(PrequalificationBean.java:375)
                         at sun.reflect.GeneratedMethodAccessor82.invoke(Unknown Source)
                         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                         at java.lang.reflect.Method.invoke(Method.java:324)
                         at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)
                         at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:185)
                         at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
                         at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
                         at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
                         at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
                         at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:118)
                         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.GeneratedMethodAccessor67.invoke(Unknown Source)
                         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.GeneratedMethodAccessor70.invoke(Unknown Source)
                         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)
                        
                        
                        Here is the method in the Stateless Session Bean:
                        
                        
                         /**
                         * Prequalify an address.
                         *
                         * @ejb.interface-method
                         *
                         * @jboss-net.web-method
                         */
                         public PrequalifyAddressResponse prequalifyAddress
                         (PrequalifyAddressRequest request)
                         throws PrequalificationException {
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: Request " + request);
                        
                         if (request == null)
                         throw new PrequalificationException("Request required");
                        
                         PrequalificationAddress address = request.getAddress();
                         if (address == null)
                         throw new PrequalificationException("Address required");
                         if (StringUtils.isBlank(address.getStreet()))
                         throw new PrequalificationException("Street required");
                         if (StringUtils.isBlank(address.getCity()))
                         throw new PrequalificationException("City required");
                         if (address.getState() == null)
                         throw new PrequalificationException("State required");
                         if (StringUtils.isBlank(address.getZip()))
                         throw new PrequalificationException("Zip required");
                        
                         PrequalificationPhone phone = request.getPhone();
                         if (phone == null)
                         throw new PrequalificationException("Phone required");
                         if (StringUtils.isBlank(phone.getAreaCode()))
                         throw new PrequalificationException("Area Code required");
                         if (StringUtils.isBlank(phone.getExchangeCode()))
                         throw new PrequalificationException("Exchange Code required");
                        
                         String phoneString =
                         phone.getAreaCode()
                         + "-" + phone.getExchangeCode()
                         + "-" + (StringUtils.isBlank(phone.getLine())
                         ? "0000"
                         : phone.getLine());
                        
                         PrequalifyAddressResponse response =
                         new PrequalifyAddressResponse();
                         response.setStatus(PrequalificationStatus.ADDRESS_NOT_FOUND);
                        
                         InetAddress host = BeanUtil.getInetAddress("MapMarkerHost");
                         MapMarkerClient client;
                         try {
                         client = new MapMarkerClient(host, OncRpcProtocols.ONCRPC_TCP);
                         OncRpcTcpClient innerClient = (OncRpcTcpClient) client.getClient();
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: ONC/RPC timeout was "
                         + innerClient.getTimeout() + "ms and "
                         + "transmission timeout was "
                         + innerClient.getTransmissionTimeout() + "ms");
                        
                         innerClient.setTimeout(ONCRPC_TIMEOUT);
                         innerClient.setTransmissionTimeout(ONCRPC_TIMEOUT);
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: ONC/RPC timeout is now "
                         + innerClient.getTimeout() + "ms and "
                         + "transmission timeout is now "
                         + innerClient.getTransmissionTimeout() + "ms");
                         }
                         catch (Exception e) {
                         String message =
                         "Failed to establish MapMarker connection with " + host
                         + ": " + e.getMessage();
                         log.error("prequalifyAddress: " + message, e);
                         throw new PrequalificationException(message, e);
                         }
                        
                         try {
                         Handle handle = new Handle();
                         handle.geocode = 1;
                         handle.server = RandomUtils.nextLong();
                        
                         GeocodeAddressRequest geocodeRequest =
                         new GeocodeAddressRequest();
                         geocodeRequest.handle = handle;
                         geocodeRequest.relaxFlags = RelaxFlags.DEFAULT;
                         geocodeRequest.linearInset = 0.0;
                         geocodeRequest.perpendicularSetback = 0.0;
                         geocodeRequest.distUnit = -1;
                         geocodeRequest.relaxDistance = -1;
                         geocodeRequest.firm = "";
                         geocodeRequest.street = address.getStreet();
                         geocodeRequest.city = address.getCity();
                         geocodeRequest.state = address.getState().getValue();
                         geocodeRequest.zip = address.getZip();
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: MapMarker request: "
                         + ToStringBuilder.reflectionToString
                         (geocodeRequest));
                        
                         GeocodeAddressResponse geocodeResponse;
                         try {
                         geocodeResponse =
                         client.geocodeAddress_1(geocodeRequest);
                         }
                         catch (Exception e) {
                         String message =
                         "Failed to geocode address: " + e.getMessage();
                         log.error("prequalifyAddress: " + message, e);
                         throw new PrequalificationException(message, e);
                         }
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: MapMarker response: "
                         + ToStringBuilder.reflectionToString
                         (geocodeResponse));
                        
                         if (geocodeResponse.numCandidates.length != 1
                         || geocodeResponse.numCloseCandidates.length != 1)
                         log.error("prequalifyAddress: Expected numCandidates and "
                         + "numCloseCandidates fields in MapMarker "
                         + "GeocodeAddressResponse to contain only one "
                         + "element: "
                         + ToStringBuilder.reflectionToString
                         (geocodeResponse));
                        
                         if ((geocodeResponse.numCloseCandidates.length > 0
                         && geocodeResponse.numCloseCandidates[0] > 0)
                         || (geocodeResponse.numCandidates.length > 0
                         && geocodeResponse.numCandidates[0] > 0)) {
                         PrequalificationAddress[] addresses = null;
                         int addressesLength = 0
                        
                         if (geocodeResponse.numCloseCandidates[0] > 0)
                         addressesLength = geocodeResponse.numCloseCandidates[0];
                         else
                         addressesLength = geocodeResponse.numCandidates[0];
                        
                         if (addressesLength > 10)
                         addressesLength = 10;
                        
                         addresses = new PrequalificationAddress[addressesLength];
                        
                         for (int index = 0; index < addressesLength; index++) {
                         CandidateRequest candidateRequest = new CandidateRequest();
                         candidateRequest.handle = geocodeResponse.handle;
                         candidateRequest.candidateNumber = index;
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: MapMarker request: "
                         + ToStringBuilder.reflectionToString
                         (candidateRequest));
                        
                         CandidateResponse candidateResponse;
                         try {
                         candidateResponse =
                         client.getCandidate_1(candidateRequest);
                         }
                         catch (Exception e) {
                         String message =
                         "Failed to retrieve candidate: " + e.getMessage();
                         log.error("prequalifyAddress: " + message, e);
                         throw new PrequalificationException(message, e);
                         }
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: MapMarker response: "
                         + ToStringBuilder.reflectionToString
                         (candidateResponse));
                        
                         if (candidateResponse.status != 0) {
                         String message =
                         "Invalid status while retrieving candidate: "
                         + candidateResponse.status + "; "
                         + "MapMarker resonse: "
                         + ToStringBuilder.reflectionToString
                         (candidateResponse);
                         log.error("prequalifyAddress: " + message);
                         throw new PrequalificationException(message);
                         }
                        
                         PrequalificationAddress candidateAddress =
                         new PrequalificationAddress();
                         addresses[index] = candidateAddress;
                        
                         candidateAddress.setStreet(candidateResponse.street);
                         candidateAddress.setCity(candidateResponse.city);
                         candidateAddress.setState
                         (StateAbbreviation.getEnum(candidateResponse.state));
                         if (candidateResponse.zip != null)
                         candidateAddress.setZip
                         (candidateResponse.zip
                         + (StringUtils.isNotBlank
                         (candidateResponse.plus4)
                         ? "-" + candidateResponse.plus4
                         : ""));
                        
                         boolean qualified = false;
                         if (index == 0) {
                         if (BEST_RESULT_CODE.equals
                         (candidateResponse.resultCode)
                         && geocodeResponse.numCloseCandidates[0] > 0) {
                         qualified = true;
                         }
                         else if (match(address, candidateAddress)) {
                         qualified = true;
                        
                         if (!BEST_RESULT_CODE.equals
                         (candidateResponse.resultCode))
                         log.warn("prequalifyAddress: Probably "
                         + "allowing approximate match too "
                         + "soon; "
                         + request + "; "
                         + ToStringBuilder.reflectionToString
                         (geocodeResponse) + "; "
                         + ToStringBuilder.reflectionToString
                         (candidateResponse));
                         }
                         }
                        
                         if (qualified) {
                         response.setStatus(PrequalificationStatus.SUCCESS);
                        
                         response.setQualifiedAddress(candidateAddress);
                        
                         if (candidateResponse.longitude.length != 1)
                         log.error("prequalifyAddress: Expected longitude "
                         + "field in MapMarker CandidateResponse "
                         + "to contain only one element: "
                         + ToStringBuilder.reflectionToString
                         (candidateResponse));
                        
                         if (candidateResponse.longitude.length > 0)
                         response.setAddressLongitude
                         (new Double(candidateResponse.longitude[0]));
                        
                         if (candidateResponse.latitude.length != 1)
                         log.error("prequalifyAddress: Expected latitude "
                         + "field in MapMarker CandidateResponse "
                         + "to contain only one element: "
                         + ToStringBuilder.reflectionToString
                         (candidateResponse));
                        
                         if (candidateResponse.latitude.length > 0)
                         response.setAddressLatitude
                         (new Double(candidateResponse.latitude[0]));
                        
                         break;
                         }
                         }
                        
                         if (!PrequalificationStatus.SUCCESS.equals
                         (response.getStatus())) {
                         response.setStatus
                         (PrequalificationStatus.SIMILAR_ADDRESSES_FOUND);
                         response.setSimilarAddresses(addresses);
                         }
                         }
                         }
                         finally {
                         if (client != null)
                         try {
                         client.close();
                         client = null;
                         }
                         catch (Exception e) {
                         log.error("prequalifyAddress: Failed to close MapMarker "
                         + "connection with " + host
                         + ": " + e.getMessage(), e);
                         }
                         }
                        
                         boolean wireCenterDifferent = false;
                         WireCenterLocal wireCenter = null;
                         if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
                         try {
                         WireCenterLocalHome wireCenterHome =
                         WireCenterUtil.getLocalHomeEjb();
                        
                         Collection wireCenters =
                         wireCenterHome.findByLongitudeAndLatitude
                         (response.getAddressLongitude(),
                         response.getAddressLatitude());
                        
                         if (wireCenters.size() == 1) {
                         wireCenter =
                         (WireCenterLocal) wireCenters.iterator().next();
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: Wire Center with "
                         + "boundary containing longitude "
                         + response.getAddressLongitude() + " and "
                         + "latitude "
                         + response.getAddressLatitude() + " of "
                         + "address "
                         + response.getQualifiedAddress() + " "
                         + "found: " + wireCenter.getClli() + " "
                         + "(" + wireCenter.getId() + ")");
                         }
                         else if (wireCenters.size() > 1) {
                         String wireCentersFound = "";
                         for (Iterator iterator = wireCenters.iterator();
                         iterator.hasNext();) {
                         WireCenterLocal currentWireCenter =
                         (WireCenterLocal) iterator.next();
                        
                         if (wireCenter == null) {
                         wireCenter = currentWireCenter;
                         }
                         else {
                         if (!StringUtils.equals
                         (wireCenter.getClli(),
                         currentWireCenter.getClli()))
                         wireCenterDifferent = true;
                         }
                        
                         if (wireCentersFound.length() > 0)
                         wireCentersFound += ", ";
                        
                         wireCentersFound +=
                         currentWireCenter.getClli()
                         + " (" + currentWireCenter.getId() + ")";
                         }
                        
                         String message =
                         "Too many Wire Centers with "
                         + "boundary containing longitude "
                         + response.getAddressLongitude() + " and "
                         + "latitude " + response.getAddressLatitude() + " of "
                         + "address " + response.getQualifiedAddress() + " "
                         + "found: " + wireCentersFound + "; ";
                        
                         if (wireCenterDifferent)
                         message +=
                         "Trusting LERG6 lookup with phone number "
                         + phoneString + " instead of this ambiguous "
                         + "geographic lookup, however in the event the "
                         + "phone number cannot be found in LERG6, the "
                         + "first ";
                         else
                         message +=
                         "Although the geographic lookup was ambiguous, "
                         + "each CLLI code was the same so ";
                        
                         message +=
                         "Wire Center " + wireCenter.getClli() + " "
                         + "(" + wireCenter.getId() + ") will be used";
                        
                         if (wireCenterDifferent)
                         log.error("prequalifyAddress: " + message);
                         else
                         log.debug("prequalifyAddress: " + message);
                         }
                         else {
                         log.error("prequalifyAddress: Wire Center with "
                         + "boundary containing longitude "
                         + response.getAddressLongitude() + " and "
                         + "latitude "
                         + response.getAddressLatitude() + " of "
                         + "address "
                         + response.getQualifiedAddress() + " "
                         + "not found, please ensure all "
                         + "MapInfo ExchangeInfo has been loaded "
                         + "into SpatialDS");
                         }
                         }
                         catch (Exception e) {
                         String message =
                         "Failed to find Wire Center with boundary containing "
                         + "longitude " + response.getAddressLongitude() + " and "
                         + "latitude " + response.getAddressLatitude() + " of "
                         + "address " + response.getQualifiedAddress()
                         + ": " + e.getMessage();
                         log.error("prequalifyAddress: " + message, e);
                         throw new PrequalificationException(message, e);
                         }
                         }
                        
                         ExchangeBlockAssignmentLocal blockAssignment = null;
                         if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
                         try {
                         ExchangeBlockAssignmentLocalHome blockAssignmentHome =
                         ExchangeBlockAssignmentUtil.getLocalHomeEjb();
                        
                         Collection blockAssignments =
                         blockAssignmentHome.findByAreaAndExchangeCodes
                         (phone.getAreaCode(),
                         phone.getExchangeCode());
                        
                         Character lineBlock = null;
                         if (StringUtils.isNotBlank(phone.getLine()))
                         lineBlock = new Character(phone.getLine().charAt(0));
                        
                         ExchangeBlockAssignmentLocal wildcardBlockAssignment = null;
                        
                         for (Iterator iterator = blockAssignments.iterator();
                         iterator.hasNext();) {
                         ExchangeBlockAssignmentLocal currentBlockAssignment =
                         (ExchangeBlockAssignmentLocal) iterator.next();
                        
                         if (currentBlockAssignment.isWildcardLineBlockCode())
                         wildcardBlockAssignment = currentBlockAssignment;
                        
                         Character currentLineBlock =
                         currentBlockAssignment.getLineBlockCode();
                        
                         if (lineBlock == null)
                         break;
                        
                         if (lineBlock.equals
                         (currentBlockAssignment.getLineBlockCode())) {
                         blockAssignment =
                         currentBlockAssignment;
                         }
                         }
                        
                         if (blockAssignment == null && wildcardBlockAssignment != null)
                         blockAssignment = wildcardBlockAssignment;
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: LERG6 Block Assignment: "
                         + blockAssignment);
                         }
                         catch (Exception e) {
                         String message =
                         "Failed to find LERG6 Block Assignment for " + phoneString
                         + ": " + e.getMessage();
                         log.error("prequalifyAddress: " + message, e);
                         throw new PrequalificationException(message, e);
                         }
                        
                         if (blockAssignment == null)
                         log.error("prequalifyAddress: Failed to find LERG6 "
                         + "Block Assignment for " + phoneString);
                         }
                        
                         if (wireCenter == null && blockAssignment == null
                         && PrequalificationStatus.SUCCESS.equals(response.getStatus()))
                         response.setStatus(PrequalificationStatus.ADDRESS_NOT_FOUND);
                        
                         ExchangeSwitchLocal exchangeSwitch = null;
                         if ((wireCenter == null || wireCenterDifferent)
                         && blockAssignment != null
                         && PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
                         exchangeSwitch = blockAssignment.getSwitchLocal();
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: LERG7 Switch: "
                         + exchangeSwitch);
                        
                         if (exchangeSwitch == null) {
                         if (wireCenter == null) {
                         log.error("prequalifyAddress: Failed to find LERG7 "
                         + "Switch for " + blockAssignment + ", however "
                         + "Wire Center " + wireCenter.getClli() + " "
                         + "(" + wireCenter + ") will be used even "
                         + "though it is ambiguous");
                         }
                         else {
                         response.setStatus
                         (PrequalificationStatus.ADDRESS_NOT_FOUND);
                        
                         log.error("prequalifyAddress: Failed to find LERG7 "
                         + "Switch for " + blockAssignment);
                         }
                         }
                         }
                        
                         CentralOfficeLocal centralOffice = null;
                         if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
                         ArrayList wirecenterCodes = new ArrayList(2);
                         if (exchangeSwitch != null)
                         wirecenterCodes.add(exchangeSwitch.getClli());
                         if (wireCenter != null)
                         wirecenterCodes.add(wireCenter.getClli());
                        
                         CentralOfficeLocalHome centralOfficeHome =
                         CentralOfficeUtil.getLocalHomeEjb();
                         String firstErrorMessage = null;
                         Exception firstException = null;
                         for (Iterator iterator = wirecenterCodes.iterator();
                         iterator.hasNext();) {
                         String wirecenterCode = (String) iterator.next();
                        
                         if (StringUtils.isNotBlank(wirecenterCode)) {
                         if (wirecenterCode.length() > 8)
                         wirecenterCode = wirecenterCode.substring(0, 8);
                        
                         try {
                         centralOffice =
                         centralOfficeHome.findByCode(wirecenterCode);
                         response.setWirecenterCode(wirecenterCode);
                         if (centralOffice.getLongitude() != null
                         || centralOffice.getLatitude() != null)
                         break;
                         }
                         catch (Exception e) {
                         if (firstErrorMessage != null) {
                         firstErrorMessage =
                         "Failed to find Central Office "
                         + wirecenterCode;
                         firstException = e;
                         }
                         }
                         }
                         }
                        
                         if (centralOffice != null) {
                         response.setWirecenterLongitude(centralOffice.getLongitude());
                         response.setWirecenterLatitude(centralOffice.getLatitude());
                         }
                         else {
                         response.setStatus(PrequalificationStatus.ADDRESS_NOT_FOUND);
                        
                         if (firstErrorMessage != null) {
                         log.error("prequalifyAddress: " + firstErrorMessage,
                         firstException);
                         if (firstException instanceof ObjectNotFoundException)
                         throw new PrequalificationException
                         (firstErrorMessage, firstException);
                         }
                         else {
                         log.error("prequalifyAddress: Failed to find Central "
                         + "Office in list "
                         + ArrayUtils.toString
                         (wirecenterCodes.toArray()));
                         }
                         }
                         }
                        
                         if (PrequalificationStatus.SUCCESS.equals(response.getStatus())) {
                         if (response.getAddressLongitude() != null
                         && response.getAddressLatitude() != null
                         && response.getWirecenterLongitude() != null
                         && response.getWirecenterLatitude() != null) {
                         double addressLongitude =
                         response.getAddressLongitude().doubleValue();
                         double addressLatitude =
                         response.getAddressLatitude().doubleValue();
                         double wirecenterLongitude =
                         response.getWirecenterLongitude().doubleValue();
                         double wirecenterLatitude =
                         response.getWirecenterLatitude().doubleValue();
                        
                         response.setDistance(new Double(distance(addressLongitude,
                         addressLatitude,
                         wirecenterLongitude,
                         wirecenterLatitude)
                         * 5280));
                         }
                         else {
                         response.setStatus(PrequalificationStatus.ADDRESS_NOT_FOUND);
                        
                         log.error("prequalifyAddress: CentralOffice is missing "
                         + "longitude and latitude coordinates: "
                         + response);
                         }
                         }
                        
                         if (log.isDebugEnabled())
                         log.debug("prequalifyAddress: Response " + response);
                        
                         return response;
                        
                         }
                        
                        
                        


                        • 9. Re: Yet another principal=null case
                          starksm64

                          Unless the login module configuration being used here(which you do not show because its hidden in the WaveAuth.createLoginContext) includes the org.jboss.security.ClientLoginModule, there is no propagation of the security context to the remote call. Get your debugger and find out if ClientLoginModule is being invoked as part of the LoginContext.login. This has nothing to do with the thread local security association because your entirely within the context of a single call with stack local variables.

                          • 10. Re: Yet another principal=null case
                            gturner

                            Wrote a test case which exhibits this intermitent error and submitted a bug report.

                            Bug 973563:
                            https://sourceforge.net/tracker/index.php?func=detail&aid=973563&group_id=22866&atid=376685