Adding resource-adapter connection-definition fails sometimes, Race Condition?
lafr Jan 30, 2013 6:19 PMProblems with resource-adapters reappeared.
The rar-file controller.rar is present in deployments folder and deployed.
In standalone.xml there is no resource-adapter defined using controller.rar.
My first cli file:
if (outcome != success) of /subsystem=resource-adapters/resource-adapter=controller.rar:read-resource
/subsystem=resource-adapters/resource-adapter=controller.rar:add(archive=controller.rar, transaction-support=NoTransaction)
end-if
if (outcome != success) of /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc:read-resource
/subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc:add(jndi-name="java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector", class-name="biz.mbisoftware.fn.jca.controllerconnector.ManagedConnectionFactoryImpl", enabled=true)
/subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=ClientService:add(value="JCAClient")
/subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=SocketTimeout:add(value="0")
/subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=Encoding:add(value="ISO-8859-15")
/subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=ServerName:add(value="sb2000")
/subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=PortNumber:add(value="6500")
/subsystem=resource-adapters/resource-adapter=controller.rar:activate
end-if
Executing this is just fine.
Output of jboss-cli.sh:
#1 /subsystem=resource-adapters/resource-adapter=controller.rar:add(archive=controller.rar, transaction-support=NoTransaction)
#1 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc:add(jndi-name="java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector", class-name="biz.mbisoftware.fn.jca.controllerconnector.ManagedConnectionFactoryImpl", enabled=true)
#2 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=ClientService:add(value="JCAClient")
#3 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=SocketTimeout:add(value="0")
#4 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=Encoding:add(value="ISO-8859-15")
#5 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=ServerName:add(value="sb2000")
#6 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=mbi2e-lafr-sb2000-ipc/config-properties=PortNumber:add(value="6500")
#7 /subsystem=resource-adapters/resource-adapter=controller.rar:activate
Entries in server.log:
00:02:41,607 INFO [org.jboss.as.connector.deployment#bindConnectionFactory] JBAS010406: Registered connection factory java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector
00:02:41,612 INFO [org.jboss.as.connector.deployers.RaXmlDeployer#createObjectsAndInjectValue] IJ020002: Deployed: file:/mbi/tools/jboss/7.2/standalone/tmp/vfs/temp165646327ca2133/controller.rar-8229ffcec3d6382d/contents/
00:02:41,621 INFO [org.jboss.as.connector.deployment#transition] JBAS010401: Bound JCA ConnectionFactory [java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector]
Resource-adapater and connection definiton are there. Also visible through management console.
Now trying to add an connection-definition, running the same script as just replacing 'mbi2e-lafr-sb2000-ipc' by 'mbi2e-lafr-sb2000-ipc'.
Output of jboss-cli.sh:
#1 /subsystem=resource-adapters/resource-adapter=controller.rar:add(archive=controller.rar, transaction-support=NoTransaction)
#1 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=hgm2e-langfr-sb2000-ipc:add(jndi-name="java:/eis/hgm2e-langfr-sb2000-ipc/ControllerConnector", class-name="biz.mbisoftware.fn.jca.controllerconnector.ManagedConnectionFactoryImpl", enabled=true)
#2 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=hgm2e-langfr-sb2000-ipc/config-properties=ClientService:add(value="JCAClient")
#3 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=hgm2e-langfr-sb2000-ipc/config-properties=SocketTimeout:add(value="0")
#4 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=hgm2e-langfr-sb2000-ipc/config-properties=Encoding:add(value="ISO-8859-15")
#5 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=hgm2e-langfr-sb2000-ipc/config-properties=ServerName:add(value="sb2000")
#6 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=hgm2e-langfr-sb2000-ipc/config-properties=PortNumber:add(value="6501")
#7 /subsystem=resource-adapters/resource-adapter=controller.rar:activate
Entries in server.log:
00:03:42,783 INFO [org.jboss.as.connector.deployment#transition] JBAS010410: Unbound JCA ConnectionFactory [java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector]
00:03:42,802 INFO [org.jboss.as.connector.deployment#bindConnectionFactory] JBAS010406: Registered connection factory java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector
00:03:42,807 INFO [org.jboss.as.connector.deployment#bindConnectionFactory] JBAS010406: Registered connection factory java:/eis/hgm2e-langfr-sb2000-ipc/ControllerConnector
00:03:42,817 INFO [org.jboss.as.connector.deployers.RaXmlDeployer#createObjectsAndInjectValue] IJ020002: Deployed: file:/mbi/tools/jboss/7.2/standalone/tmp/vfs/temp165646327ca2133/controller.rar-8229ffcec3d6382d/contents/
00:03:42,823 INFO [org.jboss.as.connector.deployment#transition] JBAS010401: Bound JCA ConnectionFactory [java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector]
00:03:42,834 INFO [org.jboss.as.connector.deployment#transition] JBAS010401: Bound JCA ConnectionFactory [java:/eis/hgm2e-langfr-sb2000-ipc/ControllerConnector]
Everything still fine in this case.
Now a third connection-definition.
Output of jboss-cli.sh:
#1 /subsystem=resource-adapters/resource-adapter=controller.rar:add(archive=controller.rar, transaction-support=NoTransaction)
#1 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=maj2e-langfr-dev:add(jndi-name="java:/eis/maj2e-langfr-dev/ControllerConnector", class-name="biz.mbisoftware.fn.jca.controllerconnector.ManagedConnectionFactoryImpl", enabled=true)
#2 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=maj2e-langfr-dev/config-properties=ClientService:add(value="JCAClient")
#3 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=maj2e-langfr-dev/config-properties=SocketTimeout:add(value="0")
#4 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=maj2e-langfr-dev/config-properties=Encoding:add(value="ISO-8859-15")
#5 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=maj2e-langfr-dev/config-properties=ServerName:add(value="sb2000")
#6 /subsystem=resource-adapters/resource-adapter=controller.rar/connection-definitions=maj2e-langfr-dev/config-properties=PortNumber:add(value="6506")
#7 /subsystem=resource-adapters/resource-adapter=controller.rar:activate
But this time in server.log:
00:04:20,941 INFO [org.jboss.as.connector.deployment#bindConnectionFactory] JBAS010406: Registered connection factory java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector
00:04:20,952 INFO [org.jboss.as.connector.deployment#transition] JBAS010410: Unbound JCA ConnectionFactory [java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector]
00:04:20,955 INFO [org.jboss.as.connector.deployment#transition] JBAS010410: Unbound JCA ConnectionFactory [java:/eis/hgm2e-langfr-sb2000-ipc/ControllerConnector]
00:04:20,955 ERROR [org.jboss.msc.service.fail#startFailed] MSC00001: Failed to start service jboss.ra.deployment."controller.rar_3": org.jboss.msc.service.StartException in service jboss.ra.deployment."controller.rar_3": org.jboss.msc.service.StartException in anonymous service: JBAS010446: Failed to start RA deployment [controller]
at org.jboss.as.connector.services.resourceadapters.deployment.ResourceAdapterXmlDeploymentService.start(ResourceAdapterXmlDeploymentService.java:131)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1811) [jboss-msc-1.0.3.GA.jar:1.0.3.GA]
at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1746) [jboss-msc-1.0.3.GA.jar:1.0.3.GA]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_38]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_38]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_38]
Caused by: org.jboss.msc.service.StartException in anonymous service: JBAS010446: Failed to start RA deployment [controller]
at org.jboss.as.connector.services.resourceadapters.deployment.ResourceAdapterXmlDeploymentService.start(ResourceAdapterXmlDeploymentService.java:115)
... 5 more
Caused by: org.jboss.jca.deployers.common.DeployException: IJ020056: Deployment failed: file:/mbi/tools/jboss/7.2/standalone/tmp/vfs/temp165646327ca2133/controller.rar-8229ffcec3d6382d/contents/
at org.jboss.jca.deployers.common.AbstractResourceAdapterDeployer.createObjectsAndInjectValue(AbstractResourceAdapterDeployer.java:2456)
at org.jboss.as.connector.services.resourceadapters.deployment.ResourceAdapterXmlDeploymentService$AS7RaXmlDeployer.doDeploy(ResourceAdapterXmlDeploymentService.java:183)
at org.jboss.as.connector.services.resourceadapters.deployment.ResourceAdapterXmlDeploymentService.start(ResourceAdapterXmlDeploymentService.java:108)
... 5 more
Caused by: org.jboss.msc.service.DuplicateServiceException: Service jboss.connector.connection-factory.java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector is already registered
at org.jboss.msc.service.ServiceRegistrationImpl.setInstance(ServiceRegistrationImpl.java:154) [jboss-msc-1.0.3.GA.jar:1.0.3.GA]
at org.jboss.msc.service.ServiceControllerImpl.startInstallation(ServiceControllerImpl.java:227) [jboss-msc-1.0.3.GA.jar:1.0.3.GA]
at org.jboss.msc.service.ServiceContainerImpl.install(ServiceContainerImpl.java:560) [jboss-msc-1.0.3.GA.jar:1.0.3.GA]
at org.jboss.msc.service.ServiceTargetImpl.install(ServiceTargetImpl.java:201) [jboss-msc-1.0.3.GA.jar:1.0.3.GA]
at org.jboss.msc.service.ServiceControllerImpl$ChildServiceTarget.install(ServiceControllerImpl.java:2228) [jboss-msc-1.0.3.GA.jar:1.0.3.GA]
at org.jboss.msc.service.ServiceBuilderImpl.install(ServiceBuilderImpl.java:307) [jboss-msc-1.0.3.GA.jar:1.0.3.GA]
at org.jboss.as.connector.services.resourceadapters.deployment.AbstractResourceAdapterDeploymentService$AbstractAS7RaDeployer.bindConnectionFactory(AbstractResourceAdapterDeploymentService.java:278)
at org.jboss.jca.deployers.common.AbstractResourceAdapterDeployer.createObjectsAndInjectValue(AbstractResourceAdapterDeployer.java:2218)
... 7 more
00:04:21,026 INFO [org.jboss.as.controller#tick] JBAS014774: Service status report
JBAS014775: New missing/unsatisfied dependencies:
service jboss.resourceadapters.ra."controller.rar".maj2e-langfr-dev (missing) dependents: [service jboss.resourceadapters.ra."controller.rar".maj2e-langfr-dev.PortNumber, service jboss.resourceadapters.ra."controller.rar".maj2e-langfr-dev.ClientService, service jboss.resourceadapters.ra."controller.rar".maj2e-langfr-dev.ServerName, service jboss.resourceadapters.ra."controller.rar".maj2e-langfr-dev.SocketTimeout, JBAS014799: ... and 2 more ]
The :activate failed and caused an exception.
This behaviour is not really reproducable. What got my attention is the order of the messages appearing.
When succesful we have Unbound, Register, Deployed, Bound.
00:03:42,783 INFO [org.jboss.as.connector.deployment#transition] JBAS010410: Unbound JCA ConnectionFactory [java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector]
00:03:42,802 INFO [org.jboss.as.connector.deployment#bindConnectionFactory] JBAS010406: Registered connection factory java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector
00:03:42,807 INFO [org.jboss.as.connector.deployment#bindConnectionFactory] JBAS010406: Registered connection factory java:/eis/hgm2e-langfr-sb2000-ipc/ControllerConnector
00:03:42,817 INFO [org.jboss.as.connector.deployers.RaXmlDeployer#createObjectsAndInjectValue] IJ020002: Deployed: file:/mbi/tools/jboss/7.2/standalone/tmp/vfs/temp165646327ca2133/controller.rar-8229ffcec3d6382d/contents/
00:03:42,823 INFO [org.jboss.as.connector.deployment#transition] JBAS010401: Bound JCA ConnectionFactory [java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector]
00:03:42,834 INFO [org.jboss.as.connector.deployment#transition] JBAS010401: Bound JCA ConnectionFactory [java:/eis/hgm2e-langfr-sb2000-ipc/ControllerConnector]
This seems to really make sense to me.
When not succesful we have Register, Unbound, Failure.
00:04:20,941 INFO [org.jboss.as.connector.deployment#bindConnectionFactory] JBAS010406: Registered connection factory java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector
00:04:20,952 INFO [org.jboss.as.connector.deployment#transition] JBAS010410: Unbound JCA ConnectionFactory [java:/eis/mbi2e-lafr-sb2000-ipc/ControllerConnector]
00:04:20,955 INFO [org.jboss.as.connector.deployment#transition] JBAS010410: Unbound JCA ConnectionFactory [java:/eis/hgm2e-langfr-sb2000-ipc/ControllerConnector]
But this does not make sense to me. The new regsitration is done before the unbinding has finished?
To me this seems to be a bug.
Maybe something is done in parallel not in strict sequence. Sometimes its succesful, sometimes not, depending on which thread gets CPU time first?