10 Replies Latest reply on Jun 16, 2009 8:02 PM by gonorrhea

    server.log is HUGE due to Seam logging

    gonorrhea

      Seam 2.0.2-FP


      current server.log size is 434MB!


      I'm hoping I'm doing something wrong here.


      The following logging in my server.log (EAP 4.3.0_CP02) is being logged way too much!


      Why is this happening?


      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.util.Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.contexts.Contexts] found in conversation context: org.jboss.seam.persistence.persistenceContexts
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.contexts.Contexts] found in conversation context: entityManager
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.util.Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.contexts.Contexts] found in conversation context: org.jboss.seam.persistence.persistenceContexts
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.contexts.Contexts] found in conversation context: entityManager
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.util.Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.contexts.Contexts] found in conversation context: org.jboss.seam.persistence.persistenceContexts
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.contexts.Contexts] found in conversation context: entityManager
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.util.Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.contexts.Contexts] found in conversation context: org.jboss.seam.persistence.persistenceContexts
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.contexts.Contexts] found in conversation context: entityManager
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.util.Naming] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] instantiating Seam component: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] initializing new instance of: org.jboss.seam.persistence.persistenceProvider
      2009-06-15 13:59:45,585 DEBUG [org.jboss.seam.Component] done initializing: org.jboss.seam.persistence.persistenceProvider
      


        • 1. Re: server.log is HUGE due to Seam logging
          gonorrhea

          components.xml:


          <?xml version="1.0" encoding="UTF-8"?>
          <components xmlns="http://jboss.com/products/seam/components"
                      xmlns:core="http://jboss.com/products/seam/core"            
                      xmlns:persistence="http://jboss.com/products/seam/persistence"
                      xmlns:drools="http://jboss.com/products/seam/drools"
                      xmlns:bpm="http://jboss.com/products/seam/bpm"
                      xmlns:security="http://jboss.com/products/seam/security"
                      xmlns:mail="http://jboss.com/products/seam/mail"
                      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
                      xmlns:transaction="http://jboss.com/products/seam/transaction"
                      xsi:schemaLocation=
                          "http://jboss.com/products/seam/core http://jboss.com/products/seam/core-2.0.xsd 
                           http://jboss.com/products/seam/persistence http://jboss.com/products/seam/persistence-2.0.xsd 
                           http://jboss.com/products/seam/drools http://jboss.com/products/seam/drools-2.0.xsd
                           http://jboss.com/products/seam/bpm http://jboss.com/products/seam/bpm-2.0.xsd
                           http://jboss.com/products/seam/security http://jboss.com/products/seam/security-2.0.xsd
                           http://jboss.com/products/seam/mail http://jboss.com/products/seam/mail-2.0.xsd
                           http://jboss.com/products/seam/components http://jboss.com/products/seam/components-2.0.xsd">
               
             <core:init debug="@debug@" jndi-pattern="@jndiPattern@"/>
             
             <!--  AS 04/06/09 - as per Seam ref docs:  In an EJB3 environment, we recommend the use of a special
                    built-in component for transaction management, that is fully aware of container transactions,
                    and can correctly process transaction success events registered with the Events component. If
                    you don't add this line to your components.xml file, Seam won't know when container-managed
                    transactions end: -->
             
             <transaction:ejb-transaction/>
               
             <!-- per CSP case 245236: set concurrent-request-timeout from 500 to 2000 -->
             <!-- 03/03/09 - setting conversation-timeout="120000" (2 minutes) b/c this applies to background conversations only, not the active conversation-->
             <core:manager concurrent-request-timeout="3000" 
                           conversation-timeout="600000" 
                           conversation-id-parameter="cid"
                           parent-conversation-id-parameter="pid"/>
              
             <persistence:managed-persistence-context name="entityManager"
                                               auto-create="true"
                                persistence-unit-jndi-name="java:/EquipmentRecoveryEntityManagerFactory"/> 
             
             <!-- use entityManagerSupport for modalPanels only -->
             
             <!--                 
             <persistence:managed-persistence-context name="entityManagerSupport"
                                               auto-create="true"
                                persistence-unit-jndi-name="java:/EquipmentRecoveryEntityManagerFactory"/>        
             -->              
             <persistence:managed-persistence-context name="entityManagerDSS"
                                               auto-create="true"
                                persistence-unit-jndi-name="java:/coxDSSEntityManagerFactory"/>   
              
             <drools:rule-base name="securityRules">
                 <drools:rule-files>
                     <value>/security.drl</value>
                 </drools:rule-files>
             </drools:rule-base>
          
             <security:identity security-rules="#{securityRules}" authenticate-method="#{authenticator.authenticate}"/>
             
             <!-- Convenience factories -->
               
             <!--  requestContextPath -->
             <factory name="requestContextPath" value="#{facesContext.externalContext.requestContextPath}" />
             
             <!--  testing -->
             <!-- <mail:mail-session host="localhost" port="2525" username="test" password="test" /> -->
             <mail:mail-session host="CORG0MS01.corp.cox.com"/>
             <!--  end testing -->
                
          </components>
          



          persistence.xml:


          <?xml version="1.0" encoding="UTF-8"?>
          <!-- Persistence deployment descriptor for dev profile -->
          <persistence xmlns="http://java.sun.com/xml/ns/persistence" 
                       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
                       xsi:schemaLocation="http://java.sun.com/xml/ns/persistence http://java.sun.com/xml/ns/persistence/persistence_1_0.xsd" 
                       version="1.0">
                       
             <persistence-unit name="EquipmentRecovery">
                <provider>org.hibernate.ejb.HibernatePersistence</provider>
                <jta-data-source>java:/EquipmentRecoveryDatasource</jta-data-source>
                <properties>
                   <property name="hibernate.dialect" value="org.hibernate.dialect.SQLServerDialect"/>
                   <!-- <property name="hibernate.hbm2ddl.auto" value="validate"/>  -->
                   <property name="hibernate.show_sql" value="true"/>
                   <property name="hibernate.format_sql" value="true"/>
                   <property name="hibernate.generate_statistics" value="true"/>
                   <property name="jboss.entity.manager.factory.jndi.name" value="java:/EquipmentRecoveryEntityManagerFactory"/>
                   <property name="hibernate.default_catalog" value="EquipmentRecovery"/>
                   <property name="hibernate.default_schema" value="dbo"/>
                </properties>
             </persistence-unit>
                
             <persistence-unit name="coxDSS">
                <provider>org.hibernate.ejb.HibernatePersistence</provider>
                <jta-data-source>java:/coxDSSDatasource</jta-data-source>
                <properties>
                   <property name="hibernate.dialect" value="org.hibernate.dialect.SQLServerDialect"/>         
                   <property name="hibernate.show_sql" value="true"/>
                   <property name="hibernate.format_sql" value="true"/>
                   <property name="jboss.entity.manager.factory.jndi.name" value="java:/coxDSSEntityManagerFactory"/>
                   <property name="hibernate.default_catalog" value="coxDSS"/>
                   <property name="hibernate.default_schema" value="dbo"/>
                </properties>
             </persistence-unit>
             
          </persistence>



          foo-ds.xml:


          <?xml version="1.0" encoding="UTF-8"?>
          
          <!DOCTYPE datasources
              PUBLIC "-//JBoss//DTD JBOSS JCA Config 1.5//EN"
              "http://www.jboss.org/j2ee/dtd/jboss-ds_1_5.dtd">
              
          <datasources>
             
             <local-tx-datasource>
                <jndi-name>EquipmentRecoveryDatasource</jndi-name>
                <connection-url>jdbc:sqlserver://CORG0DB901:1433;databaseName=EquipmentRecovery</connection-url>
                <driver-class>com.microsoft.sqlserver.jdbc.SQLServerDriver</driver-class>
                <user-name>_AppUser_JavaTestAcct</user-name>
                <password>JavaTestAcct</password>     
             </local-tx-datasource>
             
             <!-- DB02 is prod instance, currently using for dev, UAT and prod envmts... -->   
             <!-- this is already in the BETS-dev-ds.xml, so we're getting:
             org.jboss.deployment.DeploymentException: Trying to install an already registered mbean: jboss.jca:service=LocalTxCM,name=coxDSSDatasource
             fix: needs to be moved into its own foo-ds.xml file so it only is read once in the server/default/deploy folder...
              -->
                  
             <local-tx-datasource>
                <jndi-name>coxDSSDatasource</jndi-name>
                <connection-url>jdbc:sqlserver://CORG0DB02\ORGSQLDW;databaseName=coxDSS</connection-url>
                <driver-class>com.microsoft.sqlserver.jdbc.SQLServerDriver</driver-class>
                <user-name>_AppUser_SQL</user-name>
                <password>4pp$ql333</password>     
             </local-tx-datasource>
              
          </datasources>

          • 2. Re: server.log is HUGE due to Seam logging
            gonorrhea

            after startup, server.log size is 4.1MB.  Seems kinda high even with logging level set at DEBUG.  There's only one client hitting this workstation (me).

            • 3. Re: server.log is HUGE due to Seam logging
              gonorrhea

              In comparison, seam-booking's server.log is 1.9MB after startup.


              I was debugging the org.jboss.seam.Component.newInstance() method and that method is called dozens of times when the session begins and when I load a JSF page (at least in my case and the booking as well apparently).


              The following output:


              instantiating Seam component: org.jboss.seam.persistence.persistenceProvider



              is not showing in the server.log for seam-booking (most likely b/c that app is not using SMPC!)




              • 4. Re: server.log is HUGE due to Seam logging
                gonorrhea

                Now I'm seeing this in IE7:



                A script on this page is causing IE to run slowly.  If it continues to run, your computer may become unresponsive.
                • 5. Re: server.log is HUGE due to Seam logging
                  nickarls

                  Adjust your log level in the AS conf

                  • 6. Re: server.log is HUGE due to Seam logging
                    gonorrhea

                    Nicklas Karlsson wrote on Jun 16, 2009 09:48:


                    Adjust your log level in the AS conf


                    Yes, I know that will reduce the amount of logging (I set it to ERROR level in UAT box).


                    But I need to know if the methods are being called too excessively.  Is that high of a logging size normal for a Seam app with only one user running functional tests???

                    • 7. Re: server.log is HUGE due to Seam logging
                      jeanluc

                      They are excessive, indeed. Perhaps your entities are Seam components? If so, the first call to any of their methods (which might be something as trivial as an equals() or a hashCode() called when they are put in a collection after the retrieval) will trigger the injection.


                      If so (and, because of this, in general as well) I'd suggest that entities not be components.

                      • 8. Re: server.log is HUGE due to Seam logging
                        gonorrhea

                        My entities are not Seam components (i.e. no @Name at the class level).

                        • 9. Re: server.log is HUGE due to Seam logging
                          jeanluc

                          OK, then identify which components get all those logged injections. From the log, I cannot determine whether there is a single component that's repeatedly called or if there are many instances of the same class.

                          • 10. Re: server.log is HUGE due to Seam logging
                            gonorrhea

                            I remember there being different ones (events comes to mind, for example) when I added the breakpoint in the debugger...