run JBoss 6.0.0 M3 with -Xdebug
hello...
we use to run our application (let's call it) 'APP' (~900 Stateless Session Beans, ~600 Entities) with JBoss 4.2.2.GA.
these days i'm validating JBoss 6.0.0 M3. i also tried JBoss 5.x some months ago, but performance (especially boot time including deployment) was very bad. with JBoss 6.0.0 M3 boot time of JBoss improved in comparison to JBoss 5.x, but still is "slow" when compared with JBoss 4.x.
to prove my assumption i compared the time JBoss needs to start (with and without APP deployed). in addition i (de)activated remote socket debugging (in run.conf.bat). you may find the measurements in the following table. btw, i did not measure the duration, its the time that JBoss tells me through the server.log (INFO [...] JBossAS [version] Started in [mm:ss:SSS]:
| JBoss | APP | -Xdebug | boot time (s) | boot time (m) |
|---|---|---|---|---|
| 4.2.2.GA | - | - | 9 | 0,15 |
| 4.2.2.GA | x | x | 67 | 1,12 |
| 5.1.0.GA | - | - | 29 | 0,48 |
| 5.1.0.GA | x | - | 273 | 4,55 |
| 5.1.0.GA | x | x | 533 | 8,88 |
| 6.0.0.M3 | - | - | 15 | 0,25 |
| 6.0.0.M3 | x | - | 132 | 2,20 |
| 6.0.0.M3 | x | x | 489 | 8,15 |
i notice that JBoss 6.x improved over JBoss 5.x. well done.
but i recognize, too, that running JBoss 6.0.0.M3 in debug mode is just impractical!!
we use debug mode for development reasons, of course. so (re)deployment MUST NOT take ~10 minutes.
the question is: why does debug mode slows down JBoss boot time this much??
feel free to have a look at boot.log attached.
it seems to me, that JBoss enjoys some nap in debug mode :- /
11:59:54,038 INFO [AbstractJBossASServerBase] Server Configuration:
JBOSS_HOME URL: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/
Bootstrap: $JBOSS_HOME\server/APP/conf/bootstrap.xml
Common Base: $JBOSS_HOME\common/
Common Library: $JBOSS_HOME\common/lib/
Server Name: APP
Server Base: $JBOSS_HOME\server/
Server Library: $JBOSS_HOME\server/APP/lib/
Server Config: $JBOSS_HOME\server/APP/conf/
Server Home: $JBOSS_HOME\server/APP/
Server Data: $JBOSS_HOME\server/APP/data/
Server Log: $JBOSS_HOME\server/APP/log/
Server Temp: $JBOSS_HOME\server/APP/tmp/
11:59:54,044 INFO [AbstractServer] Starting: JBossAS [6.0.0.20100429-M3 "Neo"]
11:59:55,552 INFO [ServerInfo] Java version: 1.6.0_20,Sun Microsystems Inc.
11:59:55,553 INFO [ServerInfo] Java Runtime: Java(TM) SE Runtime Environment (build 1.6.0_20-b02)
11:59:55,554 INFO [ServerInfo] Java VM: Java HotSpot(TM) 64-Bit Server VM 16.3-b01,Sun Microsystems Inc.
11:59:55,554 INFO [ServerInfo] OS-System: Windows Vista 6.0,amd64
11:59:55,555 INFO [ServerInfo] VM arguments: -Dprogram.name=run.bat -Xms512M -Xmx1536M -XX:MaxPermSize=512M -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dorg.jboss.resolver.warning=true -Djava.net.preferIPv4Stack=true -Xdebug -Xrunjdwp:transport=dt_socket,address=7099,server=y,suspend=n -Djava.endorsed.dirs=D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\lib\endorsed
11:59:55,557 DEBUG [ServerInfo] Full System Properties Dump
11:59:55,558 DEBUG [ServerInfo] awt.toolkit: sun.awt.windows.WToolkit
11:59:55,558 DEBUG [ServerInfo] bind.address: 192.168.1.123
11:59:55,560 DEBUG [ServerInfo] file.encoding: Cp1252
11:59:55,561 DEBUG [ServerInfo] file.encoding.pkg: sun.io
11:59:55,561 DEBUG [ServerInfo] file.separator: \
11:59:55,561 DEBUG [ServerInfo] java.awt.graphicsenv: sun.awt.Win32GraphicsEnvironment
11:59:55,561 DEBUG [ServerInfo] java.awt.printerjob: sun.awt.windows.WPrinterJob
11:59:55,561 DEBUG [ServerInfo] java.class.path: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\bin\run.jar
11:59:55,561 DEBUG [ServerInfo] java.class.version: 50.0
11:59:55,561 DEBUG [ServerInfo] java.endorsed.dirs: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\lib\endorsed
11:59:55,562 DEBUG [ServerInfo] java.ext.dirs: C:\Java\64bit\jre6\lib\ext;C:\Windows\Sun\Java\lib\ext
11:59:55,562 DEBUG [ServerInfo] java.home: C:\Java\64bit\jre6
11:59:55,562 DEBUG [ServerInfo] java.io.tmpdir: C:\Users\USERNAME\AppData\Local\Temp\
11:59:55,562 DEBUG [ServerInfo] java.library.path: C:\Java\64bit\jre6\bin;.;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Program Files (x86)\Microsoft SQL Server\80\Tools\Binn\;C:\Program Files\Microsoft SQL Server\90\Tools\binn\;C:\Program Files (x86)\Microsoft SQL Server\90\Tools\binn\;C:\Program Files (x86)\Microsoft SQL Server\90\DTS\Binn\;C:\Program Files (x86)\Microsoft SQL Server\90\Tools\Binn\VSShell\Common7\IDE\;C:\Program Files\Microsoft SQL Server\90\DTS\Binn\;C:\Program Files (x86)\Lotus\Notes\jvm\bin;C:\Program Files (x86)\Lotus\Notes;C:\Program Files (x86)\Microsoft SQL Server\100\Tools\Binn\;C:\Program Files\Microsoft SQL Server\100\Tools\Binn\;C:\Program Files\Microsoft SQL Server\100\DTS\Binn\;C:\Program Files (x86)\Microsoft SQL Server\100\Tools\Binn\VSShell\Common7\IDE\;C:\Program Files (x86)\Microsoft SQL Server\100\DTS\Binn\;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Java\64bit\jdk1.6.0_20\bin
11:59:55,562 DEBUG [ServerInfo] java.net.preferIPv4Stack: true
11:59:55,563 DEBUG [ServerInfo] java.protocol.handler.pkgs: org.jboss.net.protocol|org.jboss.vfs.protocol
11:59:55,563 DEBUG [ServerInfo] java.rmi.server.RMIClassLoaderSpi: org.jboss.system.JBossRMIClassLoader
11:59:55,563 DEBUG [ServerInfo] java.rmi.server.hostname: 192.168.1.123
11:59:55,563 DEBUG [ServerInfo] java.runtime.name: Java(TM) SE Runtime Environment
11:59:55,563 DEBUG [ServerInfo] java.runtime.version: 1.6.0_20-b02
11:59:55,563 DEBUG [ServerInfo] java.specification.name: Java Platform API Specification
11:59:55,563 DEBUG [ServerInfo] java.specification.vendor: Sun Microsystems Inc.
11:59:55,564 DEBUG [ServerInfo] java.specification.version: 1.6
11:59:55,564 DEBUG [ServerInfo] java.util.logging.manager: org.jboss.logmanager.LogManager
11:59:55,564 DEBUG [ServerInfo] java.vendor: Sun Microsystems Inc.
11:59:55,564 DEBUG [ServerInfo] java.vendor.url: http://java.sun.com/
11:59:55,564 DEBUG [ServerInfo] java.vendor.url.bug: http://java.sun.com/cgi-bin/bugreport.cgi
11:59:55,564 DEBUG [ServerInfo] java.version: 1.6.0_20
11:59:55,564 DEBUG [ServerInfo] java.vm.info: mixed mode
11:59:55,565 DEBUG [ServerInfo] java.vm.name: Java HotSpot(TM) 64-Bit Server VM
11:59:55,565 DEBUG [ServerInfo] java.vm.specification.name: Java Virtual Machine Specification
11:59:55,565 DEBUG [ServerInfo] java.vm.specification.vendor: Sun Microsystems Inc.
11:59:55,565 DEBUG [ServerInfo] java.vm.specification.version: 1.0
11:59:55,565 DEBUG [ServerInfo] java.vm.vendor: Sun Microsystems Inc.
11:59:55,565 DEBUG [ServerInfo] java.vm.version: 16.3-b01
11:59:55,565 DEBUG [ServerInfo] javax.management.builder.initial: org.jboss.mx.server.MBeanServerBuilderImpl
11:59:55,566 DEBUG [ServerInfo] jboss.bind.address: 192.168.1.123
11:59:55,566 DEBUG [ServerInfo] jboss.boot.server.log.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\server\APP\log
11:59:55,566 DEBUG [ServerInfo] jboss.bootstrap.home.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/conf/
11:59:55,566 DEBUG [ServerInfo] jboss.bootstrap.name: bootstrap.xml
11:59:55,566 DEBUG [ServerInfo] jboss.bootstrap.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/conf/bootstrap.xml
11:59:55,566 DEBUG [ServerInfo] jboss.common.base.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/common/
11:59:55,566 DEBUG [ServerInfo] jboss.common.lib.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/common/lib/
11:59:55,567 DEBUG [ServerInfo] jboss.home: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3
11:59:55,567 DEBUG [ServerInfo] jboss.home.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3
11:59:55,567 DEBUG [ServerInfo] jboss.home.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/
11:59:55,567 DEBUG [ServerInfo] jboss.host.name: USERNAME-pc-XYZ
11:59:55,567 DEBUG [ServerInfo] jboss.lib.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/lib/
11:59:55,567 DEBUG [ServerInfo] jboss.native.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\server\APP\tmp\native
11:59:55,568 DEBUG [ServerInfo] jboss.native.load: false
11:59:55,568 DEBUG [ServerInfo] jboss.node.name: USERNAME-pc-XYZ
11:59:55,568 DEBUG [ServerInfo] jboss.partition.name: DefaultPartition
11:59:55,568 DEBUG [ServerInfo] jboss.platform.mbeanserver: true
11:59:55,568 DEBUG [ServerInfo] jboss.qualified.host.name: USERNAME-pc-XYZ
11:59:55,568 DEBUG [ServerInfo] jboss.server.base.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\server
11:59:55,568 DEBUG [ServerInfo] jboss.server.base.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/
11:59:55,569 DEBUG [ServerInfo] jboss.server.config.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/conf/
11:59:55,569 DEBUG [ServerInfo] jboss.server.data.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\server\APP\data
11:59:55,569 DEBUG [ServerInfo] jboss.server.home.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\server\APP
11:59:55,569 DEBUG [ServerInfo] jboss.server.home.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/
11:59:55,569 DEBUG [ServerInfo] jboss.server.lib.url: file:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/lib/
11:59:55,569 DEBUG [ServerInfo] jboss.server.log.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\server\APP\log
11:59:55,569 DEBUG [ServerInfo] jboss.server.name: APP
11:59:55,570 DEBUG [ServerInfo] jboss.server.temp.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\server\APP\tmp
11:59:55,570 DEBUG [ServerInfo] jboss.vfs.forceCopy: true
11:59:55,570 DEBUG [ServerInfo] jbossmx.loader.repository.class: org.jboss.mx.loading.UnifiedLoaderRepository3
11:59:55,570 DEBUG [ServerInfo] jgroups.bind_addr: 192.168.1.123
11:59:55,570 DEBUG [ServerInfo] line.separator:
11:59:55,570 DEBUG [ServerInfo] log4j.defaultInitOverride: true
11:59:55,570 DEBUG [ServerInfo] org.jboss.logging.Logger.pluginClass: org.jboss.logging.logmanager.LoggerPluginImpl
11:59:55,571 DEBUG [ServerInfo] org.jboss.resolver.warning: true
11:59:55,571 DEBUG [ServerInfo] os.arch: amd64
11:59:55,571 DEBUG [ServerInfo] os.name: Windows Vista
11:59:55,571 DEBUG [ServerInfo] os.version: 6.0
11:59:55,571 DEBUG [ServerInfo] path.separator: ;
11:59:55,571 DEBUG [ServerInfo] program.name: run.bat
11:59:55,571 DEBUG [ServerInfo] sun.arch.data.model: 64
11:59:55,571 DEBUG [ServerInfo] sun.boot.class.path: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\lib\endorsed\activation.jar;D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\lib\endorsed\jaxb-api.jar;D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\lib\endorsed\jaxws-api.jar;D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\lib\endorsed\jbossws-native-factories.jar;D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3\lib\endorsed\stax-api.jar;C:\Java\64bit\jre6\lib\resources.jar;C:\Java\64bit\jre6\lib\rt.jar;C:\Java\64bit\jre6\lib\sunrsasign.jar;C:\Java\64bit\jre6\lib\jsse.jar;C:\Java\64bit\jre6\lib\jce.jar;C:\Java\64bit\jre6\lib\charsets.jar;C:\Java\64bit\jre6\classes
11:59:55,572 DEBUG [ServerInfo] sun.boot.library.path: C:\Java\64bit\jre6\bin
11:59:55,572 DEBUG [ServerInfo] sun.cpu.endian: little
11:59:55,572 DEBUG [ServerInfo] sun.cpu.isalist: amd64
11:59:55,572 DEBUG [ServerInfo] sun.desktop: windows
11:59:55,572 DEBUG [ServerInfo] sun.io.unicode.encoding: UnicodeLittle
11:59:55,573 DEBUG [ServerInfo] sun.java.launcher: SUN_STANDARD
11:59:55,573 DEBUG [ServerInfo] sun.jnu.encoding: Cp1252
11:59:55,573 DEBUG [ServerInfo] sun.management.compiler: HotSpot 64-Bit Server Compiler
11:59:55,573 DEBUG [ServerInfo] sun.os.patch.level: Service Pack 2
11:59:55,573 DEBUG [ServerInfo] sun.rmi.dgc.client.gcInterval: 3600000
11:59:55,573 DEBUG [ServerInfo] sun.rmi.dgc.server.gcInterval: 3600000
11:59:55,573 DEBUG [ServerInfo] user.country: DE
11:59:55,574 DEBUG [ServerInfo] user.dir: D:\USERNAME\JBoss\jboss-6.0.0.20100429-M3
11:59:55,574 DEBUG [ServerInfo] user.home: C:\Users\USERNAME
11:59:55,574 DEBUG [ServerInfo] user.language: de
11:59:55,574 DEBUG [ServerInfo] user.name: USERNAME
11:59:55,574 DEBUG [ServerInfo] user.timezone: Europe/Berlin
11:59:55,574 DEBUG [ServerInfo] user.variant:
11:59:55,574 DEBUG [ServerInfo] xb.builder.repeatableParticleHandlers: false
11:59:55,575 DEBUG [ServerInfo] xb.builder.useUnorderedSequence: true
11:59:55,597 INFO [JMXKernel] Legacy JMX core initialized
12:00:00,359 INFO [AbstractServerConfig] JBoss Web Services - Native Server 3.3.0.CR1.SP2
12:00:07,657 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
***** [n-times 'Encountered deployment' like] *****
12:00:21,155 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@80183631{vfs:///D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/deploy/APP.ear/TheFirstEJB3Module.jar/}
12:00:21,288 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@1319106496{vfs:///D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/deploy/APP.ear/TheLastEJB3Module.jar/}
***** [/'Encountered deployment'] *****
12:00:22,753 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
12:00:22,938 INFO [JMXConnector] starting JMXConnector on host 192.168.1.123:1090
12:00:23,797 INFO [MailService] Mail Service bound to java:/Mail
12:00:24,610 INFO [HornetQServerImpl] live server is starting..
12:00:24,687 INFO [JournalStorageManager] Using NIO Journal
12:00:24,708 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.
12:00:26,097 INFO [NettyAcceptor] Started Netty Acceptor version 3.2.0.BETA1-r2215 192.168.1.123:5455
12:00:26,098 INFO [NettyAcceptor] Started Netty Acceptor version 3.2.0.BETA1-r2215 192.168.1.123:5445
12:00:26,102 INFO [HornetQServerImpl] HornetQ Server version 2.1.0.BETA3 (Hungry Hornet, 117) started
12:00:26,180 INFO [WebService] Using RMI server codebase: http://192.168.1.123:8083/
12:00:26,934 INFO [AprLifecycleListener] The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Java\64bit\jre6\bin;.;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Program Files (x86)\Microsoft SQL Server\80\Tools\Binn\;C:\Program Files\Microsoft SQL Server\90\Tools\binn\;C:\Program Files (x86)\Microsoft SQL Server\90\Tools\binn\;C:\Program Files (x86)\Microsoft SQL Server\90\DTS\Binn\;C:\Program Files (x86)\Microsoft SQL Server\90\Tools\Binn\VSShell\Common7\IDE\;C:\Program Files\Microsoft SQL Server\90\DTS\Binn\;C:\Program Files (x86)\Lotus\Notes\jvm\bin;C:\Program Files (x86)\Lotus\Notes;C:\Program Files (x86)\Microsoft SQL Server\100\Tools\Binn\;C:\Program Files\Microsoft SQL Server\100\Tools\Binn\;C:\Program Files\Microsoft SQL Server\100\DTS\Binn\;C:\Program Files (x86)\Microsoft SQL Server\100\Tools\Binn\VSShell\Common7\IDE\;C:\Program Files (x86)\Microsoft SQL Server\100\DTS\Binn\;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Java\64bit\jdk1.6.0_20\bin
12:00:27,080 INFO [TomcatDeployment] deploy, ctxPath=/invoker
12:00:27,766 INFO [RARDeployment] Required license terms exist, view vfs:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/deploy/jboss-local-jdbc.rar/META-INF/ra.xml
12:00:27,777 INFO [RARDeployment] Required license terms exist, view vfs:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/deploy/jboss-xa-jdbc.rar/META-INF/ra.xml
12:00:27,784 INFO [RARDeployment] Required license terms exist, view vfs:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/deploy/jms-ra.rar/META-INF/ra.xml
12:00:27,800 INFO [HornetQResourceAdapter] HornetQ resource adaptor started
12:00:27,806 INFO [RARDeployment] Required license terms exist, view vfs:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/deploy/mail-ra.rar/META-INF/ra.xml
12:00:27,816 INFO [RARDeployment] Required license terms exist, view vfs:/D:/USERNAME/JBoss/jboss-6.0.0.20100429-M3/server/APP/deploy/quartz-ra.rar/META-INF/ra.xml
12:00:27,889 INFO [SimpleThreadPool] Job execution threads will use class loader of thread: Thread-2
12:00:27,919 INFO [SchedulerSignalerImpl] Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
12:00:27,920 INFO [QuartzScheduler] Quartz Scheduler v.1.7.3 created.
12:00:27,921 DEBUG [UpdateChecker] Checking for update...
12:00:27,923 INFO [RAMJobStore] RAMJobStore initialized.
12:00:27,923 INFO [StdSchedulerFactory] Quartz scheduler 'DefaultQuartzScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
12:00:27,924 INFO [StdSchedulerFactory] Quartz scheduler version: 1.7.3
12:00:27,925 INFO [QuartzScheduler] Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED started.
12:00:28,052 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=APPDB' to JNDI name 'java:APPDB'
12:00:28,085 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=APPDBNoTx' to JNDI name 'java:APPDBNoTx'
12:00:28,406 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=DefaultDS' to JNDI name 'java:DefaultDS'
12:00:28,644 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name=JmsXA' to JNDI name 'java:JmsXA'
12:00:28,684 INFO [xnio] XNIO Version 2.1.0.CR2
12:00:28,688 INFO [nio] XNIO NIO Implementation Version 2.1.0.CR2
12:00:28,745 INFO [UpdateChecker] New update(s) found: 1.8.0 [http://www.terracotta.org/kit/reflector?kitID=default&pageID=QuartzChangeLog]
12:00:28,843 INFO [remoting] JBoss Remoting version 3.1.0.Beta2
12:00:28,935 INFO [TomcatDeployment] deploy, ctxPath=/APPHttpConnector
12:00:28,994 INFO [TomcatDeployment] deploy, ctxPath=/APPWebStart
12:00:29,036 INFO [TomcatDeployment] deploy, ctxPath=/
***** [n-times 'Created KernelDeployment' like] *****
12:00:29,670 INFO [JBossASKernel] Created KernelDeployment for: TheFirstEJB3Module.jar
12:00:49,178 WARN [InterceptorInfoRepository] EJBTHREE-1852: InterceptorInfoRepository is deprecated
12:00:49,223 WARN [EJBRemoteHandler] EJBTHREE-1828: EJBInjectionContainer jboss.j2ee:ear=APP.ear,jar=AnEJB3Module.jar,name=AStatelessSession,service=EJB3 is unconfigured, using legacy resolve
12:00:49,231 INFO [JBossASKernel] Created KernelDeployment for: TheLastEJB3Module.jar
***** [/'Created KernelDeployment'] *****
***** [n-times 'STARTED EJB' like] *****
12:00:50,354 INFO [SessionSpecContainer] Starting jboss.j2ee:ear=APP.ear,jar=TheFirstEJB3Module.jar,name=AStatelessSession,service=EJB3
12:00:50,365 INFO [EJBContainer] STARTED EJB: app.package.AStatelessSessionBean ejbName: AStatelessSession
12:00:50,470 INFO [JndiSessionRegistrarBase] Binding the following Entries in Global JNDI:
app/package/AStatelessSession - EJB3.x Default Local Business Interface
APP/AStatelessSession/local-app.package.AStatelessSession - EJB3.x Local Business Interface
***** [/'STARTED EJB'] *****
12:01:01,203 INFO [PersistenceUnitDeployment] Starting persistence unit persistence.unit:unitName=APP.ear/EJB3Persistence.jar#app.persistence.unit
12:01:10,514 INFO [Version] Hibernate Annotations 3.5.0-CR-1
12:01:10,542 INFO [Environment] Hibernate 3.5.0-CR-1
12:01:10,545 INFO [Environment] hibernate.properties not found
12:01:10,550 INFO [Environment] Bytecode provider name : javassist
12:01:10,558 INFO [Environment] using JDK 1.4 java.sql.Timestamp handling
12:01:10,748 INFO [Version] Hibernate Commons Annotations 3.2.0-SNAPSHOT
12:01:10,763 INFO [Version] Hibernate EntityManager 3.5.0-CR-1
12:01:10,806 INFO [Ejb3Configuration] Processing PersistenceUnitInfo [
name: app.persistence.unit
...]
12:01:15,134 WARN [Ejb3Configuration] Persistence provider caller does not implement the EJB3 spec correctly. PersistenceUnitInfo.getNewTempClassLoader() is null.
12:01:18,370 INFO [Version] Hibernate Validator 3.1.0.GA
12:01:19,115 INFO [Version] Hibernate Validator 4.0.2.GA
12:01:19,142 INFO [DefaultTraversableResolver] Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver.
12:01:20,317 INFO [DefaultTraversableResolver] Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver.
12:01:20,327 INFO [HibernateSearchEventListenerRegister] Unable to find org.hibernate.search.event.FullTextIndexEventListener on the classpath. Hibernate Search is not enabled.
12:01:20,956 INFO [DefaultTraversableResolver] Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver.
12:01:22,626 INFO [ConnectionProviderFactory] Initializing connection provider: org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider
12:01:22,634 INFO [InjectedDataSourceConnectionProvider] Using provided datasource
12:01:23,260 INFO [SettingsFactory] RDBMS: Microsoft SQL Server, version: 9.00.4053
12:01:23,261 INFO [SettingsFactory] JDBC driver: Microsoft SQL Server JDBC Driver 2.0, version: 2.0.1803.100
12:01:23,312 INFO [Dialect] Using dialect: org.hibernate.dialect.SQLServerDialect
12:01:23,340 INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.ejb.transaction.JoinableCMTTransactionFactory
12:01:23,345 INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup
12:01:23,349 INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup
12:01:23,349 INFO [SettingsFactory] Automatic flush during beforeCompletion(): disabled
12:01:23,350 INFO [SettingsFactory] Automatic session close at end of transaction: disabled
12:01:23,351 INFO [SettingsFactory] Scrollable result sets: enabled
12:01:23,352 INFO [SettingsFactory] JDBC3 getGeneratedKeys(): enabled
12:01:23,352 INFO [SettingsFactory] Connection release mode: auto
12:01:23,354 INFO [SettingsFactory] Default batch fetch size: 1
12:01:23,355 INFO [SettingsFactory] Generate SQL with comments: disabled
12:01:23,355 INFO [SettingsFactory] Order SQL updates by primary key: disabled
12:01:23,355 INFO [SettingsFactory] Order SQL inserts for batching: disabled
12:01:23,356 INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
12:01:23,361 INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
12:01:23,361 INFO [SettingsFactory] Query language substitutions: {}
12:01:23,361 INFO [SettingsFactory] JPA-QL strict compliance: enabled
12:01:23,362 INFO [SettingsFactory] Second-level cache: enabled
12:01:23,362 INFO [SettingsFactory] Query cache: disabled
12:01:23,373 INFO [SettingsFactory] Cache region factory : org.hibernate.cache.impl.bridge.RegionFactoryCacheProviderBridge
12:01:23,374 INFO [RegionFactoryCacheProviderBridge] Cache provider: org.hibernate.cache.HashtableCacheProvider
12:01:23,376 INFO [SettingsFactory] Optimize cache for minimal puts: disabled
12:01:23,377 INFO [SettingsFactory] Cache region prefix: persistence.unit:unitName=APP.ear/EJB3Persistence.jar#app.persistence.unit
12:01:23,377 INFO [SettingsFactory] Structured second-level cache entries: disabled
12:01:23,390 INFO [SettingsFactory] Statistics: disabled
12:01:23,390 INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled
12:01:23,391 INFO [SettingsFactory] Default entity-mode: pojo
12:01:23,391 INFO [SettingsFactory] Named query checking : enabled
12:01:23,391 INFO [SettingsFactory] Check Nullability in Core (should be disabled when Bean Validation is on): disabled
12:01:24,179 INFO [SessionFactoryImpl] building session factory
12:01:27,785 INFO [SessionFactoryObjectFactory] Factory name: persistence.unit:unitName=APP.ear/EJB3Persistence.jar#app.persistence.unit
12:01:27,788 INFO [NamingHelper] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
12:01:27,798 INFO [NamingHelper] Creating subcontext: persistence.unit:unitName=APP.ear
12:01:27,798 INFO [SessionFactoryObjectFactory] Bound factory to JNDI name: persistence.unit:unitName=APP.ear/EJB3Persistence.jar#app.persistence.unit
12:01:27,799 WARN [SessionFactoryObjectFactory] InitialContext did not implement EventContext
12:01:27,799 INFO [NamingHelper] JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
-----> ***** note that JBoss sleeps here for ~4 minutes, doing nothing; at least logging nothing :- / *****
-----> ***** note that JndiSessionRegistrarBase needs ~3 minutes to register ~600 EJB3 Session Beans!! *****
***** [n-times 'STARTED EJB' like] *****
12:05:07,966 INFO [SessionSpecContainer] Starting jboss.j2ee:ear=APP.ear,jar=AnotherEJB3Module.jar,name=AnotherStatelessSession,service=EJB3
12:05:07,967 INFO [EJBContainer] STARTED EJB: app.package.AnotherStatelessSessionBean ejbName: AnotherStatelessSession
12:05:08,253 INFO [JndiSessionRegistrarBase] Binding the following Entries in Global JNDI:
app/package/AnotherStatelessSession - EJB3.x Default Local Business Interface
APP/AnotherStatelessSession/local-app.package.AnotherStatelessSession - EJB3.x Local Business Interface
12:08:03,036 INFO [SessionSpecContainer] Starting jboss.j2ee:ear=APP.ear,jar=TheLastEJB3Module.jar,name=TheLastStatelessSession,service=EJB3
12:08:03,038 INFO [EJBContainer] STARTED EJB: app.package.TheLastStatelessSessionBean ejbName: TheLastStatelessSession
12:08:03,048 INFO [JndiSessionRegistrarBase] Binding the following Entries in Global JNDI:
app/package/TheLastStatelessSession - EJB3.x Default Remote Business Interface
APP/TheLastStatelessSession/remote-app.packageTheLastStatelessSession - EJB3.x Remote Business Interface
***** [/'STARTED EJB'] *****
12:08:03,221 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name=eis/TheFirstResourceAdapter' to JNDI name 'java:eis/TheFirstResourceAdapter'
12:08:03,247 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name=eis/TheLastResourceAdapter' to JNDI name 'java:eis/TheLastResourceAdapter'
12:08:03,635 INFO [service] Removing bootstrap log handlers
***** following lines from server.log ******
12:08:03,789 INFO [org.jboss.system.server.profileservice.ProfileServiceBootstrap] Loading profile: ProfileKey@4671b856[domain=default, server=default, name=APP]
12:08:03,823 INFO [org.apache.coyote.http11.Http11Protocol] Starting Coyote HTTP/1.1 on http-192.168.1.123-8080
12:08:03,826 INFO [org.apache.coyote.ajp.AjpProtocol] Starting Coyote AJP/1.3 on ajp-192.168.1.123-8009
-----> ***** note that overall start time (boot+deploy) is ~8 minutes oO *****
12:08:03,827 INFO [org.jboss.bootstrap.impl.base.server.AbstractServer] JBossAS [6.0.0.20100429-M3 "Neo"] Started in 8m:9s:780ms
