[jboss-user] [JBoss Web Services CXF] - XTS tests broken in AS trunk after switch to CXF stack in 3.3.0

[Andrew Dinn]

Andrew Dinn [http://community.jboss.org/people/adinn] replied to the discussion

"XTS tests broken in AS trunk after switch to CXF stack in 3.3.0"

To view the discussion, visit: http://community.jboss.org/message/547327#547327

--------------------------------------------------------------
Ok, I wrote a little byteman script to trace calls to EndpointAssociation.setEndpoint and EndpointAssociation.getEndpoint:

> # rules to track calls to getEndpoint and setEndpoint in CXF code
> #
> 
> RULE trace setEndpoint
> CLASS EndpointAssociation
> METHOD setEndpoint
> IF TRUE
> DO trace("foo", "setEndpoint(" + $1.getName() + ")\n" + formatStack())
> ENDRULE
> 
> RULE trace getEndpoint
> CLASS EndpointAssociation
> METHOD getEndpoint
> AT RETURN
> IF TRUE
> DO trace("foo", "getEndpoint() ==> " + $!.getName() + "\n" + formatStack())
> ENDRULE

When I ran my tests with  this script installed I got a few cases where successive gets and sets were using different endpoints. Here is a dump of the (filtered and reformatted) trace output:

> setEndpoint(Interop11ATParticipantService)
> Stack trace for thread http-127.0.0.1-8080-3
> getEndpoint() ==> Interop11ATParticipantService
> Stack trace for thread default-workqueue-1      // n.b. worker 1 from participant executor
> 
> setEndpoint(ActivationService)
> Stack trace for thread http-127.0.0.1-8080-4
> getEndpoint() ==> ActivationService
> Stack trace for thread http-127.0.0.1-8080-4
> 
> 
> setEndpoint(RegistrationService)
> Stack trace for thread http-127.0.0.1-8080-4
> getEndpoint() ==> RegistrationService
> Stack trace for thread http-127.0.0.1-8080-4
> 
> setEndpoint(CompletionCoordinator)
> Stack trace for thread http-127.0.0.1-8080-4
> getEndpoint() ==> CompletionCoordinator
> Stack trace for thread default-workqueue-1
> 
> setEndpoint(CompletionInitiator)
> Stack trace for thread http-127.0.0.1-8080-5
> getEndpoint() ==> CompletionInitiator
> Stack trace for thread default-workqueue-2      // n.b. worker 2 from initiator executor
> 
> setEndpoint(Interop11ATInitiatorService)
> Stack trace for thread http-127.0.0.1-8080-6
> getEndpoint() ==> Interop11ATInitiatorService
> Stack trace for thread default-workqueue-2
> 
> 
> 
> . . .
> 
> 
> 
> setEndpoint(RegistrationService)
> Stack trace for thread http-127.0.0.1-8080-9
> getEndpoint() ==> RegistrationService
> Stack trace for thread http-127.0.0.1-8080-9
> 
> setEndpoint(RegistrationService)
> Stack trace for thread http-127.0.0.1-8080-9
> getEndpoint() ==> RegistrationService
> Stack trace for thread http-127.0.0.1-8080-9
> 
> setEndpoint(Interop11ATInitiatorService)         // hmm, call is to initiator service
> Stack trace for thread http-127.0.0.1-8080-9
> getEndpoint() ==> Interop11ATParticipantService
> Stack trace for thread default-workqueue-1       // oops wrong worker and endpoint!
> 
> 
> setEndpoint(ActivationService)
> Stack trace for thread http-127.0.0.1-8080-9
> getEndpoint() ==> ActivationService
> Stack trace for thread http-127.0.0.1-8080-9
> 
> setEndpoint(Interop11ATParticipantService)       // hmm, call is participant service
> Stack trace for thread http-127.0.0.1-8080-5
> getEndpoint() ==> Interop11ATInitiatorService
> Stack trace for thread default-workqueue-2       // wrong worker and endpoint again!
> 
> setEndpoint(ActivationService)
> Stack trace for thread http-127.0.0.1-8080-5
> getEndpoint() ==> ActivationService
> Stack trace for thread http-127.0.0.1-8080-5
> 
> setEndpoint(Interop11ATParticipantService)
> Stack trace for thread http-127.0.0.1-8080-8
> getEndpoint() ==> Interop11ATParticipantService
> Stack trace for thread default-workqueue-3
> . . .
So, worker thread 1 was added under a call to the participant service and hence has this endpoint in its inherited therad local. However it appears to get reused to handle the initiator calls later. How so? I added some trace rules to see what exector was being used:

>  . .
> 
> setEndpoint(jboss.ws:context=interop11,endpoint=Interop11ATParticipantService)
> Stack trace for thread http-127.0.0.1-8080-3
> getExecutor() ==> org.apache.cxf.workqueue.AutomaticWorkQueueImpl at 16c8373 [queue size: 0, max size: 256, threads: 0, active threads: 0, low water mark: 5, high water mark: 25]
> Stack trace for thread http-127.0.0.1-8080-3
> getEndpoint() ==> jboss.ws:context=interop11,endpoint=Interop11ATParticipantService
> Stack trace for thread default-workqueue-1
> . . .
> 
> setEndpoint(jboss.ws:context=interop11,endpoint=Interop11ATInitiatorService)
> Stack trace for thread http-127.0.0.1-8080-6
> getExecutor() ==> org.apache.cxf.workqueue.AutomaticWorkQueueImpl at 16c8373 [queue size: 0, max size: 256, threads: 1, active threads: 1, low water mark: 5, high water mark: 25]
> Stack trace for thread http-127.0.0.1-8080-6
> getEndpoint() ==> jboss.ws:context=interop11,endpoint=Interop11ATInitiatorService
> Stack trace for thread default-workqueue-2
> setEndpoint(jboss.ws:context=interop11,endpoint=Interop11ATParticipantService)
> Stack trace for thread http-127.0.0.1-8080-3
> getExecutor() ==> org.apache.cxf.workqueue.AutomaticWorkQueueImpl at 16c8373 [queue size: 0, max size: 256, threads: 2, active threads: 0, low water mark: 5, high water mark: 25]
> Stack trace for thread http-127.0.0.1-8080-3
> getEndpoint() ==> jboss.ws:context=interop11,endpoint=Interop11ATParticipantService
> Stack trace for thread default-workqueue-3

I added some more trace rules to see what is going on inside getExecutor:
> RULE trace getExecutor
> CLASS ContextUtils
> METHOD getExecutor
> AT RETURN
> IF TRUE
> DO traceln("foo", "getExecutor() ==> " + $!)
> ENDRULE
> 
> 
> 
> RULE trace getExecutor internal
> CLASS ContextUtils
> METHOD getExecutor
> AFTER CALL getNamedWorkQueue
> IF TRUE
> DO traceln("foo", "getExecutor called getNamedWorkQueue")
> ENDRULE
> 
> RULE trace getExecutor internal 2
> CLASS ContextUtils
> METHOD getExecutor
> AFTER CALL getAutomaticWorkQueue
> IF TRUE
> DO traceln("foo", "getExecutor called getAutomaticWorkQueue")
> ENDRULE
> 
> RULE trace getExecutor internal 3
> CLASS ContextUtils
> METHOD getExecutor
> AFTER CALL getInstance
> IF TRUE
> DO traceln("foo", "getExecutor called getInstance")
> ENDRULE

This first rule prints the return value on the stack ($!) when getExecutor is about to return i.e. at the point where the original handler thread is queueing the runnable to execute the handed off message. The trace output reveals that the same executor is being used for both endpoints.

This appears to be because an executor is created per service. When the service has multiple endpoints then threads added to the pool can inherit an endpont at create but later be given jobs to run which are associated with one of  the other endpoints.

--------------------------------------------------------------

Reply to this message by going to Community
[http://community.jboss.org/message/547327#547327]

Start a new discussion in JBoss Web Services CXF at Community
[http://community.jboss.org/choose-container!input.jspa?contentType=1&containerType=14&container=2046]

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/jboss-user/attachments/20100610/8d88a88f/attachment.html