5 Replies Latest reply on May 11, 2007 7:05 AM by Hans Peter

    Server Log "Skipping aggresive-release..."

    Michael Caughey Newbie

      What is this message for in the Server log?

      Skipping aggresive-release due to open resources on batcher

      The number of them appear to be growing with each new server boot.

      I'm running AS 4.0.3SP1
      Portal 2.2
      MySQL 4.0.25


      ...
      17:55:27,511 WARN [Configurator] No configuration found. Configuring ehcache from ehcache-failsafe.xml found in the classpath: jar:file:/S:/jboss-4.0.3SP1/server/ppoc/tmp/deploy/tmp41209ehcache.jar!/ehcache-failsafe.xml
      17:55:27,620 WARN [EhCacheProvider] Could not find configuration [org.jboss.portal.core.security.store.SecurityPolicy]; using defaults.
      17:55:27,979 WARN [EhCacheProvider] Could not find configuration [org.jboss.portal.core.security.store.HbmSecurityConstraint]; using defaults.
      17:55:28,136 INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
      17:55:28,136 INFO [NamingHelper] JNDI InitialContext properties:{}
      17:55:28,151 INFO [UpdateTimestampsCache] starting update timestamps cache at region: org.hibernate.cache.UpdateTimestampsCache
      17:55:28,151 WARN [EhCacheProvider] Could not find configuration [org.hibernate.cache.UpdateTimestampsCache]; using defaults.
      17:55:28,151 INFO [StandardQueryCache] starting query cache at region: org.hibernate.cache.StandardQueryCache
      17:55:28,151 WARN [EhCacheProvider] Could not find configuration [org.hibernate.cache.StandardQueryCache]; using defaults.
      17:55:28,151 INFO [SessionFactoryImpl] Checking 0 named queries
      17:55:28,745 INFO [TreeCache] interceptor chain is:
      class org.jboss.cache.interceptors.CallInterceptor
      class org.jboss.cache.interceptors.LockInterceptor
      class org.jboss.cache.interceptors.CacheStoreInterceptor
      class org.jboss.cache.interceptors.CacheLoaderInterceptor
      class org.jboss.cache.interceptors.UnlockInterceptor
      17:55:28,745 INFO [TreeCache] cache mode is local, will not create the channel
      17:55:28,745 INFO [TreeCache] preloading transient state from cache loader
      17:55:28,854 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:28,901 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,042 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,058 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,058 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,058 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,058 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,058 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,073 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,073 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,073 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,089 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,089 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,089 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,104 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,104 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,120 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,120 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,120 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,120 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,136 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,151 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,151 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,167 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,167 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,167 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,167 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,183 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,183 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,183 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:29,198 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,401 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,401 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,401 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,401 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,417 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,417 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,417 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,417 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,417 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,433 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,433 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,433 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,433 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,433 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,433 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,448 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,448 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,448 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,448 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,448 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,448 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,464 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,464 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,464 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,464 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,464 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,479 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,479 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,479 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,479 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,495 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,495 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,495 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,495 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,495 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,511 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,511 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,511 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,511 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,511 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,511 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,526 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,526 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,526 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,526 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,542 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,542 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,542 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,542 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,542 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,558 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,558 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,558 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,558 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,558 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,573 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,573 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,573 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,573 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,573 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,589 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,589 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,589 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,589 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,589 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,589 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,604 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,604 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,604 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,604 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,620 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,620 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,620 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,620 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,620 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,636 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,636 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,636 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,636 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,636 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,636 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,636 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,651 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,651 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,651 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:30,651 INFO [ConnectionManager] Skipping aggresive-release due to open resources on batcher
      17:55:33,151 INFO [TreeCache] preloading transient state from cache loader was successful (in 4406 milliseconds)
      17:55:33,214 INFO [TreeCache] interceptor chain is:
      class org.jboss.cache.interceptors.CallInterceptor
      class org.jboss.cache.interceptors.LockInterceptor
      class org.jboss.cache.interceptors.UnlockInterceptor
      17:55:33,214 INFO [TreeCache] cache mode is local, will not create the channel
      17:55:33,245 INFO [Configuration] processing extends queue
      17:55:33,245 INFO [Configuration] processing collection mappings
      17:55:33,245 INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.user.PreferencesGroupImpl.prefMap -> jbp_user_pref_set
      17:55:33,245 INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.user.PreferencesImpl.content -> jbp_user_pref
      17:55:33,245 INFO [Configuration] processing association property references
      17:55:33,245 INFO [Configuration] processing foreign key constraints
      17:55:33,245 INFO [NamingHelper] JNDI InitialContext properties:{}
      17:55:33,245 INFO [DatasourceConnectionProvider] Using datasource: java:PortalDS
      17:55:33,245 INFO [SettingsFactory] RDBMS: MySQL, version: 4.0.25-nt-max
      17:55:33,245 INFO [SettingsFactory] JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.10 ( $Date: 2005/05/19 15:52:23 $, $Revision: 1.1.2.2 $ )
      17:55:33,245 INFO [Dialect] Using dialect: org.hibernate.dialect.MySQLDialect
      17:55:33,245 INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.transaction.JTATransactionFactory
      17:55:33,245 INFO [NamingHelper] JNDI InitialContext properties:{}
      17:55:33,245 INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup
      17:55:33,245 INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup
      ...


      Thanks,
      Michael

        • 1. Re: Server Log
          David Loeffler Newbie

          I am starting to see the same behavior on my application. I am running 4.0.3SP1. I was hoping someone would have replied to your message since it would save me some time trying to figure out what is going on and if it is something I need to be concerned about.

          • 2. Re: Server Log
            Conrad Kanengieter Newbie

            I do not think that your question is a JBoss Portal question. I think it is a JBoss Application Server (AS) question. Therefore, see JBoss AS forum.

            The server has always given warnings and info statements when it starts. If you get no errors, then you are in good condition. If you are so concerned about JBoss AS server performance when it is running the JBoss Portal, then see the JBoss AS wiki pages and JBoss AS documents.

            • 3. Re: Server Log
              Scott Dawson Apprentice

              The message comes from Hibernate code - the org.hibernate.jdbc.ConnectionManager class. I'm running Portal 2.2.1RC3 with JBoss AS 4.0.4RC1 and it's become a DEBUG-level message, not INFO.

              There's a post about this on the Hibernate forum but it's not very informative:
              http://forums.hibernate.org/viewtopic.php?t=943262&view=previous&sid=67e6877b1bc0acc5710fe63ccd57f53b

              I wonder if the message indicates a minor Hibernate configuration problem.

              Regards,
              Scott Dawson
              Unisys

              • 4. Re: Server Log
                Scott Dawson Apprentice

                Here's the Hibernate code (release 3.1.2) from org.hibernate.jdbc.ConnectionManager. It looks like maybe the message is just informational because the aggressiveRelease method closes the JDBC Connection.

                /**
                 * To be called after execution of each JDBC statement. Used to
                 * conditionally release the JDBC connection aggressively if
                 * the configured release mode indicates.
                 */
                public void afterStatement() {
                 if ( isAggressiveRelease() ) {
                 if ( batcher.hasOpenResources() ) {
                 log.debug( "skipping aggresive-release due to open resources on batcher" );
                 }
                 else if ( borrowedConnection != null ) {
                 log.debug( "skipping aggresive-release due to borrowed connection" );
                 }
                 else {
                 aggressiveRelease();
                 }
                 }
                }
                


                Regards,
                Scott Dawson
                Unisys


                • 5. Re: Server Log
                  Hans Peter Newbie

                  Got the same "problems". It definitely comes from the AS. I wouldn't be concerned by that, if I didn't get problems with a closed connection (ORA-17008). That totally inhibits normal working of the productive system. But I've no ideas, if there is a relationship between this issues. Anyone got the same experiences?