[
https://issues.jboss.org/browse/WFCORE-2656?page=com.atlassian.jira.plugi...
]
ehsavoie Hugonnet commented on WFCORE-2656:
-------------------------------------------
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@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@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@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@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@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@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@7be8eebe
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select
on sun.nio.ch.EPollSelectorImpl@5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on
sun.nio.ch.EPollSelectorImpl@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@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@64abf9eb on channel
org.xnio.conduits.ConduitStreamSinkChannel@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@7d79ec93
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Beginning select
on sun.nio.ch.EPollSelectorImpl@5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on
sun.nio.ch.EPollSelectorImpl@5c514c12
2017-04-14 20:02:40,254 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key
sun.nio.ch.SelectionKeyImpl@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@64abf9eb on channel
org.xnio.conduits.ConduitStreamSinkChannel@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@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@5c514c12
2017-04-14 20:02:40,255 TRACE [org.xnio.nio.selector] (management I/O-1) Selected key
sun.nio.ch.SelectionKeyImpl@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@562f7b61 on channel
org.xnio.conduits.ConduitStreamSourceChannel@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@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@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@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@5c514c12
2017-04-14 20:02:40,256 TRACE [org.xnio.nio.selector] (management I/O-1) Selected on
sun.nio.ch.EPollSelectorImpl@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@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@64abf9eb on channel
org.xnio.conduits.ConduitStreamSinkChannel@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@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@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@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@4ac3a1a1 to create
org.jboss.as.controller.registry.BasicResource@79e36cf1 and
org.jboss.as.controller.ModelControllerImpl$ManagementModelImpl@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@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@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@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&...
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)