6 Replies Latest reply on Dec 8, 2010 12:15 PM by sergiu_pienar

    com.arjuna.ats.internal.jta.transaction.arjunacore.lastResou

    wlchung

      I am new to the JbossTS. Recently, I switch from the in memory
      TransactionManager to JbossTS to handle the time out. I follow the
      following step for the swap (for Jboss 4.0.3SP1)

      - copy the following jars from the JBossJTA installation into the
      server/XXX/lib directory of the application server installation
      - lib/jbossjta.jar
      - lib/jbossjta-integration.jar
      - lib/ext/jbossts-common.jar

      - copy the following configuration file from the JBossJTA installation into
      the server/XXX/conf directory of the application server installation
      - etc/jbossjta-properties.xml

      - edit the server/XXX/conf/jboss-service.xml file and replace the
      jboss:service=TransactionManager mbean declaration with the following


      300


      - (update) copy the following jars into the server/XXX/lib directory of the
      JBoss 4.0.3 SP1 installation
      - jboss/jboss.jar
      - jboss/jboss-iiop.jar
      - jboss/jboss-hibernate.jar

      - (update) copy the following jar into the server/XXX/deploy/jboss-aop.deployer
      directory of the JBoss 4.0.3 SP1 installation
      installation
      - jboss/jboss-aspect-library.jar

      Since I am using jboss-portal 2.2.1-SP1 together with spring-portal, I also have the Spring bean.

      <!-- JTA Transaction Manager -->








      I have 2 datasource, one for jbportal and one for my portal application. Their configuration are similar, differ by user/pass.

      <?xml version="1.0" encoding="UTF-8"?>


      <local-tx-datasource>
      <jndi-name>MyAppDS</jndi-name>
      <connection-url>jdbc:mysql://127.0.0.1:3306/myappds?profileSql=true&useUnicode=true&characterEncoding=UTF-8</connection-url>
      <driver-class>com.mysql.jdbc.Driver</driver-class>
      <user-name>myuser</user-name>
      myuserpasswd
      <exception-sorter-class-name>org.jboss.resource.adapter.jdbc.vendor.MySQLExceptionSorter</exception-sorter-class-name>

      <type-mapping>mySQL</type-mapping>

      <set-tx-query-timeout>true</set-tx-query-timeout>
      </local-tx-datasource>


      However, after the change, I cannot get the system to works. The following is the log. After a long search of, I wonder if it related to the XA or 2 datasources stuff, but I really have no clue right now. Can anyone have any ideas about this problem?



      ************************* start of log
      00:07:41,221 INFO [Server] Starting JBoss (MX MicroKernel)...
      00:07:41,221 INFO [Server] Release ID: JBoss [Zion] 4.0.3SP1 (build: CVSTag=JBoss_4_0_3_SP1 date=200510231054)
      00:07:41,221 INFO [Server] Home Dir: D:\App\jboss-4.0.3
      00:07:41,221 INFO [Server] Home URL: file:/D:/App/jboss-4.0.3/
      00:07:41,231 INFO [Server] Patch URL: null
      00:07:41,231 INFO [Server] Server Name: default
      00:07:41,231 INFO [Server] Server Home Dir: D:\App\jboss-4.0.3\server\default
      00:07:41,231 INFO [Server] Server Home URL: file:/D:/App/jboss-4.0.3/server/default/
      00:07:41,231 INFO [Server] Server Temp Dir: D:\App\jboss-4.0.3\server\default\tmp
      00:07:41,231 INFO [Server] Root Deployment Filename: jboss-service.xml
      00:07:42,012 INFO [ServerInfo] Java version: 1.4.2,Sun Microsystems Inc.
      00:07:42,012 INFO [ServerInfo] Java VM: Java HotSpot(TM) Client VM 1.4.2-b28,Sun Microsystems Inc.
      00:07:42,012 INFO [ServerInfo] OS-System: Windows XP 5.1,x86
      00:07:43,214 INFO [Server] Core system initialized
      00:07:47,981 INFO [WebService] Using RMI server codebase: http://experss:8083/
      00:07:48,051 INFO [Log4jService$URLWatchTimerTask] Configuring from URL: resource:log4j.xml
      INFO [NamingService] Started jndi bootstrap jnpPort=1099, rmiPort=1098, backlog=50, bindAddress=/0.0.0.0, Client SocketFactory=null, Server SocketFactory=org.jboss.net.sockets.DefaultSocketFactory@ad093076 [2007-08-27 00:07:48,672]
      INFO [TransactionManagerService] JBossTS Transaction Service (JTA version) - JBoss Inc. [2007-08-27 00:07:49,313]
      INFO [TransactionManagerService] Setting up property manager MBean and JMX layer [2007-08-27 00:07:49,313]
      INFO [TransactionManagerService] Starting recovery manager [2007-08-27 00:07:50,294]
      INFO [TransactionManagerService] Recovery manager started [2007-08-27 00:07:50,815]
      INFO [TransactionManagerService] Binding TransactionManager JNDI Reference [2007-08-27 00:07:50,815]
      INFO [TreeCache] interceptor chain is:
      class org.jboss.cache.interceptors.CallInterceptor
      class org.jboss.cache.interceptors.LockInterceptor
      class org.jboss.cache.interceptors.UnlockInterceptor [2007-08-27 00:08:13,678]
      INFO [TreeCache] cache mode is local, will not create the channel [2007-08-27 00:08:13,678]
      INFO [Embedded] Catalina naming disabled [2007-08-27 00:08:18,174]
      INFO [Http11Protocol] Initializing Coyote HTTP/1.1 on http-0.0.0.0-8080 [2007-08-27 00:08:19,677]
      INFO [Catalina] Initialization processed in 1252 ms [2007-08-27 00:08:19,677]
      INFO [StandardService] Starting service jboss.web [2007-08-27 00:08:19,687]
      INFO [StandardEngine] Starting Servlet Engine: Apache Tomcat/5.5 [2007-08-27 00:08:19,717]
      INFO [StandardHost] XML validation disabled [2007-08-27 00:08:19,877]
      INFO [Catalina] Server startup in 280 ms [2007-08-27 00:08:19,957]
      INFO [TomcatDeployer] deploy, ctxPath=/invoker, warUrl=.../deploy/http-invoker.sar/invoker.war/ [2007-08-27 00:08:20,378]
      INFO [WebappLoader] Dual registration of jndi stream handler: factory already defined [2007-08-27 00:08:21,579]
      INFO [TomcatDeployer] deploy, ctxPath=/portal-cms, warUrl=.../deploy/jboss-portal.sar/portal-cms.war/ [2007-08-27 00:08:22,901]
      INFO [TomcatDeployer] deploy, ctxPath=/portal-core, warUrl=.../deploy/jboss-portal.sar/portal-core.war/ [2007-08-27 00:08:23,162]
      INFO [FacesConfigurator] Reading standard config org/apache/myfaces/resource/standard-faces-config.xml [2007-08-27 00:08:24,373]
      INFO [FacesConfigurator] Reading config jar:file:/D:/App/jboss-4.0.3/server/default/tmp/deploy/tmp1953jsf-facelets.jar!/META-INF/faces-config.xml [2007-08-27 00:08:24,714]
      INFO [FacesConfigurator] Reading config jar:file:/D:/App/jboss-4.0.3/server/default/tmp/deploy/tmp1968tomahawk.jar!/META-INF/faces-config.xml [2007-08-27 00:08:24,734]
      INFO [FacesConfigurator] Reading config /WEB-INF/faces-config.xml [2007-08-27 00:08:25,014]
      ERROR [LocaleUtils] Locale name null or empty, ignoring [2007-08-27 00:08:25,695]
      INFO [StartupServletContextListener] ServletContext 'D:\App\jboss-4.0.3\server\default\.\deploy\jboss-portal.sar\portal-core.war\' initialized. [2007-08-27 00:08:29,781]
      INFO [TomcatDeployer] deploy, ctxPath=/portal-samples, warUrl=.../deploy/jboss-portal.sar/portal-samples.war/ [2007-08-27 00:08:29,861]
      INFO [TomcatDeployer] deploy, ctxPath=/, warUrl=.../deploy/jboss-portal.sar/portal-server.war/ [2007-08-27 00:08:30,162]
      INFO [TomcatDeployer] deploy, ctxPath=/ws4ee, warUrl=.../tmp/deploy/tmp1977jboss-ws4ee-exp.war/ [2007-08-27 00:08:31,283]
      INFO [TomcatDeployer] deploy, ctxPath=/jbossmq-httpil, warUrl=.../deploy/jms/jbossmq-httpil.sar/jbossmq-httpil.war/ [2007-08-27 00:08:32,074]
      INFO [MailService] Mail Service bound to java:/Mail [2007-08-27 00:08:37,813]
      INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-local-jdbc.rar [2007-08-27 00:08:39,695]
      INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-xa-jdbc.rar [2007-08-27 00:08:40,156]
      INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-local-jdbc.rar [2007-08-27 00:08:40,356]
      INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-xa-jdbc.rar [2007-08-27 00:08:40,536]
      INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jms/jms-ra.rar [2007-08-27 00:08:40,797]
      INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/mail-ra.rar [2007-08-27 00:08:41,137]
      INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:name=FinDS,service=DataSourceBinding' to JNDI name 'java:FinDS' [2007-08-27 00:08:42,169]
      INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:name=JmsXA,service=ConnectionFactoryBinding' to JNDI name 'java:JmsXA' [2007-08-27 00:08:43,711]
      INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:name=DefaultDS,service=DataSourceBinding' to JNDI name 'java:DefaultDS' [2007-08-27 00:08:44,112]
      INFO [A] Bound to JNDI name: queue/A [2007-08-27 00:08:45,383]
      INFO [B] Bound to JNDI name: queue/B [2007-08-27 00:08:45,383]
      INFO [C] Bound to JNDI name: queue/C [2007-08-27 00:08:45,393]
      INFO [D] Bound to JNDI name: queue/D [2007-08-27 00:08:45,414]
      INFO [ex] Bound to JNDI name: queue/ex [2007-08-27 00:08:45,424]
      INFO [testTopic] Bound to JNDI name: topic/testTopic [2007-08-27 00:08:45,554]
      INFO [securedTopic] Bound to JNDI name: topic/securedTopic [2007-08-27 00:08:45,554]
      INFO [testDurableTopic] Bound to JNDI name: topic/testDurableTopic [2007-08-27 00:08:45,574]
      INFO [testQueue] Bound to JNDI name: queue/testQueue [2007-08-27 00:08:45,584]
      INFO [UILServerILService] JBossMQ UIL service available at : /0.0.0.0:8093 [2007-08-27 00:08:46,004]
      INFO [DLQ] Bound to JNDI name: queue/DLQ [2007-08-27 00:08:46,195]
      INFO [Environment] Hibernate 3.1 [2007-08-27 00:08:46,635]
      INFO [Environment] hibernate.properties not found [2007-08-27 00:08:46,685]
      INFO [Environment] using CGLIB reflection optimizer [2007-08-27 00:08:46,705]
      INFO [Environment] using JDK 1.4 java.sql.Timestamp handling [2007-08-27 00:08:46,705]
      INFO [Configuration] configuring from url: file:/D:/App/jboss-4.0.3/server/default/deploy/jboss-portal.sar/conf/hibernate/user/hibernate.cfg.xml [2007-08-27 00:08:47,166]
      INFO [Configuration] Reading mappings from resource: conf/hibernate/user/domain.hbm.xml [2007-08-27 00:08:47,176]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.user.UserImpl -> jbp_users [2007-08-27 00:08:47,707]
      INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.user.UserImpl.dynamic -> jbp_user_prop [2007-08-27 00:08:47,847]
      INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.user.UserImpl.roles -> jbp_role_membership [2007-08-27 00:08:47,877]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.user.PreferencesGroupImpl -> jbp_user_prefs_group [2007-08-27 00:08:47,877]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.user.PreferencesImpl -> jbp_user_pref_set [2007-08-27 00:08:47,877]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.user.PreferenceImpl -> jbp_user_pref [2007-08-27 00:08:47,877]
      INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.user.PreferenceImpl.strings -> jbp_user_pref_value [2007-08-27 00:08:47,877]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.role.RoleImpl -> jbp_roles [2007-08-27 00:08:47,887]
      INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.role.RoleImpl.users -> jbp_role_membership [2007-08-27 00:08:47,887]
      INFO [Configuration] Configured SessionFactory: null [2007-08-27 00:08:47,887]
      INFO [Configuration] configuring from url: file:/D:/App/jboss-4.0.3/server/default/deploy/jboss-portal.sar/conf/hibernate/instance/hibernate.cfg.xml [2007-08-27 00:08:47,887]
      INFO [Configuration] Reading mappings from resource: conf/hibernate/instance/domain.hbm.xml [2007-08-27 00:08:47,907]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.model.instance.InstanceImpl -> JBP_INSTANCE [2007-08-27 00:08:47,967]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.model.instance.PreferenceImpl -> JBP_INSTANCE_PREF [2007-08-27 00:08:48,047]
      INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.model.instance.PreferenceImpl.strings -> JBP_INSTANCE_PREF_VALUE [2007-08-27 00:08:48,047]
      INFO [Configuration] Configured SessionFactory: null [2007-08-27 00:08:48,047]
      INFO [Configuration] configuring from url: file:/D:/App/jboss-4.0.3/server/default/deploy/jboss-portal.sar/conf/hibernate/portal/hibernate.cfg.xml [2007-08-27 00:08:48,087]
      INFO [Configuration] Reading mappings from resource: conf/hibernate/portal/domain.hbm.xml [2007-08-27 00:08:48,107]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.model.portal.ObjectNode -> JBP_OBJECT_NODE [2007-08-27 00:08:48,147]
      INFO [HbmBinder] Mapping class: org.jboss.portal.core.impl.model.portal.PortalObjectImpl -> JBP_PORTAL_OBJECT [2007-08-27 00:08:48,568]
      INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.model.portal.PortalObjectImpl.declaredProperties -> JBP_PORTAL_OBJECT_PROPS [2007-08-27 00:08:48,578]
      INFO [HbmBinder] Mapping joined-subclass: org.jboss.portal.core.impl.model.portal.ContextImpl -> JBP_CONTEXT [2007-08-27 00:08:48,718]
      INFO [HbmBinder] Mapping joined-subclass: org.jboss.portal.core.impl.model.portal.PortalImpl -> JBP_PORTAL [2007-08-27 00:08:48,718]
      INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.model.portal.PortalImpl.modes -> JBP_PORTAL_MODE [2007-08-27 00:08:48,718]
      INFO [HbmBinder] Mapping collection: org.jboss.portal.core.impl.model.portal.PortalImpl.windowStates -> JBP_PORTAL_WINDOW_STATE [2007-08-27 00:08:48,718]
      INFO [HbmBinder] Mapping joined-subclass: org.jboss.portal.core.impl.model.portal.PageImpl -> JBP_PAGE [2007-08-27 00:08:48,718]
      INFO [HbmBinder] Mapping joined-subclass: org.jboss.portal.core.impl.model.portal.WindowImpl -> JBP_WINDOW [2007-08-27 00:08:48,718]
      INFO [Configuration] Configured SessionFactory: null [2007-08-27 00:08:48,728]
      INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:name=PortalDS,service=DataSourceBinding' to JNDI name 'java:PortalDS' [2007-08-27 00:08:48,858]
      INFO [JCRCMS] Starting JCR CMS [2007-08-27 00:08:48,858]
      INFO [HibernateStore] BUILDING SessionFactory. [2007-08-27 00:08:49,279]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/CMSEntry.hbm.xml [2007-08-27 00:08:49,279]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.CMSEntry -> jbp_cms_cmsentry [2007-08-27 00:08:49,309]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/VersionEntry.hbm.xml [2007-08-27 00:08:49,319]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.VersionEntry -> jbp_cms_versionentry [2007-08-27 00:08:49,369]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/RepositoryEntry.hbm.xml [2007-08-27 00:08:49,379]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.RepositoryEntry -> jbp_cms_repositoryentry [2007-08-27 00:08:49,429]
      INFO [Configuration] processing extends queue [2007-08-27 00:08:49,429]
      INFO [Configuration] processing collection mappings [2007-08-27 00:08:49,429]
      INFO [Configuration] processing association property references [2007-08-27 00:08:49,429]
      INFO [Configuration] processing foreign key constraints [2007-08-27 00:08:49,429]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:49,489]
      INFO [DatasourceConnectionProvider] Using datasource: java:PortalDS [2007-08-27 00:08:49,489]
      INFO [SettingsFactory] RDBMS: MySQL, version: 4.1.20-community [2007-08-27 00:08:49,529]
      INFO [SettingsFactory] JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.0.17-ga ( $Date: 2005/04/06 14:12:56 $, $Revision: 1.27.2.47 $ ) [2007-08-27 00:08:49,529]
      INFO [Dialect] Using dialect: org.hibernate.dialect.MySQLDialect [2007-08-27 00:08:49,670]
      INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.transaction.JTATransactionFactory [2007-08-27 00:08:49,710]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:49,730]
      INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup [2007-08-27 00:08:49,740]
      INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup [2007-08-27 00:08:49,750]
      INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup [2007-08-27 00:08:49,750]
      INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup [2007-08-27 00:08:49,750]
      INFO [SettingsFactory] Automatic flush during beforeCompletion(): enabled [2007-08-27 00:08:49,750]
      INFO [SettingsFactory] Automatic session close at end of transaction: disabled [2007-08-27 00:08:49,750]
      INFO [SettingsFactory] Scrollable result sets: enabled [2007-08-27 00:08:49,760]
      INFO [SettingsFactory] JDBC3 getGeneratedKeys(): enabled [2007-08-27 00:08:49,760]
      INFO [SettingsFactory] Connection release mode: auto [2007-08-27 00:08:49,760]
      INFO [SettingsFactory] Maximum outer join fetch depth: 2 [2007-08-27 00:08:49,760]
      INFO [SettingsFactory] Default batch fetch size: 1 [2007-08-27 00:08:49,760]
      INFO [SettingsFactory] Generate SQL with comments: disabled [2007-08-27 00:08:49,760]
      INFO [SettingsFactory] Order SQL updates by primary key: disabled [2007-08-27 00:08:49,760]
      INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory [2007-08-27 00:08:49,760]
      INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory [2007-08-27 00:08:49,790]
      INFO [SettingsFactory] Query language substitutions: {} [2007-08-27 00:08:49,790]
      INFO [SettingsFactory] Second-level cache: enabled [2007-08-27 00:08:49,790]
      INFO [SettingsFactory] Query cache: disabled [2007-08-27 00:08:49,790]
      INFO [SettingsFactory] Cache provider: org.hibernate.cache.HashtableCacheProvider [2007-08-27 00:08:49,790]
      INFO [SettingsFactory] Optimize cache for minimal puts: disabled [2007-08-27 00:08:49,810]
      INFO [SettingsFactory] Structured second-level cache entries: disabled [2007-08-27 00:08:49,810]
      INFO [SettingsFactory] Statistics: disabled [2007-08-27 00:08:49,840]
      INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled [2007-08-27 00:08:49,840]
      INFO [SettingsFactory] Default entity-mode: POJO [2007-08-27 00:08:49,840]
      INFO [SessionFactoryImpl] building session factory [2007-08-27 00:08:50,501]
      INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured [2007-08-27 00:08:51,873]
      INFO [SchemaUpdate] Running hbm2ddl schema update [2007-08-27 00:08:51,913]
      INFO [SchemaUpdate] fetching database metadata [2007-08-27 00:08:51,913]
      INFO [SchemaUpdate] updating schema [2007-08-27 00:08:51,913]
      INFO [Configuration] processing extends queue [2007-08-27 00:08:51,913]
      INFO [Configuration] processing collection mappings [2007-08-27 00:08:51,913]
      INFO [Configuration] processing association property references [2007-08-27 00:08:51,913]
      INFO [Configuration] processing foreign key constraints [2007-08-27 00:08:51,913]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_cmsentry [2007-08-27 00:08:52,033]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:52,033]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:52,033]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:52,033]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_repositoryentry [2007-08-27 00:08:52,083]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:52,083]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:52,083]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:52,083]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_versionentry [2007-08-27 00:08:52,103]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:52,103]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:52,103]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:52,103]
      INFO [SchemaUpdate] schema update complete [2007-08-27 00:08:52,103]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:52,113]
      INFO [SessionFactoryImpl] Checking 0 named queries [2007-08-27 00:08:52,113]
      INFO [HibernateStore] HibernateSessionFactory Created. [2007-08-27 00:08:52,113]
      INFO [HibernateStore] BUILDING SessionFactory. [2007-08-27 00:08:52,113]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/CMSEntry.hbm.xml [2007-08-27 00:08:52,113]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.CMSEntry -> jbp_cms_cmsentry [2007-08-27 00:08:52,163]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/VersionEntry.hbm.xml [2007-08-27 00:08:52,163]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.VersionEntry -> jbp_cms_versionentry [2007-08-27 00:08:52,203]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/RepositoryEntry.hbm.xml [2007-08-27 00:08:52,203]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.RepositoryEntry -> jbp_cms_repositoryentry [2007-08-27 00:08:52,223]
      INFO [Configuration] processing extends queue [2007-08-27 00:08:52,223]
      INFO [Configuration] processing collection mappings [2007-08-27 00:08:52,223]
      INFO [Configuration] processing association property references [2007-08-27 00:08:52,223]
      INFO [Configuration] processing foreign key constraints [2007-08-27 00:08:52,223]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:52,223]
      INFO [DatasourceConnectionProvider] Using datasource: java:PortalDS [2007-08-27 00:08:52,223]
      INFO [SettingsFactory] RDBMS: MySQL, version: 4.1.20-community [2007-08-27 00:08:52,223]
      INFO [SettingsFactory] JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.0.17-ga ( $Date: 2005/04/06 14:12:56 $, $Revision: 1.27.2.47 $ ) [2007-08-27 00:08:52,223]
      INFO [Dialect] Using dialect: org.hibernate.dialect.MySQLDialect [2007-08-27 00:08:52,253]
      INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.transaction.JTATransactionFactory [2007-08-27 00:08:52,253]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:52,253]
      INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup [2007-08-27 00:08:52,253]
      INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup [2007-08-27 00:08:52,253]
      INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup [2007-08-27 00:08:52,253]
      INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Automatic flush during beforeCompletion(): enabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Automatic session close at end of transaction: disabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Scrollable result sets: enabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] JDBC3 getGeneratedKeys(): enabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Connection release mode: auto [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Maximum outer join fetch depth: 2 [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Default batch fetch size: 1 [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Generate SQL with comments: disabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Order SQL updates by primary key: disabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory [2007-08-27 00:08:52,253]
      INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Query language substitutions: {} [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Second-level cache: enabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Query cache: disabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Cache provider: org.hibernate.cache.HashtableCacheProvider [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Optimize cache for minimal puts: disabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Structured second-level cache entries: disabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Statistics: disabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled [2007-08-27 00:08:52,253]
      INFO [SettingsFactory] Default entity-mode: POJO [2007-08-27 00:08:52,253]
      INFO [SessionFactoryImpl] building session factory [2007-08-27 00:08:52,263]
      INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured [2007-08-27 00:08:52,474]
      INFO [SchemaUpdate] Running hbm2ddl schema update [2007-08-27 00:08:52,474]
      INFO [SchemaUpdate] fetching database metadata [2007-08-27 00:08:52,474]
      INFO [SchemaUpdate] updating schema [2007-08-27 00:08:52,474]
      INFO [Configuration] processing extends queue [2007-08-27 00:08:52,474]
      INFO [Configuration] processing collection mappings [2007-08-27 00:08:52,474]
      INFO [Configuration] processing association property references [2007-08-27 00:08:52,474]
      INFO [Configuration] processing foreign key constraints [2007-08-27 00:08:52,474]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_cmsentry [2007-08-27 00:08:52,514]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:52,514]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:52,514]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:52,514]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_repositoryentry [2007-08-27 00:08:52,534]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:52,534]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:52,534]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:52,534]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_versionentry [2007-08-27 00:08:52,564]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:52,564]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:52,564]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:52,564]
      INFO [SchemaUpdate] schema update complete [2007-08-27 00:08:52,574]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:52,574]
      INFO [SessionFactoryImpl] Checking 0 named queries [2007-08-27 00:08:52,574]
      INFO [HibernateStore] HibernateSessionFactory Created. [2007-08-27 00:08:52,574]
      INFO [HibernateStore] BUILDING SessionFactory. [2007-08-27 00:08:52,584]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/CMSEntry.hbm.xml [2007-08-27 00:08:52,584]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.CMSEntry -> jbp_cms_cmsentry [2007-08-27 00:08:52,624]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/VersionEntry.hbm.xml [2007-08-27 00:08:52,624]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.VersionEntry -> jbp_cms_versionentry [2007-08-27 00:08:52,754]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/RepositoryEntry.hbm.xml [2007-08-27 00:08:52,754]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.RepositoryEntry -> jbp_cms_repositoryentry [2007-08-27 00:08:52,784]
      INFO [Configuration] processing extends queue [2007-08-27 00:08:52,784]
      INFO [Configuration] processing collection mappings [2007-08-27 00:08:52,784]
      INFO [Configuration] processing association property references [2007-08-27 00:08:52,784]
      INFO [Configuration] processing foreign key constraints [2007-08-27 00:08:52,784]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:52,784]
      INFO [DatasourceConnectionProvider] Using datasource: java:PortalDS [2007-08-27 00:08:52,784]
      INFO [SettingsFactory] RDBMS: MySQL, version: 4.1.20-community [2007-08-27 00:08:52,784]
      INFO [SettingsFactory] JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.0.17-ga ( $Date: 2005/04/06 14:12:56 $, $Revision: 1.27.2.47 $ ) [2007-08-27 00:08:52,784]
      INFO [Dialect] Using dialect: org.hibernate.dialect.MySQLDialect [2007-08-27 00:08:52,784]
      INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.transaction.JTATransactionFactory [2007-08-27 00:08:52,784]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:52,794]
      INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup [2007-08-27 00:08:52,794]
      INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup [2007-08-27 00:08:52,794]
      INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup [2007-08-27 00:08:52,794]
      INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Automatic flush during beforeCompletion(): enabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Automatic session close at end of transaction: disabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Scrollable result sets: enabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] JDBC3 getGeneratedKeys(): enabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Connection release mode: auto [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Maximum outer join fetch depth: 2 [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Default batch fetch size: 1 [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Generate SQL with comments: disabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Order SQL updates by primary key: disabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory [2007-08-27 00:08:52,794]
      INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Query language substitutions: {} [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Second-level cache: enabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Query cache: disabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Cache provider: org.hibernate.cache.HashtableCacheProvider [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Optimize cache for minimal puts: disabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Structured second-level cache entries: disabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Statistics: disabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled [2007-08-27 00:08:52,794]
      INFO [SettingsFactory] Default entity-mode: POJO [2007-08-27 00:08:52,794]
      INFO [SessionFactoryImpl] building session factory [2007-08-27 00:08:52,804]
      INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured [2007-08-27 00:08:52,954]
      INFO [SchemaUpdate] Running hbm2ddl schema update [2007-08-27 00:08:52,954]
      INFO [SchemaUpdate] fetching database metadata [2007-08-27 00:08:52,954]
      INFO [SchemaUpdate] updating schema [2007-08-27 00:08:52,954]
      INFO [Configuration] processing extends queue [2007-08-27 00:08:52,954]
      INFO [Configuration] processing collection mappings [2007-08-27 00:08:52,954]
      INFO [Configuration] processing association property references [2007-08-27 00:08:52,954]
      INFO [Configuration] processing foreign key constraints [2007-08-27 00:08:52,954]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_cmsentry [2007-08-27 00:08:53,014]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:53,014]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:53,014]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:53,014]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_repositoryentry [2007-08-27 00:08:53,044]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:53,044]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:53,044]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:53,044]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_versionentry [2007-08-27 00:08:53,095]
      INFO [TableMetadata] columns: [fsentry_path, fsentry_data, fsentry_name, fsentry_length, fsentry_lastmod, pk] [2007-08-27 00:08:53,095]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:53,095]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:53,095]
      INFO [SchemaUpdate] schema update complete [2007-08-27 00:08:53,105]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:53,105]
      INFO [SessionFactoryImpl] Checking 0 named queries [2007-08-27 00:08:53,105]
      INFO [HibernateStore] HibernateSessionFactory Created. [2007-08-27 00:08:53,105]
      WARN [RepositoryImpl] Existing lock file at D:\App\jboss-4.0.3\server\default\data\portal\cms\conf\.lock deteteced. Repository was not shutdown properly. [2007-08-27 00:08:53,355]
      INFO [HibernatePersistenceManager] BUILDING SessionFactory. [2007-08-27 00:08:57,351]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/state/WSPBinVal.hbm.xml [2007-08-27 00:08:57,381]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.state.WSPBinVal -> jbp_cms_wsp_binval [2007-08-27 00:08:57,411]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/state/VersionBinVal.hbm.xml [2007-08-27 00:08:57,431]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.state.VersionBinVal -> jbp_cms_version_binval [2007-08-27 00:08:57,481]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/state/WSPNode.hbm.xml [2007-08-27 00:08:57,501]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.state.WSPNode -> jbp_cms_wsp_node [2007-08-27 00:08:57,571]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/state/VersionNode.hbm.xml [2007-08-27 00:08:57,581]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.state.VersionNode -> jbp_cms_version_node [2007-08-27 00:08:57,621]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/state/WSPProp.hbm.xml [2007-08-27 00:08:57,641]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.state.WSPProp -> jbp_cms_wsp_prop [2007-08-27 00:08:57,681]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/state/VersionProp.hbm.xml [2007-08-27 00:08:57,701]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.state.VersionProp -> jbp_cms_version_prop [2007-08-27 00:08:57,761]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/state/WSPRefs.hbm.xml [2007-08-27 00:08:57,771]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.state.WSPRefs -> jbp_cms_wsp_refs [2007-08-27 00:08:57,831]
      INFO [Configuration] Reading mappings from resource: org/jboss/portal/cms/hibernate/state/VersionRefs.hbm.xml [2007-08-27 00:08:57,841]
      INFO [HbmBinder] Mapping class: org.jboss.portal.cms.hibernate.state.VersionRefs -> jbp_cms_version_refs [2007-08-27 00:08:57,881]
      INFO [Configuration] processing extends queue [2007-08-27 00:08:57,881]
      INFO [Configuration] processing collection mappings [2007-08-27 00:08:57,881]
      INFO [Configuration] processing association property references [2007-08-27 00:08:57,881]
      INFO [Configuration] processing foreign key constraints [2007-08-27 00:08:57,881]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:57,881]
      INFO [DatasourceConnectionProvider] Using datasource: java:PortalDS [2007-08-27 00:08:57,881]
      INFO [SettingsFactory] RDBMS: MySQL, version: 4.1.20-community [2007-08-27 00:08:57,881]
      INFO [SettingsFactory] JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.0.17-ga ( $Date: 2005/04/06 14:12:56 $, $Revision: 1.27.2.47 $ ) [2007-08-27 00:08:57,881]
      INFO [Dialect] Using dialect: org.hibernate.dialect.MySQLDialect [2007-08-27 00:08:57,881]
      INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.transaction.JTATransactionFactory [2007-08-27 00:08:57,881]
      INFO [NamingHelper] JNDI InitialContext properties:{} [2007-08-27 00:08:57,901]
      INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup [2007-08-27 00:08:57,901]
      INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup [2007-08-27 00:08:57,901]
      INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup [2007-08-27 00:08:57,901]
      INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Automatic flush during beforeCompletion(): enabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Automatic session close at end of transaction: disabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Scrollable result sets: enabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] JDBC3 getGeneratedKeys(): enabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Connection release mode: auto [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Maximum outer join fetch depth: 2 [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Default batch fetch size: 1 [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Generate SQL with comments: disabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Order SQL updates by primary key: disabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory [2007-08-27 00:08:57,901]
      INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Query language substitutions: {} [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Second-level cache: enabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Query cache: disabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Cache provider: org.hibernate.cache.HashtableCacheProvider [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Optimize cache for minimal puts: disabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Structured second-level cache entries: disabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Statistics: disabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled [2007-08-27 00:08:57,901]
      INFO [SettingsFactory] Default entity-mode: POJO [2007-08-27 00:08:57,901]
      INFO [SessionFactoryImpl] building session factory [2007-08-27 00:08:57,911]
      INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured [2007-08-27 00:08:58,462]
      INFO [SchemaUpdate] Running hbm2ddl schema update [2007-08-27 00:08:58,462]
      INFO [SchemaUpdate] fetching database metadata [2007-08-27 00:08:58,462]
      INFO [SchemaUpdate] updating schema [2007-08-27 00:08:58,462]
      INFO [Configuration] processing extends queue [2007-08-27 00:08:58,462]
      INFO [Configuration] processing collection mappings [2007-08-27 00:08:58,462]
      INFO [Configuration] processing association property references [2007-08-27 00:08:58,462]
      INFO [Configuration] processing foreign key constraints [2007-08-27 00:08:58,462]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_version_binval [2007-08-27 00:08:58,532]
      INFO [TableMetadata] columns: [binval_id, binval_data, pk] [2007-08-27 00:08:58,532]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:58,532]
      INFO [TableMetadata] indexes: [primary] [2007-08-27 00:08:58,532]
      INFO [TableMetadata] table found: jbportal22.jbp_cms_version_node [2007-08-27 00:08:58,542]
      INFO [TableMetadata] columns: [node_data, node_id, pk] [2007-08-27 00:08:58,542]
      INFO [TableMetadata] foreign keys: [] [2007-08-27 00:08:58,542]

      .
      .
      .
      INFO [EARDeployer] Started J2EE application: file:/D:/App/jboss-4.0.3/server/default/deploy/smpear.ear [2007-08-27 00:10:42,832]
      INFO [Http11Protocol] Starting Coyote HTTP/1.1 on http-0.0.0.0-8080 [2007-08-27 00:10:43,153]
      INFO [ChannelSocket] JK: ajp13 listening on /0.0.0.0:8009 [2007-08-27 00:10:43,724]
      INFO [JkMain] Jk running ID=0 time=0/311 config=null [2007-08-27 00:10:43,864]
      INFO [Server] JBoss (MX MicroKernel) [4.0.3SP1 (build: CVSTag=JBoss_4_0_3_SP1 date=200510231054)] Started in 3m:2s:693ms [2007-08-27 00:10:43,934]
      INFO [STDOUT] Query "SET autocommit=0" execution time: 0 [2007-08-27 00:12:20,973]
      WARN [loggerI18N] [com.arjuna.ats.internal.jta.transaction.arjunacore.lastResource.disallow] [com.arjuna.ats.internal.jta.transaction.arjunacore.lastResource.disallow] Adding multiple last resources is disallowed. Current resource is org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@126be3a [2007-08-27 00:12:20,973]
      ERROR [Ads#findByPrimaryKey] Find failed [2007-08-27 00:12:21,004]
      org.jboss.util.NestedSQLException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: -3f57fe24:c3b:46d1a555:1b47 status: ActionStatus.ABORT_ONLY >); - nested throwable: (org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: -3f57fe24:c3b:46d1a555:1b47 status: ActionStatus.ABORT_ONLY >))
      at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:79)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:210)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:128)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCFindByPrimaryKeyQuery.execute(JDBCFindByPrimaryKeyQuery.java:128)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCFindEntityCommand.execute(JDBCFindEntityCommand.java:47)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.findEntity(JDBCStoreManager.java:589)
      at org.jboss.ejb.plugins.CMPPersistenceManager.findEntity(CMPPersistenceManager.java:300)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.findEntity(CachedConnectionInterceptor.java:236)
      at org.jboss.ejb.EntityContainer.findSingleObject(EntityContainer.java:1086)
      at org.jboss.ejb.EntityContainer.find(EntityContainer.java:715)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
      at java.lang.reflect.Method.invoke(Unknown Source)
      at org.jboss.invocation.Invocation.performCall(Invocation.java:345)
      at org.jboss.ejb.EntityContainer$ContainerInterceptor.invokeHome(EntityContainer.java:1113)
      at org.jboss.ejb.plugins.AbstractInterceptor.invokeHome(AbstractInterceptor.java:90)
      at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invokeHome(EntitySynchronizationInterceptor.java:189)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invokeHome(CachedConnectionInterceptor.java:180)
      at org.jboss.ejb.plugins.AbstractInterceptor.invokeHome(AbstractInterceptor.java:90)
      at org.jboss.ejb.plugins.EntityInstanceInterceptor.invokeHome(EntityInstanceInterceptor.java:119)
      at org.jboss.ejb.plugins.EntityLockInterceptor.invokeHome(EntityLockInterceptor.java:61)
      at org.jboss.ejb.plugins.EntityCreationInterceptor.invokeHome(EntityCreationInterceptor.java:28)
      at org.jboss.ejb.plugins.CallValidationInterceptor.invokeHome(CallValidationInterceptor.java:41)
      at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:110)
      at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:335)
      at org.jboss.ejb.plugins.TxInterceptorCMT.invokeHome(TxInterceptorCMT.java:146)
      at org.jboss.ejb.plugins.SecurityInterceptor.invokeHome(SecurityInterceptor.java:130)
      at org.jboss.ejb.plugins.LogInterceptor.invokeHome(LogInterceptor.java:121)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invokeHome(ProxyFactoryFinderInterceptor.java:93)
      at org.jboss.ejb.EntityContainer.internalInvokeHome(EntityContainer.java:508)
      at org.jboss.ejb.Container.invoke(Container.java:894)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
      at java.lang.reflect.Method.invoke(Unknown Source)
      at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:141)
      at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80)
      at org.jboss.mx.server.Invocation.invoke(Invocation.java:72)
      at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:245)
      at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:644)
      at org.jboss.invocation.local.LocalInvoker$MBeanServerAction.invoke(LocalInvoker.java:155)
      at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:104)
      at org.jboss.invocation.InvokerInterceptor.invokeMarshalled(InvokerInterceptor.java:201)
      at org.jboss.invocation.MarshallingInvokerInterceptor.invoke(MarshallingInvokerInterceptor.java:35)
      at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
      at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:55)
      at org.jboss.proxy.ejb.HomeInterceptor.invoke(HomeInterceptor.java:169)
      at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:86)
      at $Proxy183.findByPrimaryKey(Unknown Source)
      at com.ss.simpleMsg.controller.AdsCtlr.handleRender(AdsCtlr.java:50)
      at org.springframework.web.portlet.mvc.AbstractCommandController.handleRenderRequestInternal(AbstractCommandController.java:139)
      at org.springframework.web.portlet.mvc.AbstractController.handleRenderRequest(AbstractController.java:184)
      at org.springframework.web.portlet.mvc.SimpleControllerHandlerAdapter.handleRender(SimpleControllerHandlerAdapter.java:44)
      at org.springframework.web.portlet.DispatcherPortlet.doRenderDispatch(DispatcherPortlet.java:815)
      at org.springframework.web.portlet.DispatcherPortlet.doRenderService(DispatcherPortlet.java:668)
      at org.springframework.web.portlet.FrameworkPortlet.serviceWrapper(FrameworkPortlet.java:408)
      at org.springframework.web.portlet.FrameworkPortlet.doDispatch(FrameworkPortlet.java:382)
      at javax.portlet.GenericPortlet.render(GenericPortlet.java:407)
      at org.jboss.portal.portlet.PortletContainer.invokeRender(PortletContainer.java:521)
      at org.jboss.portal.portlet.PortletContainer.dispatch(PortletContainer.java:433)
      at org.jboss.portal.server.app.ComponentInvocation.dispatch(ComponentInvocation.java:79)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:140)
      at org.jboss.portal.core.aspects.component.TransactionInterceptor.invoke(TransactionInterceptor.java:72)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.component.HeaderInterceptor.invoke(HeaderInterceptor.java:50)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.aspects.component.NavigationInterceptor.invoke(NavigationInterceptor.java:76)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.aspects.component.CacheInterceptor.invoke(CacheInterceptor.java:167)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.aspects.component.ModesInterceptor.invoke(ModesInterceptor.java:88)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.aspects.component.WindowStatesInterceptor.invoke(WindowStatesInterceptor.java:87)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.bridge.BridgeInterceptor.invoke(BridgeInterceptor.java:49)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.portlet.aspects.component.SessionPostDispatchInterceptor.invoke(SessionPostDispatchInterceptor.java:65)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.aspects.component.ContextDispatcherInterceptor$InvokeNextCommand.execute(ContextDispatcherInterceptor.java:129)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
      at java.lang.reflect.Method.invoke(Unknown Source)
      at org.jboss.portal.server.servlet.CommandServlet.doGet(CommandServlet.java:101)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:697)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:672)
      at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:539)
      at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:499)
      at org.jboss.portal.server.app.impl.AbstractRequestContext.include(AbstractRequestContext.java:247)
      at org.jboss.portal.server.aspects.component.ContextDispatcherInterceptor$1.include(ContextDispatcherInterceptor.java:73)
      at org.jboss.portal.server.servlet.CommandServlet.include(CommandServlet.java:81)
      at org.jboss.portal.server.aspects.component.ContextDispatcherInterceptor.invoke(ContextDispatcherInterceptor.java:79)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.portlet.aspects.component.SessionPreDispatchInterceptor.invoke(SessionPreDispatchInterceptor.java:94)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.aspects.component.ContextTrackerInterceptor.invoke(ContextTrackerInterceptor.java:49)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.portlet.aspects.component.SecureTransportInterceptor.invoke(SecureTransportInterceptor.java:69)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.portlet.aspects.component.ValveInterceptor.invoke(ValveInterceptor.java:64)
      at org.jboss.portal.server.app.ComponentInterceptor.invoke(ComponentInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.invocation.Invocation.invoke(Invocation.java:175)
      at org.jboss.portal.core.command.RenderWindowCommand.execute(RenderWindowCommand.java:84)
      at org.jboss.portal.core.command.ControllerCommand.dispatch(ControllerCommand.java:78)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:140)
      at org.jboss.portal.core.aspects.controller.EventBroadcasterInterceptor.invoke(EventBroadcasterInterceptor.java:85)
      at org.jboss.portal.core.command.CommandInterceptor.invoke(CommandInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.controller.PolicyEnforcementInterceptor.invoke(PolicyEnforcementInterceptor.java:168)
      at org.jboss.portal.core.command.CommandInterceptor.invoke(CommandInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.controller.PortalNodeInterceptor.invoke(PortalNodeInterceptor.java:61)
      at org.jboss.portal.core.command.CommandInterceptor.invoke(CommandInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.controller.NavigationInterceptor.invoke(NavigationInterceptor.java:68)
      at org.jboss.portal.core.command.CommandInterceptor.invoke(CommandInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.invocation.Invocation.invoke(Invocation.java:175)
      at org.jboss.portal.core.command.CommandContext.execute(CommandContext.java:107)
      at org.jboss.portal.core.command.CommandContext.chain(CommandContext.java:141)
      at org.jboss.portal.core.command.RenderPageCommand.renderPortlets(RenderPageCommand.java:231)
      at org.jboss.portal.core.command.RenderPageCommand.execute(RenderPageCommand.java:164)
      at org.jboss.portal.core.command.ControllerCommand.dispatch(ControllerCommand.java:78)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:140)
      at org.jboss.portal.core.aspects.controller.EventBroadcasterInterceptor.invoke(EventBroadcasterInterceptor.java:85)
      at org.jboss.portal.core.command.CommandInterceptor.invoke(CommandInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.controller.PolicyEnforcementInterceptor.invoke(PolicyEnforcementInterceptor.java:168)
      at org.jboss.portal.core.command.CommandInterceptor.invoke(CommandInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.controller.PortalNodeInterceptor.invoke(PortalNodeInterceptor.java:61)
      at org.jboss.portal.core.command.CommandInterceptor.invoke(CommandInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.controller.NavigationInterceptor.invoke(NavigationInterceptor.java:58)
      at org.jboss.portal.core.command.CommandInterceptor.invoke(CommandInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.invocation.Invocation.invoke(Invocation.java:175)
      at org.jboss.portal.core.command.CommandContext.execute(CommandContext.java:107)
      at org.jboss.portal.core.command.ExecutionContext.execute(ExecutionContext.java:93)
      at org.jboss.portal.core.command.ExecutionContext.execute(ExecutionContext.java:77)
      at org.jboss.portal.core.CoreController.handle(CoreController.java:190)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
      at java.lang.reflect.Method.invoke(Unknown Source)
      at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:141)
      at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80)
      at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:118)
      at org.jboss.mx.server.Invocation.invoke(Invocation.java:74)
      at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:127)
      at org.jboss.mx.server.Invocation.invoke(Invocation.java:74)
      at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:245)
      at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:644)
      at org.jboss.mx.util.JMXInvocationHandler.invoke(JMXInvocationHandler.java:273)
      at $Proxy181.handle(Unknown Source)
      at org.jboss.portal.server.ServerInvocation.dispatch(ServerInvocation.java:76)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:140)
      at org.jboss.portal.core.aspects.server.SubjectAssociationInterceptor.invoke(SubjectAssociationInterceptor.java:47)
      at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.server.PolicyAssociationInterceptor.invoke(PolicyAssociationInterceptor.java:52)
      at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.aspects.server.ContentTypeInterceptor.invoke(ContentTypeInterceptor.java:68)
      at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.server.LocaleInterceptor.invoke(LocaleInterceptor.java:69)
      at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.server.UserInterceptor.invoke(UserInterceptor.java:184)
      at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.aspects.server.SessionInvalidatorInterceptor.invoke(SessionInvalidatorInterceptor.java:87)
      at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.core.aspects.server.TransactionInterceptor.invoke(TransactionInterceptor.java:75)
      at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      at org.jboss.portal.server.invocation.Invocation.invokeNext(Invocation.java:130)
      at org.jboss.portal.server.invocation.Invocation.invoke(Invocation.java:175)
      at org.jboss.portal.server.servlet.PortalServlet.doGet(PortalServlet.java:221)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:697)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:81)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
      at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:39)
      at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:159)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:407)
      at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:59)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)
      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)
      at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
      at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)
      at java.lang.Thread.run(Unknown Source)
      Caused by: org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: -3f57fe24:c3b:46d1a555:1b47 status: ActionStatus.ABORT_ONLY >)
      at org.jboss.resource.connectionmanager.TxConnectionManager.managedConnectionReconnected(TxConnectionManager.java:373)
      at org.jboss.resource.connectionmanager.BaseConnectionManager2.reconnectManagedConnection(BaseConnectionManager2.java:598)
      at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:465)
      at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:894)
      at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:73)
      ... 218 more
      Caused by: javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: -3f57fe24:c3b:46d1a555:1b47 status: ActionStatus.ABORT_ONLY >
      at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener$TransactionSynchronization.checkEnlisted(TxConnectionManager.java:742)
      at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener.enlist(TxConnectionManager.java:603)
      at org.jboss.resource.connectionmanager.TxConnectionManager.managedConnectionReconnected(TxConnectionManager.java:367)
      ... 222 more
      WARN [DispatcherPortlet] Handler execution resulted in exception - forwarding to resolved error view [2007-08-27 00:12:21,304]
      javax.ejb.FinderException: Find failed: org.jboss.util.NestedSQLException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: -3f57fe24:c3b:46d1a555:1b47 status: ActionStatus.ABORT_ONLY >); - nested throwable: (org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: -3f57fe24:c3b:46d1a555:1b47 status: ActionStatus.ABORT_ONLY >))
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:245)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:128)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCFindByPrimaryKeyQuery.execute(JDBCFindByPrimaryKeyQuery.java:128)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCFindEntityCommand.execute(JDBCFindEntityCommand.java:47)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.findEntity(JDBCStoreManager.java:589)
      at org.jboss.ejb.plugins.CMPPersistenceManager.findEntity(CMPPersistenceManager.java:300)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.findEntity(CachedConnectionInterceptor.java:236)
      at org.jboss.ejb.EntityContainer.findSingleObject(EntityContainer.java:1086)
      at org.jboss.ejb.EntityContainer.find(EntityContainer.java:715)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
      at java.lang.reflect.Method.invoke(Unknown Source)
      at org.jboss.invocation.Invocation.performCall(Invocation.java:345)
      at org.jboss.ejb.EntityContainer$ContainerInterceptor.invokeHome(EntityContainer.java:111

        • 1. Re: com.arjuna.ats.internal.jta.transaction.arjunacore.lastR
          marklittle

          Well I suppose:

          WARN [loggerI18N] [com.arjuna.ats.internal.jta.transaction.arjunacore.lastResource.disallow] [com.arjuna.ats.internal.jta.transaction.arjunacore.lastResource.disallow] Adding multiple last resources is disallowed. Current resource is org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@126be3a [2007-08-27 00:12:20,973]
          


          is a bit of a give-away.

          You don't say which version of JBossTS you are using, but it should be the most recent if you want to support multiple one-phase resources in the same transaction. If it is the latest release, then check out the documentation (or the main TS labs page) for how to enable it.

          • 2. jta.transaction.arjunacore.lastResource.disallow
            wlchung

            Yes, I am using the latest JbossTS, 4.2.3 SP5.

            I find a way in a page, in a language that I cannot read, to let my application run again by add the bold line below in jboss-service.xml

            <properties depends="arjuna" name="jta">
             <property name="com.arjuna.ats.jta.allowMultipleLastResources" value="true"/>
             <!-- ... other properties ... -->
            </properties>


            And with this warning.

            WARN [loggerI18N] [com.arjuna.ats.internal.jta.transaction.arjunacore.lastResource.multipleWarning]
            [com.arjuna.ats.internal.jta.transaction.arjunacore.lastResource.multipleWarning] Multiple last resources have been added to the current transaction. This is transactionally unsafe and should not be relied upon. Current resource is
            org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1b8fa10

            After reading the document you referred, I can verified the cause of my problem. And I understand more and sure that my problem is "Enlisting multiple one-phase aware resources". Seems that my only option now is to upgrade my mysql to 5.0. Hope that its XA limitation is not a problem to my application.

            More when I am done with it.

            • 3. Re: com.arjuna.ats.internal.jta.transaction.arjunacore.lastR
              marklittle

              While I think you definitely should be upgrading so you don't put more than one 1PC resource in the same transaction, the configuration option you've now enabled does allow that. The warning you are getting is just that: a warning.

              • 4. Re: com.arjuna.ats.internal.jta.transaction.arjunacore.lastR
                wlchung

                I am using 3 datasources ( 1 for Jboss AS, 1 for Jboss Portal 2.2 and 1 for my portal application). So I am upgrading to MySQL 5.0.45 for its XA data source support.

                As expected, the upgrade is not smooth, is time klling and is frustrating. The current issue is

                2007-08-31 12:09:16,914 INFO [STDOUT] Fri Aug 31 12:09:16 CST 2007 INFO: Profiler Event: [QUERY] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.start(XAManagedConnection.java:131) duration: 0 ms, connection-id: 226, statement-id: 191, resultset-id: 0, message: XA START 0x312d2d33663537666532343a313262653a34366437393161613a32356439,0x2d33663537666532343a313262653a34366437393161613a32356464,0x20003
                
                2007-08-31 12:09:16,914 INFO [STDOUT] Fri Aug 31 12:09:16 CST 2007 INFO: Profiler Event: [FETCH] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.start(XAManagedConnection.java:131) duration: 0 ms, connection-id: 226, statement-id: 191, resultset-id: 0
                
                2007-08-31 12:09:16,924 INFO [STDOUT] Fri Aug 31 12:09:16 CST 2007 INFO: Profiler Event: [QUERY] at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:211) duration: 0 ms, connection-id: 226, statement-id: 192, resultset-id: 132, message: SELECT t0_MsgSet.account, t0_MsgSet.setname FROM msgset t0_MsgSet WHERE t0_MsgSet.account='john' AND t0_MsgSet.setname='pubmisn'
                
                2007-08-31 12:09:16,924 INFO [STDOUT] Fri Aug 31 12:09:16 CST 2007 INFO: Profiler Event: [FETCH] at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:211) duration: 0 ms, connection-id: 226, statement-id: 192, resultset-id: 132
                
                2007-08-31 12:09:43,392 INFO [STDOUT] Fri Aug 31 12:09:43 CST 2007 INFO: Profiler Event: [QUERY] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.end(XAManagedConnection.java:146) duration: 0 ms, connection-id: 225, statement-id: 193, resultset-id: 0, message: XA END 0x312d2d33663537666532343a313262653a34366437393161613a32356137,0x2d33663537666532343a313262653a34366437393161613a32356234,0x20003
                
                2007-08-31 12:09:43,392 INFO [STDOUT] Fri Aug 31 12:09:43 CST 2007 INFO: Profiler Event: [FETCH] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.end(XAManagedConnection.java:146) duration: 0 ms, connection-id: 225, statement-id: 193, resultset-id: 0
                
                2007-08-31 12:09:43,392 INFO [STDOUT] Fri Aug 31 12:09:43 CST 2007 INFO: Profiler Event: [QUERY] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:185) duration: 0 ms, connection-id: 225, statement-id: 194, resultset-id: 0, message: XA ROLLBACK 0x312d2d33663537666532343a313262653a34366437393161613a32356137,0x2d33663537666532343a313262653a34366437393161613a32356234,0x20003
                
                2007-08-31 12:09:43,392 INFO [STDOUT] Fri Aug 31 12:09:43 CST 2007 INFO: Profiler Event: [FETCH] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:185) duration: 0 ms, connection-id: 225, statement-id: 194, resultset-id: 0
                
                2007-08-31 12:09:43,402 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id -3f57fe24:12be:46d791aa:25d9 invoked while multiple threads active within it.
                
                2007-08-31 12:09:43,402 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action -3f57fe24:12be:46d791aa:25d9 aborting with 1 threads active!
                
                2007-08-31 12:09:43,402 INFO [STDOUT] Fri Aug 31 12:09:43 CST 2007 INFO: Profiler Event: [QUERY] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.end(XAManagedConnection.java:146) duration: 0 ms, connection-id: 226, statement-id: 195, resultset-id: 0, message: XA END 0x312d2d33663537666532343a313262653a34366437393161613a32356439,0x2d33663537666532343a313262653a34366437393161613a32356464,0x20003
                
                2007-08-31 12:09:43,552 INFO [STDOUT] Fri Aug 31 12:09:43 CST 2007 INFO: Profiler Event: [FETCH] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.end(XAManagedConnection.java:146) duration: 0 ms, connection-id: 226, statement-id: 195, resultset-id: 0
                
                2007-08-31 12:09:43,562 INFO [STDOUT] Fri Aug 31 12:09:43 CST 2007 INFO: Profiler Event: [QUERY] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:185) duration: 0 ms, connection-id: 226, statement-id: 196, resultset-id: 0, message: XA ROLLBACK 0x312d2d33663537666532343a313262653a34366437393161613a32356439,0x2d33663537666532343a313262653a34366437393161613a32356464,0x20003
                
                2007-08-31 12:09:43,572 INFO [STDOUT] Fri Aug 31 12:09:43 CST 2007 INFO: Profiler Event: [FETCH] at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:185) duration: 0 ms, connection-id: 226, statement-id: 196, resultset-id: 0
                
                2007-08-31 12:09:43,572 ERROR [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackLocalException in method: public abstract com.ss.simpleMsg.ejb.MsgSetData com.ss.simpleMsg.ejb.MsgSetLocal.getData(), causedBy:
                
                org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fe24:12be:46d791aa:25d9 status: ActionStatus.ABORTING >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fe24:12be:46d791aa:25d9 status: ActionStatus.ABORTING >)
                

                It takes me 2 full whole days and night to test and analyse logs to guess the meaning of this message.

                "Abort of action id -3f57fe24:12be:46d791aa:25d9 invoked while multiple threads active within it."


                Now I guess (hope someone can correct me if I am wrong as this is really a guess) the meaning is:
                "There are active 2 threads and they share the same transaction. One of them rollback the transaction and the other thread then have no valid transaction as it already ended by the 1st thread. This result the invalid status".

                Knowing this does not help because the 2 threads are the 2 portlet of a portal page. In fact, the above rollback was caused by one of these threads locking an entity needed by the other thread. (However, I wonder why there was no time-out message).

                So I wonder if there is any configuration in JbossTS that can control this situation, i.e. the sequence of the threads, .... . Or may be configurations in Jboss or Jboss Portal. Definitely, it cannot be controlled in my application, which I hope I can.

                • 5. Re: com.arjuna.ats.internal.jta.transaction.arjunacore.lastR
                  marklittle

                  Yes, your transaction is being terminated with multiple threads still associated with it. This could be due to an application not behaving as you might expect/want with regards to its threads, or maybe a transaction is timing out and TS is rolling it back when the creating thread is still active.

                  JBossTS can't control the ordering of your threads. It has no knowledge about what threads belong to what application, service, or whatever.

                  Try increasing the timeout associated with your transaction. If you can't do that, try increasing the default timeout (this is a global option, so it will affect all transactions created by that instance of AS).

                  • 6. Re: com.arjuna.ats.internal.jta.transaction.arjunacore.lastResou
                    sergiu_pienar

                    How was this issue solved? I am dealing with it now.

                     

                    Thx