VMLoanBrokerSynchronousFunctionalTestCase logs a warning regarding a null MULE_REMOTE_SYNC property

This isn't just a warning - he test is failing (well, the test is passing, but it's not actually doing anything).

I'm looking at this because I need this test to work for MULE-1551.

Just to correct the above - I think the test is working after all. Sorry.

This is a multithreading issue.

The problem occurs when a MuleMessage contains properties named "method" or "MULE_REMOTE_SYNC". These properties are being deleted in MuleSession.processResponse. However, at the same time, within AbstractMessageDispatcher, another thread is making a copy of the message properties. This second thread requests an iterator over names which is then uses to access the properties. The affected property names appear in the iterator list, but they are deleted from the message before read for copying. As a consequence null values are found.

I can imagine various hacks to solve this, but the underlying problem is a lack of sequencing in the message handling. So I am assigning this to Holger.

Correction: the error occurs in AbstractMesssageAdapter (not Dispatcher) and occurs within MuleMessage constructor (line 74) when copying properties from a previous message. This is itself occurring in VmMessageReceiver (line 96).

Branch https://svn.codehaus.org/mule/branches/trunk-fix-for-MULE-1564 contains modified core classes which produce a detailed multi-threaded report for the issue at runtime.

I believe the following may be related:

================================================================================
= Testing: lots of loan requests =
= (org.mule.examples.loanbroker.esn.XFireLoanBrokerAsynchronousFunctionalTestC =
= ase) =
================================================================================
[07-02 16:49:04] WARN DefaultMessageAdapter [syncVm.dispatcher.5]: setProperty(key, value) called with null value; removing key: method; please report the following stack trace to null
java.lang.Throwable
at org.mule.providers.AbstractMessageAdapter.setProperty(AbstractMessageAdapter.java:141)
at org.mule.providers.DefaultMessageAdapter.<init>(DefaultMessageAdapter.java:88)
at org.mule.impl.MuleMessage.<init>(MuleMessage.java:68)
at org.mule.providers.vm.VMMessageReceiver.onEvent(VMMessageReceiver.java:102)
at org.mule.providers.vm.VMMessageDispatcher.doDispatch(VMMessageDispatcher.java:151)
at org.mule.providers.AbstractMessageDispatcher$Worker.run(AbstractMessageDispatcher.java:608)
at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:987)
at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:528)
at java.lang.Thread.run(Thread.java:534)

(ignore "please report ... null" - I think that's just because I don't have a manifest as I am not running from a packaged distro).

Line 88 of DefaultMessageAdapter is constructing a new message from the contents of an old one.

I was looking at this test because generally it works fine, but it is one of the tests that fails regularly on CI. I think this is fairly strong confirmation that the CI problems we are seeing are related to this issue.

Just trying a local fix. Not intending to cure the greater problem, but perhaps ameliorate the issue a little (and get CI working).

I've modified DefaultMessageAdapter to print a warning rather than die when these problems occur.

This doesn't fix the underlying issue, since we still have inpredictable code. And we can have unpredictable code even when there are no messages printed (it's unpredictabe all the time). So I'm not sure how much this will help. But at the moment CI is failing more than it is passing. So it is interesting to see how this changes things.

Back to you.

output after update - test still fails.

[07-02 20:34:03] WARN DefaultMessageAdapter [syncVm.dispatcher.8]: Detected concurrent access to property method for org.mule.providers.DefaultMessageAdapter{id=92078f5f-28db-11dc-a302-bfddaeaa75bc, payload=org.mule.examples.loanbroker.messages.LoanBrokerQuoteRequest, correlationId=92078f5f-28db-11dc-a302-bfddaeaa75bc, correlationGroup=-1, correlationSeq=-1, encoding=UTF-8, exceptionPayload=null, properties={ MULE_ENDPOINT=vm://lender.service?method=setLenderList MULE_SESSION=SUQ9OTIwODJiYTItMjhkYi0xMWRjLWEzMDItYmZkZGFlYWE3NWJjO0lEPTkyMDgyYmEyLTI4ZGItMTFkYy1hMzAyLWJmZGRhZWFhNzViYw== MULE_ORIGINATING_ENDPOINT=CustomerRequests MULE_CORRELATION_ID=92078f5f-28db-11dc-a302-bfddaeaa75bc }}

Going to remove loanbroker tests from CI.

I think I "fixed" the synchronous loanbroker tests - the config was missing the synchronous default. With that, and the disabled threading that was already present, these tests now pass. We still have the larger issue of scribbling on asynchronous VM (at least) messaging, but that's amply covered in other issues, so tentatively closing this (have e-enabled tests),

The change has to applied to Mule 1.x as well, I don't know why you committed everything to 2.x

I didn't realise this was an issue in 1.4.

My fixes are 2.0 specific. They cannot be applied to 1.4. Indeed, all they do (as far as I know) is make the 2.0 code behave as the 1.4 code should.

So there is no code to apply to 1.4. I guess this issue remains open for that version.

This seems to be a 1.4 issue, so shifting assignment from me back into the pool.

Well, the Affects Version is 1.4, so you have no excuse

Yeah, I did wonder whether that was a mistake, but I guess not.

This also seen with AxisConnectorJmsTopicsFunctionalTestCase

Also, there are two similar but separate issues here. One is attachment handling (DefaultMessageAdapter constructor). The other is properties handling (AbstractMessageAdapter addProperties).

I believe this was fixed in 2.0 I am not seeing this error in the logs