Attachment 918706 Details for Bug 971679 – log86

log86

log86 (text/plain), 18.66 KB, created by Matous Jobanek on 2014-07-17 13:44:15 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Matous Jobanek

Created: 2014-07-17 13:44:15 UTC

Size: 18.66 KB

patch

obsolete

>[INFO] Scanning for projects...
>[INFO] 
>[INFO] Using the builder org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder with a thread count of 1
>[INFO]                                                                         
>[INFO] ------------------------------------------------------------------------
>[INFO] Building ejb.tests 0.0.1-SNAPSHOT
>[INFO] ------------------------------------------------------------------------
>[INFO] 
>[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ ejb.tests ---
>[INFO] Deleting /home/mjobanek/temp/ejb.tests/target
>[INFO] 
>[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ ejb.tests ---
>[WARNING] Using platform encoding (UTF-8 actually) to copy filtered resources, i.e. build is platform dependent!
>[INFO] Copying 0 resource
>[INFO] 
>[INFO] --- maven-compiler-plugin:2.5.1:compile (default-compile) @ ejb.tests ---
>[WARNING] File encoding has not been set, using platform encoding UTF-8, i.e. build is platform dependent!
>[INFO] Compiling 3 source files to /home/mjobanek/temp/ejb.tests/target/classes
>[INFO] 
>[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ ejb.tests ---
>[WARNING] File encoding has not been set, using platform encoding UTF-8, i.e. build is platform dependent!
>[WARNING] Using platform encoding (UTF-8 actually) to copy filtered resources, i.e. build is platform dependent!
>[INFO] Copying 6 resources
>[INFO] 
>[INFO] --- maven-compiler-plugin:2.5.1:testCompile (default-testCompile) @ ejb.tests ---
>[WARNING] File encoding has not been set, using platform encoding UTF-8, i.e. build is platform dependent!
>[INFO] Compiling 1 source file to /home/mjobanek/temp/ejb.tests/target/test-classes
>[INFO] 
>[INFO] --- maven-surefire-plugin:2.10:test (default-test) @ ejb.tests ---
>[INFO] Surefire report directory: /home/mjobanek/temp/ejb.tests/target/surefire-reports
>
>-------------------------------------------------------
> T E S T S
>-------------------------------------------------------
>Running ejb.test.timer.undeploy.test.TimerUndeployTest
>Jul 17, 2014 2:44:30 PM org.jboss.as.arquillian.container.managed.ManagedDeployableContainer startInternal
>INFO: Starting container with: [/usr/java/jdk1.7.0_45/bin/java, -Xmx1024m, -XX:MaxPermSize=1024m, -ea, -Djboss.home.dir=/home/mjobanek/temp/servers/jboss-eap-6.3/, -Dorg.jboss.boot.log.file=/home/mjobanek/temp/servers/jboss-eap-6.3/standalone/log/boot.log, -Dlogging.configuration=file:/home/mjobanek/temp/servers/jboss-eap-6.3/standalone/configuration/logging.properties, -Djboss.bundles.dir=/home/mjobanek/temp/servers/jboss-eap-6.3//bundles, -jar, /home/mjobanek/temp/servers/jboss-eap-6.3/jboss-modules.jar, -mp, /home/mjobanek/temp/servers/jboss-eap-6.3//modules, -jaxpmodule, javax.xml.jaxp-provider, org.jboss.as.standalone, -server-config, standalone.xml]
>[0m14:44:31,511 INFO  [org.jboss.modules] (main) JBoss Modules version 1.3.3.Final-redhat-1
>[0m[0m14:44:32,298 INFO  [org.jboss.msc] (main) JBoss MSC version 1.1.5.Final-redhat-1
>[0m[0m14:44:32,632 INFO  [org.jboss.as] (MSC service thread 1-8) JBAS015899: JBoss EAP 6.3.0.GA (AS 7.4.0.Final-redhat-19) starting
>[0m[0m14:44:35,386 INFO  [org.xnio] (MSC service thread 1-4) XNIO Version 3.0.10.GA-redhat-1
>[0m[0m14:44:35,402 INFO  [org.jboss.as.server] (Controller Boot Thread) JBAS015888: Creating http management service using socket-binding (management-http)
>[0m[0m14:44:35,410 INFO  [org.xnio.nio] (MSC service thread 1-4) XNIO NIO Implementation Version 3.0.10.GA-redhat-1
>[0m[0m14:44:35,445 INFO  [org.jboss.remoting] (MSC service thread 1-4) JBoss Remoting version (unknown)
>[0m[0m14:44:35,571 INFO  [org.jboss.as.naming] (ServerService Thread Pool -- 37) JBAS011800: Activating Naming Subsystem
>[0m[0m14:44:35,607 INFO  [org.jboss.as.security] (ServerService Thread Pool -- 42) JBAS013171: Activating Security Subsystem
>[0m[0m14:44:35,569 INFO  [org.jboss.as.jsf] (ServerService Thread Pool -- 35) JBAS012605: Activated the following JSF Implementations: [main, 1.2]
>[0m[33m14:44:35,603 WARN  [org.jboss.as.txn] (ServerService Thread Pool -- 44) JBAS010153: Node identifier property is set to the default value. Please make sure it is unique.
>[0m[0m14:44:35,669 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 29) JBAS010280: Activating Infinispan subsystem.
>[0m[0m14:44:35,701 INFO  [org.jboss.as.webservices] (ServerService Thread Pool -- 46) JBAS015537: Activating WebServices Extension
>[0m[0m14:44:35,703 INFO  [org.jboss.as.security] (MSC service thread 1-8) JBAS013170: Current PicketBox version=4.0.19.SP8-redhat-1
>[0m[0m14:44:35,915 INFO  [org.jboss.as.connector.logging] (MSC service thread 1-1) JBAS010408: Starting JCA Subsystem (IronJacamar 1.0.26.Final-redhat-1)
>[0m[0m14:44:35,947 INFO  [org.jboss.as.mail.extension] (MSC service thread 1-3) JBAS015400: Bound mail session [java:jboss/mail/Default]
>[0m[0m14:44:35,948 INFO  [org.jboss.as.naming] (MSC service thread 1-1) JBAS011802: Starting Naming Service
>[0m[0m14:44:36,167 INFO  [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 25) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3)
>[0m[0m14:44:36,918 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-7) JBWEB003001: Coyote HTTP/1.1 initializing on : http-/127.0.0.1:8080
>[0m[0m14:44:37,006 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-7) JBWEB003000: Coyote HTTP/1.1 starting on: http-/127.0.0.1:8080
>[0m[0m14:44:37,445 INFO  [org.jboss.ws.common.management] (MSC service thread 1-1) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.3.0.Final-redhat-3
>[0m[0m14:44:37,545 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-4) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS]
>[0m[0m14:44:37,611 INFO  [org.jboss.as.remoting] (MSC service thread 1-3) JBAS017100: Listening on 127.0.0.1:4447
>[0m[0m14:44:37,613 INFO  [org.jboss.as.remoting] (MSC service thread 1-2) JBAS017100: Listening on 127.0.0.1:9999
>[0m[0m14:44:37,627 INFO  [org.jboss.as.server.deployment.scanner] (MSC service thread 1-5) JBAS015012: Started FileSystemDeploymentService for directory /home/mjobanek/temp/servers/jboss-eap-6.3/standalone/deployments
>[0m[0m14:44:37,936 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management
>[0m[0m14:44:37,938 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990
>[0m[0m14:44:37,939 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.3.0.GA (AS 7.4.0.Final-redhat-19) started in 7417ms - Started 151 of 189 services (56 services are lazy, passive or on-demand)
>[0mJul 17, 2014 2:44:44 PM org.jboss.arquillian.drone.webdriver.factory.WebDriverFactory createInstance
>INFO: Property "browserCapabilities" was not specified, using default value of htmlUnit
>[0m14:44:45,779 INFO  [org.jboss.as.repository] (management-handler-thread - 2) JBAS014900: Content added at location /home/mjobanek/temp/servers/jboss-eap-6.3/standalone/data/content/f4/845946e439081abf892832f3b773adf73211e9/content
>[0m[0m14:44:45,797 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-7) JBAS015876: Starting deployment of "ejbtest.war" (runtime-name: "ejbtest.war")
>[0m[0m14:44:46,217 INFO  [org.jboss.weld.deployer] (MSC service thread 1-6) JBAS016002: Processing weld deployment ejbtest.war
>[0m[0m14:44:46,224 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-6) JNDI bindings for session bean named TestTimer in deployment unit deployment "ejbtest.war" are as follows:
>
>	java:global/ejbtest/TestTimer!ejb.test.timer.TestTimer
>	java:app/ejbtest/TestTimer!ejb.test.timer.TestTimer
>	java:module/TestTimer!ejb.test.timer.TestTimer
>	java:global/ejbtest/TestTimer
>	java:app/ejbtest/TestTimer
>	java:module/TestTimer
>
>[0m[0m14:44:46,337 INFO  [org.jboss.weld.deployer] (MSC service thread 1-7) JBAS016005: Starting Services for CDI deployment: ejbtest.war
>[0m[0m14:44:46,389 INFO  [org.jboss.weld.Version] (MSC service thread 1-7) WELD-000900 1.1.23 (redhat)
>[0m[0m14:44:46,420 INFO  [org.jboss.weld.deployer] (MSC service thread 1-8) JBAS016008: Starting weld service for deployment ejbtest.war
>[0m[0m14:44:46,805 INFO  [org.jboss.web] (ServerService Thread Pool -- 5) JBAS018210: Register web context: /ejbtest
>[0m[0m14:44:46,883 INFO  [javax.enterprise.resource.webcontainer.jsf.config] (ServerService Thread Pool -- 5) Initializing Mojarra 2.1.28-jbossorg-2  for context '/ejbtest'
>[0m[0m14:44:47,130 INFO  [org.hibernate.validator.internal.util.Version] (ServerService Thread Pool -- 5) HV000001: Hibernate Validator 4.3.1.Final-redhat-1
>[0m[0m14:44:47,414 INFO  [org.jboss.as.server] (management-handler-thread - 2) JBAS018559: Deployed "ejbtest.war" (runtime-name : "ejbtest.war")
>[0m[0m14:44:50,307 INFO  [stdout] (EJB default - 1) Time out called Application Scoped
>[0m[0m14:44:55,306 INFO  [stdout] (EJB default - 2) Time out called Application Scoped
>[0m[0m14:45:00,307 INFO  [org.jboss.web] (ServerService Thread Pool -- 5) JBAS018224: Unregister web context: /ejbtest
>[0m[0m14:45:00,316 INFO  [org.jboss.weld.deployer] (MSC service thread 1-8) JBAS016009: Stopping weld service for deployment ejbtest.war
>[0m[31m14:45:00,315 ERROR [org.jboss.as.ejb3] (EJB default - 3) JBAS014120: Error invoking timeout for timer: [id=5f0af9d8-3f16-4b29-8a27-1883ec611b7d timedObjectId=ejbtest.ejbtest.TestTimer auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@533f6512 initialExpiration=Thu Jul 17 14:44:50 CEST 2014 intervalDuration(in milli sec)=5000 nextExpiration=Thu Jul 17 14:45:05 CEST 2014 timerState=IN_TIMEOUT: org.jboss.as.ejb3.component.EJBComponentUnavailableException: JBAS014559: Invocation cannot proceed as component is shutting down
>	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:59) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
>	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
>	at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
>	at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
>	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
>	at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:101) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]
>	at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:111) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]
>	at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:157) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]
>	at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:132) [jboss-as-ejb3-7.4.0.Final-redhat-19.jar:7.4.0.Final-redhat-19]
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_45]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_45]
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_45]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_45]
>	at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_45]
>	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]
>
>[0mLogManager error of type FORMAT_FAILURE: Formatting error
>java.lang.IllegalStateException
>	at org.jboss.msc.value.InjectedValue.getValue(InjectedValue.java:47)
>	at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.getTimedObjectId(TimedObjectInvokerImpl.java:106)
>	at org.jboss.as.ejb3.timerservice.TimerImpl.toString(TimerImpl.java:615)
>	at java.util.Formatter$FormatSpecifier.printString(Formatter.java:2838)
>	at java.util.Formatter$FormatSpecifier.print(Formatter.java:2718)
>	at java.util.Formatter.format(Formatter.java:2488)
>	at java.util.Formatter.format(Formatter.java:2423)
>	at java.lang.String.format(String.java:2797)
>	at org.jboss.logmanager.ExtLogRecord.formatRecord(ExtLogRecord.java:434)
>	at org.jboss.logmanager.ExtLogRecord.getFormattedMessage(ExtLogRecord.java:397)
>	at org.jboss.logmanager.formatters.Formatters$10.renderRaw(Formatters.java:568)
>	at org.jboss.logmanager.formatters.Formatters$JustifyingFormatStep.render(Formatters.java:225)
>	at org.jboss.logmanager.formatters.MultistepFormatter.format(MultistepFormatter.java:86)
>	at org.jboss.logmanager.ExtFormatter.format(ExtFormatter.java:35)
>	at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:49)[0m14:45:00,347 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-6) JBAS015877: Stopped deployment ejbtest.war (runtime-name: ejbtest.war) in 45ms
>[0m
>	at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:79)
>	at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:296)
>	at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
>	at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
>	at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
>	at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
>	at org.jboss.logmanager.Logger.logRaw(Logger.java:721)
>	at org.jboss.logmanager.Logger.log(Logger.java:672)
>	at org.jboss.logging.JBossLogManagerLogger.doLogf(JBossLogManagerLogger.java:50)
>	at org.jboss.logging.Logger.logf(Logger.java:2096)
>	at org.jboss.as.ejb3.EjbLogger_$logger.timerRetried(EjbLogger_$logger.java:214)
>	at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:139)
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>	at java.lang.Thread.run(Thread.java:744)
>	at org.jboss.threads.JBossThread.run(JBossThread.java:122)
>[0m14:45:00,442 INFO  [org.jboss.as.repository] (management-handler-thread - 3) JBAS014901: Content removed from location /home/mjobanek/temp/servers/jboss-eap-6.3/standalone/data/content/f4/845946e439081abf892832f3b773adf73211e9/content
>[0m[0m14:45:00,443 INFO  [org.jboss.as.server] (management-handler-thread - 3) JBAS018558: Undeployed "ejbtest.war" (runtime-name: "ejbtest.war")
>[0m[0m14:45:00,525 INFO  [org.jboss.as.repository] (management-handler-thread - 4) JBAS014900: Content added at location /home/mjobanek/temp/servers/jboss-eap-6.3/standalone/data/content/8e/33a464fb1ea6485c0286f3d3eb178b595c377d/content
>[0m[0m14:45:00,528 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-4) JBAS015876: Starting deployment of "ejbtest.war" (runtime-name: "ejbtest.war")
>[0m[0m14:45:00,689 INFO  [org.jboss.weld.deployer] (MSC service thread 1-8) JBAS016002: Processing weld deployment ejbtest.war
>[0m[0m14:45:00,691 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-8) JNDI bindings for session bean named TestTimer in deployment unit deployment "ejbtest.war" are as follows:
>
>	java:global/ejbtest/TestTimer!ejb.test.timer.TestTimer
>	java:app/ejbtest/TestTimer!ejb.test.timer.TestTimer
>	java:module/TestTimer!ejb.test.timer.TestTimer
>	java:global/ejbtest/TestTimer
>	java:app/ejbtest/TestTimer
>	java:module/TestTimer
>
>[0m[0m14:45:00,722 INFO  [org.jboss.weld.deployer] (MSC service thread 1-2) JBAS016005: Starting Services for CDI deployment: ejbtest.war
>[0m[0m14:45:00,742 INFO  [org.jboss.weld.deployer] (MSC service thread 1-2) JBAS016008: Starting weld service for deployment ejbtest.war
>[0m[0m14:45:00,845 INFO  [org.jboss.web] (ServerService Thread Pool -- 54) JBAS018210: Register web context: /ejbtest
>[0m[0m14:45:00,856 INFO  [javax.enterprise.resource.webcontainer.jsf.config] (ServerService Thread Pool -- 54) Initializing Mojarra 2.1.28-jbossorg-2  for context '/ejbtest'
>[0m[0m14:45:01,013 INFO  [org.jboss.as.server] (management-handler-thread - 4) JBAS018559: Deployed "ejbtest.war" (runtime-name : "ejbtest.war")
>[0m[0m14:45:01,209 INFO  [org.jboss.web] (ServerService Thread Pool -- 54) JBAS018224: Unregister web context: /ejbtest
>[0m[0m14:45:01,220 INFO  [org.jboss.weld.deployer] (MSC service thread 1-5) JBAS016009: Stopping weld service for deployment ejbtest.war
>[0m[0m14:45:01,231 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-4) JBAS015877: Stopped deployment ejbtest.war (runtime-name: ejbtest.war) in 25ms
>[0m[0m14:45:01,324 INFO  [org.jboss.as.repository] (management-handler-thread - 2) JBAS014901: Content removed from location /home/mjobanek/temp/servers/jboss-eap-6.3/standalone/data/content/8e/33a464fb1ea6485c0286f3d3eb178b595c377d/content
>[0m[0m14:45:01,324 INFO  [org.jboss.as.server] (management-handler-thread - 2) JBAS018558: Undeployed "ejbtest.war" (runtime-name: "ejbtest.war")
>[0mTests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 34.636 sec
>
>Results :
>
>Tests run: 1, Failures: 0, Errors: 0, Skipped: 0
>
>[INFO] 
>[INFO] --- maven-war-plugin:2.2:war (default-war) @ ejb.tests ---
>[INFO] Packaging webapp
>[INFO] Assembling webapp [ejb.tests] in [/home/mjobanek/temp/ejb.tests/target/ejbtest]
>[INFO] Processing war project
>[INFO] Copying webapp resources [/home/mjobanek/temp/ejb.tests/src/main/webapp]
>[INFO] Webapp assembled in [33 msecs]
>[INFO] Building war: /home/mjobanek/temp/ejb.tests/target/ejbtest.war
>[INFO] WEB-INF/web.xml already added, skipping
>[INFO] ------------------------------------------------------------------------
>[INFO] BUILD SUCCESS
>[INFO] ------------------------------------------------------------------------
>[INFO] Total time: 45.509 s
>[INFO] Finished at: 2014-07-17T14:45:01+01:00
>[INFO] Final Memory: 32M/320M
>[INFO] ------------------------------------------------------------------------

Actions: View

Attachments on bug 971679: 758002 | 918705 | 918706 | 919049