JBoss 6.1.0.Final doesn't start on IBM System I (AS400) with OS 7.1.0
kingm Aug 1, 2012 8:00 AMWe use JBoss on System i since a long time which works fine, until we changed from OS 6.1.0 to OS 7.1.0. Now we have the problem that JBoss doesn't boot anymore. We are already in contact with IBM support and we made a lot of dumps which where analyzed from IBM. They can't find any problems in their system and VM (Java 6) and they told me to contact JBoss support.
We only know that JBoss always stopps at the same position in the boot log. The job's are active and still use CPU - but JBoss does not continuing booting. Can anybody tell me how we can find out what JBoss ist waiting for?
Boot log:
16:46:01,705 INFO [AbstractJBossASServerBase] Server Configuration:
JBOSS_HOME URL: file:/jboss/jboss-6.1.0.Final/
Bootstrap: $JBOSS_HOME/server/default/conf/bootstrap.xml
Common Base: $JBOSS_HOME/common/
Common Library: $JBOSS_HOME/common/lib/
Server Name: default
Server Base: $JBOSS_HOME/server/
Server Library: $JBOSS_HOME/server/default/lib/
Server Config: $JBOSS_HOME/server/default/conf/
Server Home: $JBOSS_HOME/server/default/
Server Data: $JBOSS_HOME/server/default/data/
Server Log: $JBOSS_HOME/server/default/log/
Server Temp: $JBOSS_HOME/server/default/tmp/
16:46:01,938 INFO [AbstractServer] Starting: JBossAS [6.1.0.Final "Neo"]
16:46:11,021 INFO [ServerInfo] Java version: 1.6.0,IBM Corporation
16:46:11,022 INFO [ServerInfo] Java Runtime: Java(TM) SE Runtime Environment (build jvmap3260sr10-20111208)
16:46:11,023 INFO [ServerInfo] Java VM: IBM J9 VM 2.4,IBM Corporation
16:46:11,024 INFO [ServerInfo] OS-System: OS/400 V7R1M0,PowerPC
16:46:11,041 INFO [ServerInfo] VM arguments: -Xjcl:jclscar_24 -Dcom.ibm.oti.vm.bootstrap.library.path=/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc -Dsun.boot.library.path=/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc -Djava.library.path=/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc/classic:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc/classic:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc/default:/usr/lib:/jboss/jboss-6.1.0.Final/bin/native/lib:/usr/lib -Djava.home=/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre -Djava.ext.dirs=/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ext -Duser.dir=/jboss/jboss-6.1.0.Final/bin _j2se_j9=71168 -Xdump -Dos400.vm.inputargs=-Xms128m -Xmx1536m -Dorg.jboss.resolver.warning=true -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dprogram.name=run.sh -Dlogging.configuration=file:./logging.properties -Djava.library.path=/jboss/jboss-6.1.0.Final/bin/native/lib -Djava.endorsed.dirs=/jboss/jboss-6.1.0.Final//lib/endorsed -Xms128m -Xmx1536m -Dorg.jboss.resolver.warning=true -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dprogram.name=run.sh -Dlogging.configuration=file:./logging.properties -Djava.library.path=/jboss/jboss-6.1.0.Final/bin/native/lib -Djava.endorsed.dirs=/jboss/jboss-6.1.0.Final//lib/endorsed -Djava.class.path=/jboss/jboss-6.1.0.Final//bin/run.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit//lib/tools.jar -Dos400.vm.inputargs=-Xms128m -Xmx1536m -Dorg.jboss.resolver.warning=true -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dprogram.name=run.sh -Dlogging.configuration=file:./logging.properties -Djava.library.path=/jboss/jboss-6.1.0.Final/bin/native/lib -Djava.endorsed.dirs=/jboss/jboss-6.1.0.Final//lib/endorsed -Djava.class.path=/jboss/jboss-6.1.0.Final//bin/run.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit//lib/tools.jar -Dos400.class.path.security.check=20 -Dos400.stdin.allowed=1 -Xargencoding:utf8 -Duser.home=/ -Xbootclasspath/a:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/IBMmisc.jar -Xbootclasspath/a:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/lib/IBMi5OSJSSE.jar -Dos.arch=PowerPC -Dos.name=OS/400 -Xruni5ostools -agentlib:i5ostools -Dos.version=V7R1M0 -Djava.ext.dirs=/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ext:/QIBM/UserData/Java400/ext -Duser.timezone=Europe/Zurich -Dfile.encoding=ISO8859_1 -Dos400.job.file.encoding=Cp273 -Dos400.file.encoding.ccsid=00819 _port_library _org.apache.harmony.vmi.portlib
16:46:11,045 DEBUG [ServerInfo] Full System Properties Dump
16:46:11,052 DEBUG [ServerInfo] bind.address: 10.90.0.101
16:46:11,052 DEBUG [ServerInfo] com.ibm.cpu.endian: big
16:46:11,053 DEBUG [ServerInfo] com.ibm.jcl.checkClassPath:
16:46:11,053 DEBUG [ServerInfo] com.ibm.oti.configuration: scar
16:46:11,054 DEBUG [ServerInfo] com.ibm.oti.jcl.build: 20111101_1053
16:46:11,054 DEBUG [ServerInfo] com.ibm.oti.shared.enabled: false
16:46:11,058 DEBUG [ServerInfo] com.ibm.oti.vm.bootstrap.library.path: /QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc
16:46:11,059 DEBUG [ServerInfo] com.ibm.oti.vm.library.version: 24
16:46:11,059 DEBUG [ServerInfo] com.ibm.util.extralibs.properties:
16:46:11,059 DEBUG [ServerInfo] com.ibm.vm.bitmode: 32
16:46:11,060 DEBUG [ServerInfo] file.encoding: ISO8859_1
16:46:11,060 DEBUG [ServerInfo] file.separator: /
16:46:11,061 DEBUG [ServerInfo] ibm.signalhandling.rs: false
16:46:11,061 DEBUG [ServerInfo] ibm.signalhandling.sigchain: true
16:46:11,061 DEBUG [ServerInfo] ibm.signalhandling.sigint: true
16:46:11,062 DEBUG [ServerInfo] ibm.system.encoding: ISO8859-1
16:46:11,062 DEBUG [ServerInfo] java.assistive: ON
16:46:11,063 DEBUG [ServerInfo] java.awt.fonts:
16:46:11,063 DEBUG [ServerInfo] java.awt.graphicsenv: sun.awt.X11GraphicsEnvironment
16:46:11,064 DEBUG [ServerInfo] java.awt.printerjob: sun.print.PSPrinterJob
16:46:11,064 DEBUG [ServerInfo] java.class.path: /jboss/jboss-6.1.0.Final//bin/run.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit//lib/tools.jar
16:46:11,065 DEBUG [ServerInfo] java.class.version: 50.0
16:46:11,065 DEBUG [ServerInfo] java.compiler: j9jit24
16:46:11,066 DEBUG [ServerInfo] java.endorsed.dirs: /jboss/jboss-6.1.0.Final//lib/endorsed
16:46:11,066 DEBUG [ServerInfo] java.ext.dirs: /QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ext:/QIBM/UserData/Java400/ext
16:46:11,067 DEBUG [ServerInfo] java.fullversion: JRE 1.6.0 IBM J9 2.4 OS/400 ppc-32 jvmap3260sr10-20111208 (JIT enabled, AOT enabled)
J9VM - 20111207_096808
JIT - r9_20111107_21307ifx1
GC - 20110519_AA
16:46:11,067 DEBUG [ServerInfo] java.home: /QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre
16:46:11,068 DEBUG [ServerInfo] java.io.tmpdir: /tmp/
16:46:11,068 DEBUG [ServerInfo] java.jcl.version: 20111220_01
16:46:11,069 DEBUG [ServerInfo] java.library.path: /jboss/jboss-6.1.0.Final/bin/native/lib
16:46:11,069 DEBUG [ServerInfo] java.protocol.handler.pkgs: org.jboss.net.protocol|org.jboss.vfs.protocol
16:46:11,070 DEBUG [ServerInfo] java.rmi.server.RMIClassLoaderSpi: org.jboss.system.JBossRMIClassLoader
16:46:11,070 DEBUG [ServerInfo] java.rmi.server.hostname: 10.90.0.101
16:46:11,071 DEBUG [ServerInfo] java.runtime.name: Java(TM) SE Runtime Environment
16:46:11,071 DEBUG [ServerInfo] java.runtime.version: jvmap3260sr10-20111208
16:46:11,072 DEBUG [ServerInfo] java.specification.name: Java Platform API Specification
16:46:11,072 DEBUG [ServerInfo] java.specification.vendor: Sun Microsystems Inc.
16:46:11,073 DEBUG [ServerInfo] java.specification.version: 1.6
16:46:11,073 DEBUG [ServerInfo] java.util.logging.manager: org.jboss.logmanager.LogManager
16:46:11,074 DEBUG [ServerInfo] java.util.prefs.PreferencesFactory: java.util.prefs.FileSystemPreferencesFactory
16:46:11,074 DEBUG [ServerInfo] java.vendor: IBM Corporation
16:46:11,075 DEBUG [ServerInfo] java.vendor.url: http://www.ibm.com/
16:46:11,075 DEBUG [ServerInfo] java.version: 1.6.0
16:46:11,077 DEBUG [ServerInfo] java.vm.info: JRE 1.6.0 IBM J9 2.4 OS/400 ppc-32 jvmap3260sr10-20111208 (JIT enabled, AOT enabled)
J9VM - 20111207_096808
JIT - r9_20111107_21307ifx1
GC - 20110519_AA
16:46:11,078 DEBUG [ServerInfo] java.vm.name: IBM J9 VM
16:46:11,078 DEBUG [ServerInfo] java.vm.specification.name: Java Virtual Machine Specification
16:46:11,079 DEBUG [ServerInfo] java.vm.specification.vendor: Sun Microsystems Inc.
16:46:11,079 DEBUG [ServerInfo] java.vm.specification.version: 1.0
16:46:11,080 DEBUG [ServerInfo] java.vm.vendor: IBM Corporation
16:46:11,080 DEBUG [ServerInfo] java.vm.version: 2.4
16:46:11,081 DEBUG [ServerInfo] javax.management.builder.initial: org.jboss.mx.server.MBeanServerBuilderImpl
16:46:11,081 DEBUG [ServerInfo] jboss.bind.address: 10.90.0.101
16:46:11,082 DEBUG [ServerInfo] jboss.boot.server.log.dir: /jboss/jboss-6.1.0.Final/server/default/log
16:46:11,082 DEBUG [ServerInfo] jboss.bootstrap.home.url: file:/jboss/jboss-6.1.0.Final/server/default/conf/
16:46:11,083 DEBUG [ServerInfo] jboss.bootstrap.name: bootstrap.xml
16:46:11,083 DEBUG [ServerInfo] jboss.bootstrap.url: file:/jboss/jboss-6.1.0.Final/server/default/conf/bootstrap.xml
16:46:11,084 DEBUG [ServerInfo] jboss.common.base.url: file:/jboss/jboss-6.1.0.Final/common/
16:46:11,084 DEBUG [ServerInfo] jboss.common.lib.url: file:/jboss/jboss-6.1.0.Final/common/lib/
16:46:11,085 DEBUG [ServerInfo] jboss.home: /jboss/jboss-6.1.0.Final
16:46:11,085 DEBUG [ServerInfo] jboss.home.dir: /jboss/jboss-6.1.0.Final
16:46:11,086 DEBUG [ServerInfo] jboss.home.url: file:/jboss/jboss-6.1.0.Final/
16:46:11,086 DEBUG [ServerInfo] jboss.host.name: atstraka
16:46:11,087 DEBUG [ServerInfo] jboss.lib.url: file:/jboss/jboss-6.1.0.Final/lib/
16:46:11,087 DEBUG [ServerInfo] jboss.native.dir: /jboss/jboss-6.1.0.Final/server/default/tmp/native
16:46:11,088 DEBUG [ServerInfo] jboss.native.load: false
16:46:11,088 DEBUG [ServerInfo] jboss.node.name: atstraka
16:46:11,089 DEBUG [ServerInfo] jboss.partition.name: DefaultPartition
16:46:11,089 DEBUG [ServerInfo] jboss.platform.mbeanserver: true
16:46:11,089 DEBUG [ServerInfo] jboss.qualified.host.name: atstraka.straka.local
16:46:11,090 DEBUG [ServerInfo] jboss.server.base.dir: /jboss/jboss-6.1.0.Final/server
16:46:11,090 DEBUG [ServerInfo] jboss.server.base.url: file:/jboss/jboss-6.1.0.Final/server/
16:46:11,091 DEBUG [ServerInfo] jboss.server.config.url: file:/jboss/jboss-6.1.0.Final/server/default/conf/
16:46:11,091 DEBUG [ServerInfo] jboss.server.data.dir: /jboss/jboss-6.1.0.Final/server/default/data
16:46:11,092 DEBUG [ServerInfo] jboss.server.home.dir: /jboss/jboss-6.1.0.Final/server/default
16:46:11,092 DEBUG [ServerInfo] jboss.server.home.url: file:/jboss/jboss-6.1.0.Final/server/default/
16:46:11,093 DEBUG [ServerInfo] jboss.server.lib.url: file:/jboss/jboss-6.1.0.Final/server/default/lib/
16:46:11,093 DEBUG [ServerInfo] jboss.server.log.dir: /jboss/jboss-6.1.0.Final/server/default/log
16:46:11,094 DEBUG [ServerInfo] jboss.server.name: default
16:46:11,094 DEBUG [ServerInfo] jboss.server.temp.dir: /jboss/jboss-6.1.0.Final/server/default/tmp
16:46:11,095 DEBUG [ServerInfo] jboss.vfs.forceCopy: true
16:46:11,095 DEBUG [ServerInfo] jbossmx.loader.repository.class: org.jboss.mx.loading.UnifiedLoaderRepository3
16:46:11,096 DEBUG [ServerInfo] jgroups.bind_addr: 10.90.0.101
16:46:11,096 DEBUG [ServerInfo] jxe.current.romimage.version: 15
16:46:11,097 DEBUG [ServerInfo] jxe.lowest.romimage.version: 15
16:46:11,099 DEBUG [ServerInfo] line.separator:
16:46:11,099 DEBUG [ServerInfo] log4j.defaultInitOverride: true
16:46:11,100 DEBUG [ServerInfo] logging.configuration: file:./logging.properties
16:46:11,100 DEBUG [ServerInfo] org.jboss.deployers.spi.deployer.matchers.NameIgnoreMechanism: org.jboss.deployers.spi.deployer.helpers.DummyNameIgnoreMechanism
16:46:11,101 DEBUG [ServerInfo] org.jboss.logging.Logger.pluginClass: org.jboss.logging.logmanager.LoggerPluginImpl
16:46:11,101 DEBUG [ServerInfo] org.jboss.reflect.spi.TypeInfoFactory: org.jboss.reflect.plugins.introspection.IntrospectionTypeInfoFactory
16:46:11,102 DEBUG [ServerInfo] org.jboss.resolver.warning: true
16:46:11,102 DEBUG [ServerInfo] os.arch: PowerPC
16:46:11,103 DEBUG [ServerInfo] os.encoding: ISO8859-1
16:46:11,103 DEBUG [ServerInfo] os.name: OS/400
16:46:11,103 DEBUG [ServerInfo] os.version: V7R1M0
16:46:11,104 DEBUG [ServerInfo] os400.class.path.security.check: 20
16:46:11,104 DEBUG [ServerInfo] os400.file.encoding.ccsid: 00819
16:46:11,105 DEBUG [ServerInfo] os400.job.file.encoding: Cp273
16:46:11,105 DEBUG [ServerInfo] os400.stdin.allowed: 1
16:46:11,106 DEBUG [ServerInfo] os400.vm.inputargs: -Xms128m -Xmx1536m -Dorg.jboss.resolver.warning=true -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dprogram.name=run.sh -Dlogging.configuration=file:./logging.properties -Djava.library.path=/jboss/jboss-6.1.0.Final/bin/native/lib -Djava.endorsed.dirs=/jboss/jboss-6.1.0.Final//lib/endorsed -Djava.class.path=/jboss/jboss-6.1.0.Final//bin/run.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit//lib/tools.jar
16:46:11,108 DEBUG [ServerInfo] os400dbg.fr.arena_size: 0x32c0820,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,
16:46:11,108 DEBUG [ServerInfo] os400dbg.fr.arena_used: 0x3292000,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,
16:46:11,109 DEBUG [ServerInfo] os400dbg.fr.break: 0x332c0ec0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,
16:46:11,109 DEBUG [ServerInfo] os400dbg.fr.timestamps: Wed Jun 13 16:45:58 2012
,Thu Jan 1 01:00:00 1970
,Thu Jan 1 01:00:00 1970
,Thu Jan 1 01:00:00 1970
,Thu Jan 1 01:00:00 1970
,Thu Jan 1 01:00:00 1970
,Thu Jan 1 01:00:00 1970
,Thu Jan 1 01:00:00 1970
,Thu Jan 1 01:00:00 1970
,Thu Jan 1 01:00:00 1970
,
16:46:11,110 DEBUG [ServerInfo] path.separator: :
16:46:11,110 DEBUG [ServerInfo] program.name: run.sh
16:46:11,111 DEBUG [ServerInfo] sun.arch.data.model: 32
16:46:11,111 DEBUG [ServerInfo] sun.boot.class.path: /jboss/jboss-6.1.0.Final//lib/endorsed/stax-api.jar:/jboss/jboss-6.1.0.Final//lib/endorsed/jbossws-cxf-factories.jar:/jboss/jboss-6.1.0.Final//lib/endorsed/jboss-jaxws-api_2.2_spec.jar:/jboss/jboss-6.1.0.Final//lib/endorsed/jboss-jaxb-api_2.2_spec.jar:/jboss/jboss-6.1.0.Final//lib/endorsed/jboss-annotations-api_1.1_spec.jar:/jboss/jboss-6.1.0.Final//lib/endorsed/activation.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/vm.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/annotation.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/beans.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/java.util.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/jndi.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/logging.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/security.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/sql.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmorb.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmorbapi.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmcfw.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/rt.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/charsets.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/resources.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmpkcs.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmcertpathfw.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmjgssfw.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmjssefw.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmsaslfw.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmjcefw.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmjgssprovider.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmjsseprovider2.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmcertpathprovider.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ibmxmlcrypto.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/management-agent.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/xml.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/jlm.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/javascript.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/IBMmisc.jar:/QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/lib/IBMi5OSJSSE.jar
16:46:11,113 DEBUG [ServerInfo] sun.boot.library.path: /QOpenSys/QIBM/ProdData/JavaVM/jdk60/32bit/jre/lib/ppc
16:46:11,114 DEBUG [ServerInfo] sun.cpu.endian: big
16:46:11,114 DEBUG [ServerInfo] sun.io.unicode.encoding: UnicodeBig
16:46:11,114 DEBUG [ServerInfo] sun.java2d.fontpath:
16:46:11,115 DEBUG [ServerInfo] sun.jnu.encoding: ISO8859-1
16:46:11,116 DEBUG [ServerInfo] sun.rmi.dgc.client.gcInterval: 3600000
16:46:11,117 DEBUG [ServerInfo] sun.rmi.dgc.server.gcInterval: 3600000
16:46:11,117 DEBUG [ServerInfo] user.country: DE
16:46:11,118 DEBUG [ServerInfo] user.dir: /jboss/jboss-6.1.0.Final/bin
16:46:11,118 DEBUG [ServerInfo] user.home: /
16:46:11,119 DEBUG [ServerInfo] user.language: de
16:46:11,119 DEBUG [ServerInfo] user.name: dgr
16:46:11,120 DEBUG [ServerInfo] user.timezone: Europe/Zurich
16:46:11,120 DEBUG [ServerInfo] user.variant:
16:46:11,121 DEBUG [ServerInfo] xb.builder.repeatableParticleHandlers: false
16:46:11,121 DEBUG [ServerInfo] xb.builder.useUnorderedSequence: true
16:46:11,225 INFO [JMXKernel] Legacy JMX core initialized
16:46:41,814 INFO [AbstractServerConfig] JBoss Web Services - Stack CXF Server 3.4.1.GA
16:46:43,323 INFO [JSFImplManagementDeployer] Initialized 3 JSF configurations: [Mojarra-1.2, MyFaces-2.0, Mojarra-2.0]
16:47:26,811 INFO [PersistenceUnitValueMetaData] iDependOn persistence.unit:unitName=jboss-ejb3-timerservice-mk2.jar#timerdb
16:47:27,629 INFO [ResteasyIntegrationDeployer] *** Adding JAX-RS resource classes: com.dgr.profi.rest.LBResource,com.dgr.profi.rest.OffertResource,com.dgr.profi.rest.BelegartResource,com.dgr.profi.rest.PreferenceResource,com.dgr.profi.rest.LieferantResource,com.dgr.profi.rest.FakturaResource,com.dgr.profi.rest.NummerkreisDescriptorResource,com.dgr.profi.rest.KundeResource,com.dgr.profi.rest.RuleSetResource,com.dgr.profi.rest.PreiswarterResource,com.dgr.profi.rest.DatanormResource,com.dgr.profi.rest.RechnungsartResource,com.dgr.profi.rest.WaehrungResource,com.dgr.profi.rest.RabattgruppeResource,com.dgr.profi.rest.AusschreibungResource,com.dgr.profi.rest.LVResource,com.dgr.profi.rest.WarengruppeResource,com.dgr.profi.rest.test.StatusResource,com.dgr.profi.rest.BetriebsstelleResource,com.dgr.profi.rest.ProjektResource,com.dgr.profi.emf.rest.EPackageResource,com.dgr.profi.rest.GenericDocumentResource,com.dgr.profi.rest.LizenzResource,com.dgr.profi.rest.AuftragResource,com.dgr.profi.rest.VersionResource,com.dgr.profi.rest.KalkulationsartResource,com.dgr.profi.rest.StandardResource,com.dgr.profi.rest.SteuerResource,com.dgr.profi.rest.SparteResource,com.dgr.profi.rest.TextBausteinResource,com.dgr.profi.rest.PersonalResource,com.dgr.profi.emf.rest.URNResource,com.dgr.profi.rest.MetallResource,com.dgr.profi.rest.AuftragspositionResource,com.dgr.profi.rest.AuftragsartResource,com.dgr.profi.rest.AufmassResource,com.dgr.profi.rest.KommunikationsartResource,com.dgr.profi.rest.TicketResource,com.dgr.profi.rest.ArtikelResource,com.dgr.profi.rest.jboss.LogResource,com.dgr.profi.rest.search.SearchResource,com.dgr.profi.rest.NummerkreisResource,com.dgr.profi.rest.test.RestTest,com.dgr.profi.rest.EtikettResource
16:47:27,632 INFO [ResteasyIntegrationDeployer] *** Adding JAX-RS provider classes: com.dgr.profi.emf.rest.CollectionProvider,com.dgr.profi.rest.providers.EJBExceptionMapper,com.dgr.profi.rest.providers.ReaderProvider,com.dgr.profi.rest.providers.ServletRequestMessageProvider,com.dgr.profi.rest.providers.ThreadLocalMessageProvider,com.dgr.profi.emf.resteasy.DateConverter,com.dgr.profi.rest.providers.RuntimeExceptionMapper,com.dgr.profi.emf.rest.EObjectProvider,com.dgr.profi.emf.resteasy.ResourceSetInitializerInterceptor,com.dgr.profi.rest.providers.OptimisticLockExceptionMapper,com.dgr.profi.rest.providers.MethodNotAllowedExceptionMapper,com.dgr.profi.emf.rest.ResourceProvider,com.dgr.profi.rest.providers.EntityNotFoundExceptionMapper,com.dgr.profi.emf.resteasy.ReadOnlyInterceptor
16:47:31,586 INFO [SystemPropertiesService] Loaded system properties from: file:/jboss/jboss-6.1.0.Final/server/default/conf/profi.properties
16:47:34,728 WARNUNG [FileConfigurationParser] AIO wasn't located on this platform, it will fall back to using pure Java NIO. If your platform is Linux, install LibAIO to enable the AIO journal
16:47:35,258 INFO [JMXConnector] starting JMXConnector on host 10.90.0.101:21090
16:47:36,082 INFO [MailService] Mail Service bound to java:/Mail
16:47:44,858 INFO [HornetQServerImpl] live server is starting with configuration HornetQ Configuration (clustered=false,backup=false,sharedStore=true,journalDirectory=/jboss/jboss-6.1.0.Final/server/default/data/hornetq/journal,bindingsDirectory=/jboss/jboss-6.1.0.Final/server/default/data/hornetq/bindings,largeMessagesDirectory=/jboss/jboss-6.1.0.Final/server/default/data/hornetq/largemessages,pagingDirectory=/jboss/jboss-6.1.0.Final/server/default/data/hornetq/paging)
16:47:44,861 INFO [HornetQServerImpl] Waiting to obtain live lock
16:47:45,107 INFO [JournalStorageManager] Using NIO Journal
16:47:45,212 WARNUNG [HornetQServerImpl] Security risk! It has been detected that the cluster admin user and password have not been changed from the installation default. Please see the HornetQ user guide, cluster chapter, for instructions on how to do this.
16:47:45,954 INFO [FileLockNodeManager] Waiting to obtain live lock
16:47:45,955 INFO [FileLockNodeManager] Live Server Obtained live lock
16:47:50,879 INFO [NettyAcceptor] Started Netty Acceptor version 3.2.3.Final-r${buildNumber} 10.90.0.101:25455 for CORE protocol
16:47:50,979 INFO [NettyAcceptor] Started Netty Acceptor version 3.2.3.Final-r${buildNumber} 10.90.0.101:25445 for CORE protocol
16:47:51,048 INFO [HornetQServerImpl] Server is now live
16:47:51,049 INFO [HornetQServerImpl] HornetQ Server version 2.2.5.Final (HQ_2_2_5_FINAL_AS7, 121) [967e1817-a59d-11e1-b696-42003c0099c3] started
16:47:51,202 INFO [WebService] Using RMI server codebase: http://10.90.0.101:28083/
16:47:51,949 INFO [jbossatx] ARJUNA-32010 JBossTS Recovery Service (tag: JBOSSTS_4_14_0_Final) - JBoss Inc.
16:47:51,971 INFO [arjuna] ARJUNA-12324 Start RecoveryActivators
16:47:52,157 INFO [arjuna] ARJUNA-12296 ExpiredEntryMonitor running at Mi, 13 Jun 2012 16:47:52
16:47:53,994 INFO [arjuna] ARJUNA-12310 Recovery manager listening on endpoint 10.90.0.101:24712
16:47:54,154 INFO [arjuna] ARJUNA-12344 RecoveryManagerImple is ready on port 24712
16:47:54,155 INFO [jbossatx] ARJUNA-32013 Starting transaction recovery manager
16:47:54,255 INFO [arjuna] ARJUNA-12163 Starting service com.arjuna.ats.arjuna.recovery.ActionStatusService on port 24713
16:47:54,382 INFO [arjuna] ARJUNA-12337 TransactionStatusManagerItem host: 10.90.0.101 port: 24713
16:47:54,409 INFO [arjuna] ARJUNA-12170 TransactionStatusManager started on port 24713 and host 10.90.0.101 with service com.arjuna.ats.arjuna.recovery.ActionStatusService
16:47:54,665 INFO [jbossatx] ARJUNA-32017 JBossTS Transaction Service (JTA version - tag: JBOSSTS_4_14_0_Final) - JBoss Inc.
16:47:55,084 INFO [arjuna] ARJUNA-12202 registering bean jboss.jta:type=ObjectStore.
16:47:56,657 INFO [AprLifecycleListener] The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /jboss/jboss-6.1.0.Final/bin/native/lib
16:47:57,170 INFO [TomcatDeployment] deploy, ctxPath=/invoker
16:47:58,977 INFO [ModClusterService] Initializing mod_cluster 1.1.0.Final
16:47:59,228 INFO [RARDeployment] Required license terms exist, view vfs:/jboss/jboss-6.1.0.Final/server/default/deploy/jboss-local-jdbc.rar/META-INF/ra.xml
16:47:59,273 INFO [RARDeployment] Required license terms exist, view vfs:/jboss/jboss-6.1.0.Final/server/default/deploy/jboss-xa-jdbc.rar/META-INF/ra.xml
16:47:59,390 INFO [RARDeployment] Required license terms exist, view vfs:/jboss/jboss-6.1.0.Final/server/default/deploy/jms-ra.rar/META-INF/ra.xml
16:47:59,459 INFO [HornetQResourceAdapter] HornetQ resource adaptor started
16:47:59,515 INFO [RARDeployment] Required license terms exist, view vfs:/jboss/jboss-6.1.0.Final/server/default/deploy/mail-ra.rar/META-INF/ra.xml
16:47:59,676 INFO [RARDeployment] Required license terms exist, view vfs:/jboss/jboss-6.1.0.Final/server/default/deploy/quartz-ra.rar/META-INF/ra.xml
16:48:00,223 INFO [SimpleThreadPool] Job execution threads will use class loader of thread: Thread-7
16:48:01,099 INFO [SchedulerSignalerImpl] Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
16:48:01,099 INFO [QuartzScheduler] Quartz Scheduler v.1.8.3 created.
16:48:01,104 INFO [RAMJobStore] RAMJobStore initialized.
16:48:01,106 INFO [QuartzScheduler] Scheduler meta-data: Quartz Scheduler (v1.8.3) 'JBossQuartzScheduler' with instanceId 'NON_CLUSTERED'
Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
NOT STARTED.
Currently in standby mode.
Number of jobs executed: 0
Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.
16:48:01,115 INFO [StdSchedulerFactory] Quartz scheduler 'JBossQuartzScheduler' initialized from an externally opened InputStream.
16:48:01,115 INFO [StdSchedulerFactory] Quartz scheduler version: 1.8.3
16:48:01,115 INFO [QuartzScheduler] Scheduler JBossQuartzScheduler_$_NON_CLUSTERED started.
16:48:08,779 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=DefaultDS' to JNDI name 'java:DefaultDS'
16:48:10,085 INFO [PersistenceUnitDeployment] Starting persistence unit persistence.unit:unitName=jboss-ejb3-timerservice-mk2.jar#timerdb
16:48:12,642 INFO [Version] Hibernate Commons Annotations 3.2.0.Final
16:48:12,693 INFO [Environment] Hibernate 3.6.6.Final
16:48:12,776 INFO [Environment] hibernate.properties not found
16:48:12,790 INFO [Environment] Bytecode provider name : javassist
16:48:12,808 INFO [Environment] using JDK 1.4 java.sql.Timestamp handling
16:48:13,198 INFO [Version] Hibernate EntityManager 3.6.6.Final
16:48:13,333 INFO [Ejb3Configuration] Processing PersistenceUnitInfo [
name: timerdb
...]
16:48:14,136 WARN [Ejb3Configuration] Persistence provider caller does not implement the EJB3 spec correctly.PersistenceUnitInfo.getNewTempClassLoader() is null.
16:48:14,705 INFO [AnnotationBinder] Binding entity from annotated class: org.jboss.ejb3.timerservice.mk2.persistence.TimerEntity
16:48:15,306 INFO [EntityBinder] Bind entity org.jboss.ejb3.timerservice.mk2.persistence.TimerEntity on table timer
16:48:15,515 INFO [AnnotationBinder] Binding entity from annotated class: org.jboss.ejb3.timerservice.mk2.persistence.CalendarTimerEntity
16:48:15,518 INFO [EntityBinder] Bind entity org.jboss.ejb3.timerservice.mk2.persistence.CalendarTimerEntity on table calendar_timer
16:48:15,660 INFO [AnnotationBinder] Binding entity from annotated class: org.jboss.ejb3.timerservice.mk2.persistence.TimeoutMethod
16:48:15,666 INFO [EntityBinder] Bind entity org.jboss.ejb3.timerservice.mk2.persistence.TimeoutMethod on table timeout_method
16:48:15,932 INFO [Version] Hibernate Validator 3.1.0.GA
16:48:17,370 INFO [Version] Hibernate Validator 4.1.0.Final
16:48:17,403 INFO [DefaultTraversableResolver] Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver.
16:48:20,616 INFO [DefaultTraversableResolver] Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver.
16:48:20,625 INFO [DefaultTraversableResolver] Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver.
16:48:20,643 INFO [HibernateSearchEventListenerRegister] Unable to find org.hibernate.search.event.FullTextIndexEventListener on the classpath. Hibernate Search is not enabled.
16:48:20,663 INFO [ConnectionProviderFactory] Initializing connection provider: org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider
16:48:20,722 INFO [InjectedDataSourceConnectionProvider] Using provided datasource
16:48:20,977 INFO [Dialect] Using dialect: org.hibernate.dialect.HSQLDialect
16:48:21,013 INFO [JdbcSupportLoader] Disabling contextual LOB creation as JDBC driver reported JDBC version [3] less than 4
16:48:21,014 INFO [SettingsFactory] Database ->
name : HSQL Database Engine
version : 1.8.0
major : 1
minor : 8
16:48:21,014 INFO [SettingsFactory] Driver ->
name : HSQL Database Engine Driver
version : 1.8.0
major : 1
minor : 8
16:48:21,024 INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.ejb.transaction.JoinableCMTTransactionFactory
16:48:21,036 INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup
16:48:21,041 INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup
16:48:21,041 INFO [SettingsFactory] Automatic flush during beforeCompletion(): disabled
16:48:21,042 INFO [SettingsFactory] Automatic session close at end of transaction: disabled
16:48:21,042 INFO [SettingsFactory] JDBC batch size: 15
16:48:21,042 INFO [SettingsFactory] JDBC batch updates for versioned data: disabled
16:48:21,044 INFO [SettingsFactory] Scrollable result sets: enabled
16:48:21,044 INFO [SettingsFactory] JDBC3 getGeneratedKeys(): disabled
16:48:21,044 INFO [SettingsFactory] Connection release mode: auto
16:48:21,045 INFO [SettingsFactory] Default batch fetch size: 1
16:48:21,046 INFO [SettingsFactory] Generate SQL with comments: disabled
16:48:21,046 INFO [SettingsFactory] Order SQL updates by primary key: disabled
16:48:21,046 INFO [SettingsFactory] Order SQL inserts for batching: disabled
16:48:21,046 INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
16:48:21,052 INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
16:48:21,053 INFO [SettingsFactory] Query language substitutions: {}
16:48:21,053 INFO [SettingsFactory] JPA-QL strict compliance: enabled
16:48:21,053 INFO [SettingsFactory] Second-level cache: enabled
16:48:21,053 INFO [SettingsFactory] Query cache: disabled
16:48:21,055 INFO [SettingsFactory] Cache region factory : org.hibernate.cache.impl.bridge.RegionFactoryCacheProviderBridge
16:48:21,074 INFO [RegionFactoryCacheProviderBridge] Cache provider: org.hibernate.cache.HashtableCacheProvider
16:48:21,077 INFO [SettingsFactory] Optimize cache for minimal puts: disabled
16:48:21,077 INFO [SettingsFactory] Cache region prefix: persistence.unit:unitName=jboss-ejb3-timerservice-mk2.jar#timerdb
16:48:21,078 INFO [SettingsFactory] Structured second-level cache entries: disabled
16:48:21,092 INFO [SettingsFactory] Statistics: disabled
16:48:21,092 INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled
16:48:21,093 INFO [SettingsFactory] Default entity-mode: pojo
16:48:21,093 INFO [SettingsFactory] Named query checking : enabled
16:48:21,093 INFO [SettingsFactory] Check Nullability in Core (should be disabled when Bean Validation is on): disabled
16:48:21,223 INFO [SessionFactoryImpl] building session factory
16:48:21,243 INFO [BasicTypeRegistry] Type registration [materialized_blob] overrides previous : org.hibernate.type.MaterializedBlobType@602a602a
16:48:21,243 INFO [BasicTypeRegistry] Type registration [clob] overrides previous : org.hibernate.type.ClobType@436c436c
16:48:21,243 INFO [BasicTypeRegistry] Type registration [java.sql.Clob] overrides previous : org.hibernate.type.ClobType@436c436c
16:48:21,244 INFO [BasicTypeRegistry] Type registration [materialized_clob] overrides previous : org.hibernate.type.MaterializedClobType@26c226c2
16:48:21,244 INFO [BasicTypeRegistry] Type registration [wrapper_materialized_blob] overrides previous : org.hibernate.type.WrappedMaterializedBlobType@29062906
16:48:21,244 INFO [BasicTypeRegistry] Type registration [characters_clob] overrides previous : org.hibernate.type.PrimitiveCharacterArrayClobType@3e1e3e1e
16:48:21,244 INFO [BasicTypeRegistry] Type registration [wrapper_characters_clob] overrides previous : org.hibernate.type.CharacterArrayClobType@6a0c6a0c
16:48:21,245 INFO [BasicTypeRegistry] Type registration [blob] overrides previous : org.hibernate.type.BlobType@135e135e
16:48:21,245 INFO [BasicTypeRegistry] Type registration [java.sql.Blob] overrides previous : org.hibernate.type.BlobType@135e135e
16:48:22,049 INFO [SessionFactoryObjectFactory] Factory name: persistence.unit:unitName=jboss-ejb3-timerservice-mk2.jar#timerdb
16:48:22,052 INFO [NamingHelper] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
16:48:22,126 INFO [SessionFactoryObjectFactory] Bound factory to JNDI name: persistence.unit:unitName=jboss-ejb3-timerservice-mk2.jar#timerdb
16:48:22,174 INFO [SchemaUpdate] Running hbm2ddl schema update
16:48:22,174 INFO [SchemaUpdate] fetching database metadata
16:48:22,179 INFO [SchemaUpdate] updating schema
16:48:22,183 INFO [DefaultTraversableResolver] Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver.
16:48:22,264 INFO [TableMetadata] table found: PUBLIC.TIMEOUTMETHOD_METHODPARAMS
16:48:22,264 INFO [TableMetadata] columns: [methodparams, timeoutmethod_id]
16:48:22,264 INFO [TableMetadata] foreign keys: [fkf294c964b7de2d8a]
16:48:22,264 INFO [TableMetadata] indexes: [sys_idx_55]
16:48:22,299 INFO [TableMetadata] table found: PUBLIC.CALENDAR_TIMER
16:48:22,299 INFO [TableMetadata] columns: [scheduleexprminute, scheduleexprsecond, scheduleexprstartdate, scheduleexprtimezone, scheduleexpryear, scheduleexprhour, scheduleexprmonth, autotimer, timeoutmethod_id, scheduleexprdayofmonth, scheduleexprdayofweek, id, scheduleexprenddate]
16:48:22,300 INFO [TableMetadata] foreign keys: [fk2b697f04e6e6ef93, fk2b697f04b7de2d8a]
16:48:22,300 INFO [TableMetadata] indexes: [sys_idx_57, sys_idx_59, sys_idx_48]
16:48:22,329 INFO [TableMetadata] table found: PUBLIC.TIMEOUT_METHOD
16:48:22,329 INFO [TableMetadata] columns: [declaringclass, id, methodname]
16:48:22,329 INFO [TableMetadata] foreign keys: []
16:48:22,330 INFO [TableMetadata] indexes: [sys_idx_50]
16:48:22,358 INFO [TableMetadata] table found: PUBLIC.TIMER
16:48:22,359 INFO [TableMetadata] columns: [repeatinterval, timedobjectid, nextdate, initialdate, previousrun, id, timerstate, info]
16:48:22,359 INFO [TableMetadata] foreign keys: []
16:48:22,359 INFO [TableMetadata] indexes: [sys_idx_52]
16:48:22,369 INFO [SchemaUpdate] schema update complete
16:48:22,377 INFO [NamingHelper] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
16:48:23,170 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name=JmsXA' to JNDI name 'java:JmsXA'
16:48:23,274 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=jdbc/profiDB' to JNDI name 'java:jdbc/profiDB'
16:48:24,071 INFO [xnio] XNIO Version 2.1.0.CR2
16:48:24,216 INFO [nio] XNIO NIO Implementation Version 2.1.0.CR2
16:48:24,277 WARN [nio] The currently defined selector provider class (sun.nio.ch.PollSelectorProvider) is not supported for use with XNIO
16:48:25,435 INFO [remoting] JBoss Remoting version 3.1.0.Beta2