[jboss-jira] [JBoss JIRA] (WFCORE-2656) DeploymentTestCase.testFilesystemScannerRegistration fails intermittently
ehsavoie Hugonnet (JIRA)
issues at jboss.org
Fri Apr 14 14:15:01 EDT 2017
[ https://issues.jboss.org/browse/WFCORE-2656?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13393870#comment-13393870 ]
ehsavoie Hugonnet edited comment on WFCORE-2656 at 4/14/17 2:14 PM:
--------------------------------------------------------------------
Trying to get some meaningful traces :
2017-04-14 20:02:40,252 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) Prepared response is {"outcome" => undefined}
2017-04-14 20:02:40,252 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) published org.jboss.as.controller.ModelControllerImpl$ManagementModelImpl at 1600a8e3
2017-04-14 20:02:40,251 ERROR [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) WFLYDS0012: Scan of /home/ehsavoie/dev/wildfly/core/testsuite/standalone/target/dummy threw Exception: java.lang.RuntimeException: WFLYDS0036: Deployment model operation failed. WFLYCTL0271: Operation cancelled
at org.jboss.as.server.deployment.scanner.DefaultDeploymentOperations.getDeploymentsStatus(DefaultDeploymentOperations.java:84)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService.establishDeployedContentList(FileSystemDeploymentService.java:434)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService.scan(FileSystemDeploymentService.java:583)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService.scan(FileSystemDeploymentService.java:493)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService$DeploymentScanRunnable.run(FileSystemDeploymentService.java:255)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
2017-04-14 20:02:40,253 TRACE [org.jboss.threads] (DeploymentScanner-threads - 1) Thread "Thread[DeploymentScanner-threads - 1,5,DeploymentScanner-threads]" exiting
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) Final response for step handler org.jboss.as.controller.AbstractRemoveStepHandler$1 at 3f939aae handling remove in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {"outcome" => "success"}
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) Final response for step handler org.jboss.as.server.deployment.scanner.DeploymentScannerRemove at 54138c07 handling remove in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {"outcome" => "success"}
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) Final response for step handler org.jboss.as.controller.ModelControllerImpl$DefaultPrepareStepHandler at 5a4c4a6b handling remove in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {"outcome" => "success"}
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller] (management-handler-thread - 1) Executed client request 1807172747
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller.management-operation] (ServerService Thread Pool -- 5) Transmitting response for 1807172747
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) CAS Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
old: RS=false WS=false IM=0 OM=0
new: RS=false WS=false IM=0 OM=1
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Opened outbound message on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Message window is open (131072-44=131028 remaining), proceeding with send
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Flushing message channel
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Sending message (with EOF) (java.nio.DirectByteBuffer[pos=0 lim=8 cap=8192]) to org.xnio.nio.NioSocketStreamConnection at 764220a3
2017-04-14 20:02:40,254 TRACE [org.xnio.nio] (management I/O-1) Running task org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener$$Lambda$150/323991875 at 7be8eebe
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) CAS Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
old: RS=false WS=false IM=0 OM=1
new: RS=false WS=false IM=0 OM=0
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key sun.nio.ch.SelectionKeyImpl at 4f30e74d for java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:9990 remote=/127.0.0.1:53704]
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Closed outbound message on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,254 TRACE [org.xnio.listener] (management I/O-1) Invoking listener org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener at 64abf9eb on channel org.xnio.conduits.ConduitStreamSinkChannel at 4ee73496
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Flushing message channel
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Sent 56 bytes
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Flushed channel
2017-04-14 20:02:40,254 TRACE [org.xnio.nio] (management I/O-1) Running task org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener$$Lambda$150/323991875 at 7d79ec93
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key sun.nio.ch.SelectionKeyImpl at 4f30e74d for java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:9990 remote=/127.0.0.1:53704]
2017-04-14 20:02:40,255 TRACE [org.xnio.listener] (management I/O-1) Invoking listener org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener at 64abf9eb on channel org.xnio.conduits.ConduitStreamSinkChannel at 4ee73496
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Sent 12 bytes
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Flushed channel
2017-04-14 20:02:40,255 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,255 TRACE [org.jboss.as.protocol] (management-handler-thread - 1) Deregistered active operation 1807172747
2017-04-14 20:02:40,255 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,255 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key sun.nio.ch.SelectionKeyImpl at 4f30e74d for java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:9990 remote=/127.0.0.1:53704]
2017-04-14 20:02:40,255 TRACE [org.xnio.listener] (management I/O-1) Invoking listener org.jboss.remoting3.remote.RemoteReadListener at 562f7b61 on channel org.xnio.conduits.ConduitStreamSourceChannel at 6df0b4ee
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) No buffers in queue for message header
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Allocated fresh buffers
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received 26 bytes
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received message java.nio.HeapByteBuffer[pos=0 lim=11 cap=8192]
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message window open
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Acknowledged 44 bytes on Outbound message ID 83d4 on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received message java.nio.HeapByteBuffer[pos=0 lim=7 cap=8192]
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message async close
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Removed Outbound message ID 83d4 on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) No buffers in queue for message header
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Allocated fresh buffers
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received 276 bytes
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received message java.nio.HeapByteBuffer[pos=0 lim=260 cap=8192]
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message data
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) CAS Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
old: RS=false WS=false IM=0 OM=0
new: RS=false WS=false IM=1 OM=0
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Opened inbound message on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.endpoint] (management I/O-1) Allocated tick to 9 of endpoint "localhost:MANAGEMENT" <6910f9b0> (opened org.jboss.remoting3.EndpointImpl$TrackingExecutor at 1ac46e42)
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message (chan 7125e1e3 msg 9e42) (131072-252=130820 remaining)
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received message java.nio.HeapByteBuffer[pos=0 lim=8 cap=8192]
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message data
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message (chan 7125e1e3 msg 9e42) (130820-0=130820 remaining)
2017-04-14 20:02:40,255 TRACE [org.jboss.as.protocol] (management task-7) org.jboss.as.protocol.mgmt.ManagementChannelReceiver at 6154857c handling incoming data
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote] (management I/O-1) CAS Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
old: RS=false WS=false IM=1 OM=0
new: RS=false WS=false IM=0 OM=0
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote] (management I/O-1) Closed inbound message on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) No buffers in queue for message header
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Allocated fresh buffers
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) No read bytes available
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote] (management I/O-1) No message ready; returning
2017-04-14 20:02:40,256 TRACE [org.xnio.nio] (management I/O-1) Running task org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener$$Lambda$150/323991875 at 257cc695
2017-04-14 20:02:40,256 TRACE [org.jboss.as.protocol] (management task-7) Registered active operation 1404179838
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller.management-operation] (management task-7) Handling ExecuteRequest for 1404179838
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key sun.nio.ch.SelectionKeyImpl at 4f30e74d for java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:9990 remote=/127.0.0.1:53704]
2017-04-14 20:02:40,256 TRACE [org.xnio.listener] (management I/O-1) Invoking listener org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener at 64abf9eb on channel org.xnio.conduits.ConduitStreamSinkChannel at 4ee73496
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Sent 11 bytes
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Flushed channel
2017-04-14 20:02:40,256 TRACE [org.jboss.as.protocol] (management task-7) org.jboss.as.protocol.mgmt.ManagementChannelReceiver at 6154857c done handling incoming data
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.endpoint] (management task-7) Resource closed count 00000008 of endpoint "localhost:MANAGEMENT" <6910f9b0> (closed org.jboss.remoting3.EndpointImpl$TrackingExecutor at 1ac46e42)
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Executing ExecuteRequest for 1404179838
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller] (management-handler-thread - 2) Executing client request 1404179838(109)
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Executing {
"operation" => "add",
"address" => [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
],
"path" => "/home/ehsavoie/dev/wildfly/core/testsuite/standalone/target/dummy",
"scan-enabled" => true,
"scan-interval" => 1000,
"auto-deploy-zipped" => false,
"operation-headers" => {
"caller-type" => "user",
"access-mechanism" => "NATIVE"
}
}
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Executing "add" [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
]
2017-04-14 20:02:40,257 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) cloned to org.jboss.as.controller.registry.BasicResource at 4ac3a1a1 to create org.jboss.as.controller.registry.BasicResource at 79e36cf1 and org.jboss.as.controller.ModelControllerImpl$ManagementModelImpl at 208ac94e
2017-04-14 20:02:40,257 DEBUG [org.jboss.as.controller.management-operation] (management-handler-thread - 2) WFLYCTL0017: Operation ("add") failed - address: ([
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
]) - failure description: "WFLYCTL0436: Cannot register capability 'org.wildfly.management.deployment-scanner.dummy' at location '[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]' as it is already registered in context 'global' at location(s) '[[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]]'"
2017-04-14 20:02:40,257 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Rolling back on failed response {
"outcome" => "failed",
"failure-description" => "WFLYCTL0436: Cannot register capability 'org.wildfly.management.deployment-scanner.dummy' at location '[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]' as it is already registered in context 'global' at location(s) '[[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]]'",
"rolled-back" => true
} to operation add on address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] in stage MODEL
2017-04-14 20:02:40,258 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) discarded org.jboss.as.controller.ModelControllerImpl$ManagementModelImpl at 208ac94e
2017-04-14 20:02:40,258 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Final response for step handler org.jboss.as.server.deployment.scanner.DeploymentScannerAdd at 2a559b76 handling add in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {
"outcome" => "failed",
"failure-description" => "WFLYCTL0436: Cannot register capability 'org.wildfly.management.deployment-scanner.dummy' at location '[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]' as it is already registered in context 'global' at location(s) '[[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]]'",
"rolled-back" => true
}
2017-04-14 20:02:40,258 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Final response for step handler org.jboss.as.controller.ModelControllerImpl$DefaultPrepareStepHandler at 5a4c4a6b handling add in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {
"outcome" => "failed",
"failure-description" => "WFLYCTL0436: Cannot register capability 'org.wildfly.management.deployment-scanner.dummy' at location '[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]' as it is already registered in context 'global' at location(s) '[[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]]'",
"rolled-back" => true
}
was (Author: ehugonnet):
2017-04-14 20:02:40,252 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) Prepared response is {"outcome" => undefined}
2017-04-14 20:02:40,252 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) published org.jboss.as.controller.ModelControllerImpl$ManagementModelImpl at 1600a8e3
2017-04-14 20:02:40,251 ERROR [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) WFLYDS0012: Scan of /home/ehsavoie/dev/wildfly/core/testsuite/standalone/target/dummy threw Exception: java.lang.RuntimeException: WFLYDS0036: Deployment model operation failed. WFLYCTL0271: Operation cancelled
at org.jboss.as.server.deployment.scanner.DefaultDeploymentOperations.getDeploymentsStatus(DefaultDeploymentOperations.java:84)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService.establishDeployedContentList(FileSystemDeploymentService.java:434)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService.scan(FileSystemDeploymentService.java:583)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService.scan(FileSystemDeploymentService.java:493)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService$DeploymentScanRunnable.run(FileSystemDeploymentService.java:255)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
2017-04-14 20:02:40,253 TRACE [org.jboss.threads] (DeploymentScanner-threads - 1) Thread "Thread[DeploymentScanner-threads - 1,5,DeploymentScanner-threads]" exiting
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) Final response for step handler org.jboss.as.controller.AbstractRemoveStepHandler$1 at 3f939aae handling remove in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {"outcome" => "success"}
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) Final response for step handler org.jboss.as.server.deployment.scanner.DeploymentScannerRemove at 54138c07 handling remove in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {"outcome" => "success"}
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 1) Final response for step handler org.jboss.as.controller.ModelControllerImpl$DefaultPrepareStepHandler at 5a4c4a6b handling remove in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {"outcome" => "success"}
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller] (management-handler-thread - 1) Executed client request 1807172747
2017-04-14 20:02:40,254 TRACE [org.jboss.as.controller.management-operation] (ServerService Thread Pool -- 5) Transmitting response for 1807172747
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) CAS Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
old: RS=false WS=false IM=0 OM=0
new: RS=false WS=false IM=0 OM=1
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Opened outbound message on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Message window is open (131072-44=131028 remaining), proceeding with send
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Flushing message channel
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Sending message (with EOF) (java.nio.DirectByteBuffer[pos=0 lim=8 cap=8192]) to org.xnio.nio.NioSocketStreamConnection at 764220a3
2017-04-14 20:02:40,254 TRACE [org.xnio.nio] (management I/O-1) Running task org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener$$Lambda$150/323991875 at 7be8eebe
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) CAS Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
old: RS=false WS=false IM=0 OM=1
new: RS=false WS=false IM=0 OM=0
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key sun.nio.ch.SelectionKeyImpl at 4f30e74d for java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:9990 remote=/127.0.0.1:53704]
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Closed outbound message on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,254 TRACE [org.xnio.listener] (management I/O-1) Invoking listener org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener at 64abf9eb on channel org.xnio.conduits.ConduitStreamSinkChannel at 4ee73496
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote] (ServerService Thread Pool -- 5) Flushing message channel
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Sent 56 bytes
2017-04-14 20:02:40,254 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Flushed channel
2017-04-14 20:02:40,254 TRACE [org.xnio.nio] (management I/O-1) Running task org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener$$Lambda$150/323991875 at 7d79ec93
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key sun.nio.ch.SelectionKeyImpl at 4f30e74d for java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:9990 remote=/127.0.0.1:53704]
2017-04-14 20:02:40,255 TRACE [org.xnio.listener] (management I/O-1) Invoking listener org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener at 64abf9eb on channel org.xnio.conduits.ConduitStreamSinkChannel at 4ee73496
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Sent 12 bytes
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Flushed channel
2017-04-14 20:02:40,255 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,255 TRACE [org.jboss.as.protocol] (management-handler-thread - 1) Deregistered active operation 1807172747
2017-04-14 20:02:40,255 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,255 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key sun.nio.ch.SelectionKeyImpl at 4f30e74d for java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:9990 remote=/127.0.0.1:53704]
2017-04-14 20:02:40,255 TRACE [org.xnio.listener] (management I/O-1) Invoking listener org.jboss.remoting3.remote.RemoteReadListener at 562f7b61 on channel org.xnio.conduits.ConduitStreamSourceChannel at 6df0b4ee
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) No buffers in queue for message header
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Allocated fresh buffers
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received 26 bytes
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received message java.nio.HeapByteBuffer[pos=0 lim=11 cap=8192]
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message window open
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Acknowledged 44 bytes on Outbound message ID 83d4 on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received message java.nio.HeapByteBuffer[pos=0 lim=7 cap=8192]
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message async close
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Removed Outbound message ID 83d4 on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) No buffers in queue for message header
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Allocated fresh buffers
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received 276 bytes
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received message java.nio.HeapByteBuffer[pos=0 lim=260 cap=8192]
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message data
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) CAS Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
old: RS=false WS=false IM=0 OM=0
new: RS=false WS=false IM=1 OM=0
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Opened inbound message on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.endpoint] (management I/O-1) Allocated tick to 9 of endpoint "localhost:MANAGEMENT" <6910f9b0> (opened org.jboss.remoting3.EndpointImpl$TrackingExecutor at 1ac46e42)
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message (chan 7125e1e3 msg 9e42) (131072-252=130820 remaining)
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Received message java.nio.HeapByteBuffer[pos=0 lim=8 cap=8192]
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message data
2017-04-14 20:02:40,255 TRACE [org.jboss.remoting.remote] (management I/O-1) Received message (chan 7125e1e3 msg 9e42) (130820-0=130820 remaining)
2017-04-14 20:02:40,255 TRACE [org.jboss.as.protocol] (management task-7) org.jboss.as.protocol.mgmt.ManagementChannelReceiver at 6154857c handling incoming data
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote] (management I/O-1) CAS Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
old: RS=false WS=false IM=1 OM=0
new: RS=false WS=false IM=0 OM=0
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote] (management I/O-1) Closed inbound message on Channel ID 7125e1e3 (inbound) of Remoting connection 0eba43d6 to /127.0.0.1:53704 of endpoint "localhost:MANAGEMENT" <6910f9b0>
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) No buffers in queue for message header
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Allocated fresh buffers
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) No read bytes available
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote] (management I/O-1) No message ready; returning
2017-04-14 20:02:40,256 TRACE [org.xnio.nio] (management I/O-1) Running task org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener$$Lambda$150/323991875 at 257cc695
2017-04-14 20:02:40,256 TRACE [org.jboss.as.protocol] (management task-7) Registered active operation 1404179838
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller.management-operation] (management task-7) Handling ExecuteRequest for 1404179838
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key sun.nio.ch.SelectionKeyImpl at 4f30e74d for java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:9990 remote=/127.0.0.1:53704]
2017-04-14 20:02:40,256 TRACE [org.xnio.listener] (management I/O-1) Invoking listener org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener at 64abf9eb on channel org.xnio.conduits.ConduitStreamSinkChannel at 4ee73496
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Sent 11 bytes
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.remote.connection] (management I/O-1) Flushed channel
2017-04-14 20:02:40,256 TRACE [org.jboss.as.protocol] (management task-7) org.jboss.as.protocol.mgmt.ManagementChannelReceiver at 6154857c done handling incoming data
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select on sun.nio.ch.EPollSelectorImpl at 5c514c12
2017-04-14 20:02:40,256 TRACE [org.jboss.remoting.endpoint] (management task-7) Resource closed count 00000008 of endpoint "localhost:MANAGEMENT" <6910f9b0> (closed org.jboss.remoting3.EndpointImpl$TrackingExecutor at 1ac46e42)
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Executing ExecuteRequest for 1404179838
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller] (management-handler-thread - 2) Executing client request 1404179838(109)
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Executing {
"operation" => "add",
"address" => [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
],
"path" => "/home/ehsavoie/dev/wildfly/core/testsuite/standalone/target/dummy",
"scan-enabled" => true,
"scan-interval" => 1000,
"auto-deploy-zipped" => false,
"operation-headers" => {
"caller-type" => "user",
"access-mechanism" => "NATIVE"
}
}
2017-04-14 20:02:40,256 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Executing "add" [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
]
2017-04-14 20:02:40,257 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) cloned to org.jboss.as.controller.registry.BasicResource at 4ac3a1a1 to create org.jboss.as.controller.registry.BasicResource at 79e36cf1 and org.jboss.as.controller.ModelControllerImpl$ManagementModelImpl at 208ac94e
2017-04-14 20:02:40,257 DEBUG [org.jboss.as.controller.management-operation] (management-handler-thread - 2) WFLYCTL0017: Operation ("add") failed - address: ([
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
]) - failure description: "WFLYCTL0436: Cannot register capability 'org.wildfly.management.deployment-scanner.dummy' at location '[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]' as it is already registered in context 'global' at location(s) '[[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]]'"
2017-04-14 20:02:40,257 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Rolling back on failed response {
"outcome" => "failed",
"failure-description" => "WFLYCTL0436: Cannot register capability 'org.wildfly.management.deployment-scanner.dummy' at location '[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]' as it is already registered in context 'global' at location(s) '[[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]]'",
"rolled-back" => true
} to operation add on address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] in stage MODEL
2017-04-14 20:02:40,258 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) discarded org.jboss.as.controller.ModelControllerImpl$ManagementModelImpl at 208ac94e
2017-04-14 20:02:40,258 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Final response for step handler org.jboss.as.server.deployment.scanner.DeploymentScannerAdd at 2a559b76 handling add in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {
"outcome" => "failed",
"failure-description" => "WFLYCTL0436: Cannot register capability 'org.wildfly.management.deployment-scanner.dummy' at location '[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]' as it is already registered in context 'global' at location(s) '[[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]]'",
"rolled-back" => true
}
2017-04-14 20:02:40,258 TRACE [org.jboss.as.controller.management-operation] (management-handler-thread - 2) Final response for step handler org.jboss.as.controller.ModelControllerImpl$DefaultPrepareStepHandler at 5a4c4a6b handling add in address [
("subsystem" => "deployment-scanner"),
("scanner" => "dummy")
] is {
"outcome" => "failed",
"failure-description" => "WFLYCTL0436: Cannot register capability 'org.wildfly.management.deployment-scanner.dummy' at location '[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]' as it is already registered in context 'global' at location(s) '[[
(\"subsystem\" => \"deployment-scanner\"),
(\"scanner\" => \"dummy\")
]]'",
"rolled-back" => true
}
> DeploymentTestCase.testFilesystemScannerRegistration fails intermittently
> -------------------------------------------------------------------------
>
> Key: WFCORE-2656
> URL: https://issues.jboss.org/browse/WFCORE-2656
> Project: WildFly Core
> Issue Type: Bug
> Components: Deployment Scanner, Domain Management
> Reporter: Brian Stansberry
> Assignee: Brian Stansberry
>
> https://ci.wildfly.org/project.html?projectId=WildFlyCore_PullRequest&testNameId=5510538220891037036&tab=testDetails
> I fear this has something to do with the capability registry and nothing to do with the scanner itself. It started happening when I added a capability to the scanner so it could consume a capability for the path it references.
> The test does a quick add/remove/add of a scanner resource and it's the 2nd add that fails with a dupicate capability error. But the remove mean the dup is gone. It's intermittent so I fear some race, but there's nothing obvious.
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
More information about the jboss-jira
mailing list