6 Replies Latest reply on Jun 12, 2009 4:55 AM by Andrew Rubinger

    Cleaning up Logging

    Andrew Rubinger Master

      I know we've discussed this before, but let's just get these on the table. I want to kill the following (to DEBUG):

      12:53:39,374 WARN [StatelessBeanContext] EJBTHREE-1337: do not get WebServiceContext property from stateless bean context, it should already have been injected


      ...and...

      12:53:39,382 WARN [InterceptorsFactory] EJBTHREE-1246: Do not use InterceptorsFactory with a ManagedObjectAdvisor, InterceptorRegistry should be used via the bean container


      ...and...

      22:55:08,580 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@988821214{vfsfile:/home/alrubinger/business/jboss/wc/jbossas/branches/Branch_5_x/build/output/jboss-5.2.0.Beta/server/default/deploy/profileservice-secured.jar/}


      ...and...

      23:18:05,567 INFO [EJB3EndpointDeployer] Deploy AbstractBeanMetaData@6687ec13{name=jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true}


      ...and...

      23:18:05,572 INFO [Ejb3MetricsDeployer] Attaching MC Bean: SecureManagementView-metrics-instance


      Will make JIRAs for each Thursday pending no objections.

      S,
      ALR

        • 1. Re: Cleaning up Logging
          jaikiran pai Master

           

          12:53:39,374 WARN [StatelessBeanContext] EJBTHREE-1337: do not get WebServiceContext property from stateless bean context, it should already have been injected


          Being tracked here https://jira.jboss.org/jira/browse/EJBTHREE-1847

          12:53:39,382 WARN [InterceptorsFactory] EJBTHREE-1246: Do not use InterceptorsFactory with a ManagedObjectAdvisor, InterceptorRegistry should be used via the bean container

          Already done (i just need to commit it today) http://www.jboss.org/index.html?module=bb&op=viewtopic&t=156567

          And no objections from me for the other changes, although i remember Carlo had wanted the Ejb3DependenciesDeployer to be at INFO level.

          • 2. Re: Cleaning up Logging
            Brian Stansberry Master

            My 2 cents: this is easily the spammiest thing in the console logging of the "all" config startup:

            08:50:19,747 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@998706428{vfsfile:/home/bes/dev/jboss/Branch_5_x/build/output/jboss-5.2.0.Beta/server/all/deploy/profileservice-secured.jar/}
            08:50:19,747 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@998706428{vfsfile:/home/bes/dev/jboss/Branch_5_x/build/output/jboss-5.2.0.Beta/server/all/deploy/profileservice-secured.jar/}
            08:50:19,748 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@998706428{vfsfile:/home/bes/dev/jboss/Branch_5_x/build/output/jboss-5.2.0.Beta/server/all/deploy/profileservice-secured.jar/}
            08:50:19,749 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@998706428{vfsfile:/home/bes/dev/jboss/Branch_5_x/build/output/jboss-5.2.0.Beta/server/all/deploy/profileservice-secured.jar/}
            


            Unless, of course, the fact that it logs the same thing 4 times tells us that some expensive code path is needlessly being executed repeatedly. In which case it's the most useful logging in the "all" config startup! ;-)

            • 3. Re: Cleaning up Logging
              jaikiran pai Master

              That's interesting. I don't see a reason why it should process the same unit 4 times. Unless its again some MC thing which causes this to be called multiple times. Let me see what causes this.

              • 4. Re: Cleaning up Logging
                jaikiran pai Master

                Its our use of AbstractRealDeployerWithInput< JBossMetaData> which causes the deployment framework to call our deployer multiple times for the same deployment unit. The logic in AbstractRealDeployerWithInput involves looking for attachments of type JBossMetaData in a given unit and call the deployer for each of these attachments:

                AbstractRealDeployerWithInput:

                protected <U> void deploy(DeploymentUnit unit, DeploymentVisitor<U> visitor) throws DeploymentException
                 {
                 if (visitor == null)
                 throw new IllegalArgumentException("Null visitor.");
                
                 List<U> visited = new ArrayList<U>();
                 try
                 {
                 Set<? extends U> deployments = unit.getAllMetaData(visitor.getVisitorType());
                 for (U deployment : deployments)
                 {
                 visitor.deploy(unit, deployment);
                


                AbstractDeploymentUnit:

                 public <T> Set<? extends T> getAllMetaData(Class<T> type)
                 {
                 if (type == null)
                 throw new IllegalArgumentException("Null type");
                
                 Set<T> result = new HashSet<T>();
                 Map<String, Object> attachments = getAttachments();
                 for (Object object : attachments.values())
                 {
                 if (type.isInstance(object))
                 {
                 T t = type.cast(object);
                 result.add(t);
                 }
                 }
                 if (result.isEmpty() == false)
                 deploymentContext.deployed();
                 return result;
                 }
                


                A deployment unit can have multiple attachments of the same type (with different keys) in a given unit and hence the deployer will end up being called that many times.

                Looking at the Ejb3DependenciesDeployer, all we are doing is adding a dependency on the "unit" at PRE_REAL stage. So i guess we can change the deployer as follows:

                1) Change the deployer to extend from AbstractDeployer
                2) Set the stage of the deployer as PRE_REAL (this is already there in the current deployer)
                3) setInput(JBossMetaData.class) so that the deployer expects a JBossMetaData as a requirement
                4) addInput(MergedJBossMetaDataDeployer.EJB_MERGED_ATTACHMENT_NAME) so that the deployer gets called at the right time (when the metadata has been merged)

                Here's the change:

                
                Index: src/main/org/jboss/ejb3/deployers/Ejb3DependenciesDeployer.java
                ===================================================================
                --- src/main/org/jboss/ejb3/deployers/Ejb3DependenciesDeployer.java (revision 90046)
                +++ src/main/org/jboss/ejb3/deployers/Ejb3DependenciesDeployer.java (working copy)
                @@ -27,66 +27,60 @@
                 import org.jboss.dependency.spi.ControllerState;
                 import org.jboss.deployers.spi.DeploymentException;
                 import org.jboss.deployers.spi.deployer.DeploymentStages;
                -import org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployerWithInput;
                -import org.jboss.deployers.spi.deployer.helpers.DeploymentVisitor;
                +import org.jboss.deployers.spi.deployer.helpers.AbstractDeployer;
                 import org.jboss.deployers.structure.spi.DeploymentUnit;
                 import org.jboss.deployers.vfs.plugins.dependency.DependenciesMetaData;
                -import org.jboss.deployers.vfs.plugins.dependency.DependencyItemMetaData;
                +import org.jboss.ejb.deployers.MergedJBossMetaDataDeployer;
                 import org.jboss.metadata.ejb.jboss.JBossMetaData;
                
                 /**
                 * @author <a href="mailto:cdewolf@redhat.com">Carlo de Wolf</a>
                 * @version $Revision$
                 */
                -public class Ejb3DependenciesDeployer extends AbstractRealDeployerWithInput<JBossMetaData>
                +public class Ejb3DependenciesDeployer extends AbstractDeployer
                 {
                + /**
                + * Constructor
                + */
                 public Ejb3DependenciesDeployer()
                 {
                + // PRE_REAL stage is when we run
                 setStage(DeploymentStages.PRE_REAL);
                + // we need JBossMetadata as input
                + setInput(JBossMetaData.class);
                + // we should run after the metadata has been merged
                + addInput(MergedJBossMetaDataDeployer.EJB_MERGED_ATTACHMENT_NAME);
                + // this is our output
                 setOutput(DependenciesMetaData.class);
                - DeploymentVisitor<JBossMetaData> visitor = new DeploymentVisitor<JBossMetaData>()
                - {
                - public void deploy(DeploymentUnit unit, JBossMetaData deployment) throws DeploymentException
                - {
                - log.info("Encountered deployment " + unit);
                -
                - if(!deployment.isEJB3x())
                - return;
                -
                - // TODO: get the dependencies from beans.xml
                - /*
                - DependenciesMetaData dependencies = new DependenciesMetaData();
                - List<DependencyItemMetaData> items = new ArrayList<DependencyItemMetaData>();
                - items.add(createDependencyItemMetaData(TransactionManager.class.getName()));
                - dependencies.setItems(items);
                - log.debug("Encountered EJB3 deployment " + unit + ", adding dependencies " + items);
                - // We add to toplevel, because DeploymentControllerContext will deploy all kids when it goes to install
                - unit.getTopLevel().addAttachment(DependenciesMetaData.class, dependencies);
                - */
                - //ControllerContext context = unit.getAttachment(ControllerContext.class);
                - unit.addIDependOn(new AbstractDependencyItem(unit.getName(), TransactionManager.class, new ControllerState("Real"), ControllerState.INSTALLED));
                - }
                + }
                
                - private DependencyItemMetaData createDependencyItemMetaData(String name)
                - {
                - DependencyItemMetaData item = new DependencyItemMetaData();
                - item.setValue(name);
                - // This is ugly, MC checks on String value
                - //item.setWhenRequired(new ControllerState(DeploymentStages.REAL.toString()));
                - item.setWhenRequired(new ControllerState("Real"));
                - item.setDependentState(ControllerState.INSTALLED);
                - return item;
                - }
                + /**
                + * Adds a dependency on {@link TransactionManager} class to the <code>unit</code>
                + * if the deployment unit contains a EJB3 deployment.
                + *
                + * @param unit The unit being deployed
                + */
                + public void deploy(DeploymentUnit unit) throws DeploymentException
                + {
                + JBossMetaData metadata = unit.getAttachment(JBossMetaData.class);
                
                - public Class<JBossMetaData> getVisitorType()
                - {
                - return JBossMetaData.class;
                - }
                + // we have marked this deployer as requiring the JBossMetaData input,
                + // so if it's not present then its an issue with MC deployers framework, hence
                + // the assert instead of an exception
                + assert metadata != null : "Unit " + unit + " does not have " + JBossMetaData.class + " as attachment";
                
                - public void undeploy(DeploymentUnit unit, JBossMetaData deployment)
                - {
                - }
                - };
                - setDeploymentVisitor(visitor);
                + // we are only interested in EJB3 deployments
                + if (!metadata.isEJB3x())
                + {
                + return;
                + }
                + if (log.isTraceEnabled())
                + {
                + log.trace("Adding " + TransactionManager.class + " as a dependency on unit " + unit);
                + }
                + // add a dependency on the unit
                + unit.addIDependOn(new AbstractDependencyItem(unit.getName(), TransactionManager.class,
                + new ControllerState("Real"), ControllerState.INSTALLED));
                +
                 }
                 }
                



                Thoughts?

                • 5. Re: Cleaning up Logging
                  Carlo de Wolf Master

                  Better to create an extension on the DeploymentVisitor to not only specify the type, but also the name.

                  • 6. Re: Cleaning up Logging
                    Andrew Rubinger Master

                     

                    "ALRubinger" wrote:
                    23:18:05,567 INFO [EJB3EndpointDeployer] Deploy AbstractBeanMetaData@6687ec13{name=jboss.j2ee:jar=profileservice-secured.jar,name=SecureDeploymentManager,service=EJB3_endpoint bean=org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl properties=[container] constructor=null autowireCandidate=true}


                    https://jira.jboss.org/jira/browse/EJBTHREE-1848

                    Resolved by jboss-ejb3-endpoint-deployer/0.1.4.

                    "ALRubinger" wrote:
                    23:18:05,572 INFO [Ejb3MetricsDeployer] Attaching MC Bean: SecureManagementView-metrics-instance


                    Resolved by jboss-ejb3-metrics-deployer/1.0.0-alpha-7.

                    Also I've updated AS Branch_5_x to use the new endpoint-deployer, as-int to use new metrics-deployer, and Plugin to use both.

                    S,
                    ALR