Server Log "Skipping aggresive-release..."

[mcaughey]

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

[perfectionist]

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.

[conkan]

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.

[scottdawson]

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

[scottdawson]

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

[derkoensen]

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?