Issue Details (XML | Word | Printable)

Key: MULE-2968
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Critical Critical
Assignee: Dirk Olmes
Reporter: Dirk Olmes
Votes: 0
Watchers: 0
Operations

If you were logged in you would be able to see more operations.
Mule

Disposing TCP stream workers creates infinite loop

Created: 05/Feb/08 05:47 AM   Updated: 06/Feb/08 10:18 AM
Component/s: Core: Concurrency / Threading
Affects Version/s: 1.4.3
Fix Version/s: 1.4.4

Time Tracking:
Not Specified

Issue Links:
Related
 

Labels:
User impact: High
Log Output:
[02-05 10:17:55] ERROR DefaultExceptionStrategy [connector.tcp.0.receiver.2]: Caught exception in Exception Strategy: null
java.lang.InterruptedException
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:429)
at edu.emory.mathcs.backport.java.util.concurrent.CountDownLatch.await(CountDownLatch.java:178)
at org.mule.providers.tcp.TcpMessageReceiver$TcpStreamWorker.handleResults(TcpMessageReceiver.java:408)
at org.mule.providers.AbstractReceiverWorker.doRun(AbstractReceiverWorker.java:125)
at org.mule.providers.AbstractReceiverResourceWorker.doRun(AbstractReceiverResourceWorker.java:50)
at org.mule.providers.AbstractReceiverWorker.run(AbstractReceiverWorker.java:60)
at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061)
at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575)
at java.lang.Thread.run(Thread.java:534)
[02-05 10:17:55] ERROR DefaultExceptionStrategy [connector.tcp.0.receiver.2]:
********************************************************************************
Message : Cannot route event as component "bridge2" is stopped. Component that caused exception is: bridge2. Message payload is of type: CloseCountDownInputStream
Type : org.mule.umo.ComponentException
Code : MULE_ERROR-79999
JavaDoc : http://mule.mulesource.org/docs/apidocs/org/mule/umo/ComponentException.html
Payload : org.mule.impl.model.streaming.CloseCountDownInputStream@10efd7c
********************************************************************************
Exception stack is:
1. Cannot route event as component "bridge2" is stopped. Component that caused exception is: bridge2. Message payload is of type: CloseCountDownInputStream (org.mule.umo.ComponentException)
  org.mule.impl.model.AbstractComponent:383 (http://mule.mulesource.org/docs/apidocs/org/mule/umo/ComponentException.html)
********************************************************************************
Root Exception stack trace:
org.mule.umo.ComponentException: Cannot route event as component "bridge2" is stopped. Component that caused exception is: bridge2. Message payload is of type: CloseCountDownInputStream
at org.mule.impl.model.AbstractComponent.sendEvent(AbstractComponent.java:383)
at org.mule.impl.MuleSession.sendEvent(MuleSession.java:349)
at org.mule.routing.inbound.InboundRouterCollection.send(InboundRouterCollection.java:197)
at org.mule.routing.inbound.InboundRouterCollection.route(InboundRouterCollection.java:163)
at org.mule.providers.AbstractMessageReceiver$DefaultInternalMessageListener.onMessage(AbstractMessageReceiver.java:581)
at org.mule.providers.AbstractMessageReceiver.routeMessage(AbstractMessageReceiver.java:322)
at org.mule.providers.AbstractReceiverWorker$1.doInTransaction(AbstractReceiverWorker.java:107)
at org.mule.transaction.TransactionTemplate.execute(TransactionTemplate.java:40)
at org.mule.providers.AbstractReceiverWorker.doRun(AbstractReceiverWorker.java:124)
at org.mule.providers.AbstractReceiverResourceWorker.doRun(AbstractReceiverResourceWorker.java:50)
at org.mule.providers.AbstractReceiverWorker.run(AbstractReceiverWorker.java:60)
at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061)
at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575)
at java.lang.Thread.run(Thread.java:534)

********************************************************************************


 Description  « Hide
The problem can be recreated by running org.mule.test.integration.streaming.FileToTcpStreamingTestCase which produces the attached log output.

 All   Comments   Work Log   Change History   Transitions   FishEye      Sort Order: Ascending order - Click to sort in descending order
Holger Hoffstaette added a comment - 05/Feb/08 11:21 AM
This test (and streaming in general) suffers from several symptoms:

1) input file cannot be deleted on Windows because StreamMessage input stream is never closed

2) file polling overtaking itself which causes multiple stream workers to be spawned for the same file, since it could not be deleted

3) test shutting down (wrongly succeeding on Linux since it allows deletion of opened files!) and TcpWorkers swallowing InterruptedExceptions, continuing to bounce around with stopped & discarded model/component/connectors etc.

3) is what causes the insane amount of logging in mere seconds.


Holger Hoffstaette added a comment - 05/Feb/08 11:24 AM

2) can be mitigated at least for the test by setting the pollingFrequency on the file connector to a higher value. This does not prevent any of the other errors, but only causes one TcpWorker to go bump.



Holger Hoffstaette added a comment - 06/Feb/08 04:09 AM
revisions in previous comment & r10711 for exclusion as this cannot be fixed easily.

Dirk Olmes added a comment - 06/Feb/08 09:32 AM
revisions blocked on the release branch in http://fisheye.codehaus.org/changelog/mule/?cs=10723

Holger Hoffstaette added a comment - 06/Feb/08 09:59 AM
Argh - sorry, I was not clear. r10703/04 are OK for 1.x, they are blocked for 2.x only.

Holger Hoffstaette added a comment - 06/Feb/08 10:04 AM
and just to be crystal-clear r10711 needs to be merged too.

Dirk Olmes added a comment - 06/Feb/08 10:16 AM
reopen for merging into the 1.4.x branch

Dirk Olmes added a comment - 06/Feb/08 10:18 AM