You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@servicemix.apache.org by Atit <at...@gmail.com> on 2011/06/13 10:49:22 UTC

SMXCOMP-594: persists in 2009.02

Hi,

SMXCOMP-594 refers to the defect where ServiceMix is "Unable to acquire lock
on .... " a file during file polling. When ServiceMix polls files from a
directory, it fails to read some files and leaves them behind in the
directory. But will continues to read any other files dropped in the
directory.

We are using ServiceMix 3.3.1 which has 2009.01 release of servicemix-file.
We downloaded 2009.02 from
http://mirrors.ibiblio.org/pub/mirrors/maven2/org/apache/servicemix/servicemix-file
and replaced the 2009.01 version in the hotdeploy folder. We also replaced
the servicemix-utils-1.1.0.jar in the lib folder with 1.2.0. However when
testing with a large number of message we still see this error. There are
still files left behind in the polled directory and we see the "unable to
acquire lock on ..." message in the log files.

Can you help us with this.

thanks and regards
Atit 

--
View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4483715.html
Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Arvind <am...@gmail.com>.
Sometimes File.exists() return false. This is a known issue which has been
raised since jdk 1.4 and has not been fixed yet. 
Details can be found at 
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=5003595
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=5003595 .

--
View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4583155.html
Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Arvind <am...@gmail.com>.
Hi All,

After going through the org.apache.servicemix.file.FilePollerEndPoint.java 

I found that inside the processFileNow method "aFile.exists()"  fails at
times, due to which the lock on the file is never gets released. 

I have verified this by adding the logger. 
http://servicemix.396122.n5.nabble.com/file/n4578634/sampleAppLog.log
sampleAppLog.log  contains the snapshot of the logs which highlights the
issue. Traverse the logs for the file "test_20110612200851_5281.txt".

Hence would like to propose the following code changes(*in bold*) in
FilePollerEndPoint.java. Kindly validate the same

 protected void processFileNow(File aFile) {
        try {
            if (logger.isDebugEnabled()) {
                logger.debug("Processing file " + aFile);
            }
            if (aFile.exists()) {
                processFile(aFile);
            } 
	   *//Proposed code change to fix the issue
	   else {
                if (logger.isDebugEnabled()) {
                    logger.debug("File Not found ..Releasing lock" + aFile);
                }
                unlockAsyncFile(aFile);
            }*
        } catch (Exception e) {
            logger.error("Failed to process file: " + aFile + ". Reason: " +
e, e);
            unlockAsyncFile(aFile);
        }
    }



--
View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4578634.html
Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Atit <at...@gmail.com>.
Hi All,

We ported the ServiceMix 3.3.1 code to ServiceMix 4.3 and were able to
simulate the same problem. I am unable to attach the log file because we
couldn't put ServiceMix 4.3 in debug mode. However i have attached the code
here for your reference 
http://servicemix.396122.n5.nabble.com/file/n4531921/SMX4.3_Sample.rar
SMX4.3_Sample.rar .

Thanks
Atit
[athoughtfactory.blogspot.com]

--
View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4531921.html
Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Jean-Baptiste Onofré <jb...@nanthrax.net>.
Hi Atit,

not yet but it's in my TODO list.

Regards
JB

On 06/21/2011 05:46 PM, Atit wrote:
> Hi All,
>
> I was wondering if you guys have been able to work on this and identify the
> issue. Is there anything i can help you with?
>
> regards
> Atit
>
> --
> View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4511092.html
> Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Atit <at...@gmail.com>.
Hi All,

I was wondering if you guys have been able to work on this and identify the
issue. Is there anything i can help you with?

regards
Atit 

--
View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4511092.html
Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Atit <at...@gmail.com>.
Hi,

We have stripped all of the proprietary code and have it uploaded here as 
http://servicemix.396122.n5.nabble.com/file/n4490848/sample-code.zip
sample-code.zip .

This code does the following:
1. Polls files from C:\Test\inbound
2. Processes the file - to emulate our business processing we have put a
delay of 6 seconds
3. Write the polled file to C:\Test\outbound\testOutput

We have reproduced this issue using this sample code, 2011.01 version of
servicemix-file and 1.2.1 version of servicemix-utils.

During the issue simulation, we saw there were around 8 files left behind -
files 2.txt through 9.txt. I Have attached the log file 
http://servicemix.396122.n5.nabble.com/file/n4490848/servicemix1_trimmed.log
servicemix.log .

I hope this helps you identify the issue. Let me know if you have any
questions.

Thanks
Atit
[http://athoughtfactory.blogspot.com]

--
View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4490848.html
Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Gert Vanthienen <ge...@gmail.com>.
L.S.,

If you're using the servicemix-camel JBI component shipped with
ServiceMix, you shouldn't have to deal with setting the DONE status
yourself - the component should handle that for you as soon as the
route ends.  Could you try removing all the proprietary code from the
camel route and just keeping the bare essentials around for us to
reproduce the issue?

Regards,

Gert Vanthienen
------------------------
FuseSource
Web: http://fusesource.com
Blog: http://gertvanthienen.blogspot.com/



On Tue, Jun 14, 2011 at 3:04 PM, Atit <at...@gmail.com> wrote:
> Hi Gert,
>
> Thanks for analyzing the log file.
> I did read this else where about having to set the status on the exchange
> object as either DONE or ERROR.  The endpoint
> ({http://myapplication}messageRouter) is custom coded camel route.
> Unfortunately i will not be able to share the code, but we have built it
> using  http://servicemix.apache.org/order-file-processing.html this example
> .
>
> Where do we set the status code? Should i be setting the status in the
> sender class in the custom write marshaller or in the processor? I will also
> need to write this in my error handler class?
>
> Is this the right way to set the status:
>
>
> import javax.annotation.Resource;
> import javax.jbi.messaging.DeliveryChannel;
> import javax.jbi.messaging.ExchangeStatus;
> import javax.jbi.messaging.InOnly;
>
> public class MyClass implements Processor {
>
>    @Resource
>    private DeliveryChannel channel;
>
>   public void process(final Exchange exchange) throws Exception {
>
>            //my application code
>
>            InOnly exchangeMsg =
> channel.createExchangeFactory().createInOnlyExchange();
>            exchangeMsg.setStatus(ExchangeStatus.DONE);
>            channel.send(exchangeMsg);
>   }
> }
>
> --
> View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4487741.html
> Sent from the ServiceMix - Dev mailing list archive at Nabble.com.
>

Re: SMXCOMP-594: persists in 2009.02

Posted by Atit <at...@gmail.com>.
Hi Gert,

Thanks for analyzing the log file.
I did read this else where about having to set the status on the exchange
object as either DONE or ERROR.  The endpoint
({http://myapplication}messageRouter) is custom coded camel route. 
Unfortunately i will not be able to share the code, but we have built it
using  http://servicemix.apache.org/order-file-processing.html this example
.

Where do we set the status code? Should i be setting the status in the
sender class in the custom write marshaller or in the processor? I will also
need to write this in my error handler class?

Is this the right way to set the status:


import javax.annotation.Resource;
import javax.jbi.messaging.DeliveryChannel;
import javax.jbi.messaging.ExchangeStatus;
import javax.jbi.messaging.InOnly;

public class MyClass implements Processor {

    @Resource
    private DeliveryChannel channel;

   public void process(final Exchange exchange) throws Exception {
            
            //my application code
         
            InOnly exchangeMsg =
channel.createExchangeFactory().createInOnlyExchange(); 
            exchangeMsg.setStatus(ExchangeStatus.DONE);
            channel.send(exchangeMsg);
   }
}

--
View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4487741.html
Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Gert Vanthienen <ge...@gmail.com>.
Atit,


Browsing through the log, it looks like the exchanges are not being
handled (properly) by the target endpoint.  If you look at the log...
- there's a 'Processing file
C:\myapplication\inbound\MSG_NW_DAN_ERR1_NoPID1.txt' nearly at the top
of the log, that's where the poller notices the file and sends it to
the ESB
- the message exchange is being sent right after that, it's currently
in status ACTIVE, however, there never is a DONE exchange in the log,
so that means that the exchange is still 'pending' or being processed
- because the exchange is still pending, the lock on the file is held
to avoid processing the same file twice and that's why you get 'Unable
to acquire lock on
C:\myapplication\inbound\MSG_NW_DAN_ERR1_NoPID1.txt'

The problem here is in the target endpoint, that is either very slow
in handling the exchange (i.e. it fails to handle the exchange before
the next run of the poller) or it never properly ends the message
exchange (e.g. it never sends back the DONE status).  What kind of
endpoint is that ({http://myapplication}messageRouter)?  If it is
something you coded (e.g. in a bean or through a camel route), could
you send along the code so we can help you figure out where things go
wrong?


Regards,

Gert Vanthienen
------------------------
FuseSource
Web: http://fusesource.com
Blog: http://gertvanthienen.blogspot.com/



On Tue, Jun 14, 2011 at 1:40 PM, Atit <at...@gmail.com> wrote:
> Hi,
>
> To save you some time, i have been able to simulate this issue on 2011.01
> version of the service-file as well. [note: I had upgraded the utility.jar
> to 1.2.0]. I have attached the log file. you may want to ignore things that
> say "my applications process" - i had to mask off our business processing
> and references.
>
> Let me know if this helps.
>
> thanks and regards
> Atit
> http://servicemix.396122.n5.nabble.com/file/n4487563/06142011_2011-01version_masked.log
> 06142011_2011-01version_masked.log
>
> --
> View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4487563.html
> Sent from the ServiceMix - Dev mailing list archive at Nabble.com.
>

Re: SMXCOMP-594: persists in 2009.02

Posted by Atit <at...@gmail.com>.
Hi,

To save you some time, i have been able to simulate this issue on 2011.01
version of the service-file as well. [note: I had upgraded the utility.jar
to 1.2.0]. I have attached the log file. you may want to ignore things that
say "my applications process" - i had to mask off our business processing
and references.

Let me know if this helps.

thanks and regards
Atit
http://servicemix.396122.n5.nabble.com/file/n4487563/06142011_2011-01version_masked.log
06142011_2011-01version_masked.log  

--
View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4487563.html
Sent from the ServiceMix - Dev mailing list archive at Nabble.com.

Re: SMXCOMP-594: persists in 2009.02

Posted by Jean-Baptiste Onofré <jb...@nanthrax.net>.
Hi Atit,

thanks for the update. I will make a try on 2011.01 components and I 
will reopen the Jira if the issue is still there.

Regards
JB

On 06/13/2011 10:49 AM, Atit wrote:
> Hi,
>
> SMXCOMP-594 refers to the defect where ServiceMix is "Unable to acquire lock
> on .... " a file during file polling. When ServiceMix polls files from a
> directory, it fails to read some files and leaves them behind in the
> directory. But will continues to read any other files dropped in the
> directory.
>
> We are using ServiceMix 3.3.1 which has 2009.01 release of servicemix-file.
> We downloaded 2009.02 from
> http://mirrors.ibiblio.org/pub/mirrors/maven2/org/apache/servicemix/servicemix-file
> and replaced the 2009.01 version in the hotdeploy folder. We also replaced
> the servicemix-utils-1.1.0.jar in the lib folder with 1.2.0. However when
> testing with a large number of message we still see this error. There are
> still files left behind in the polled directory and we see the "unable to
> acquire lock on ..." message in the log files.
>
> Can you help us with this.
>
> thanks and regards
> Atit
>
> --
> View this message in context: http://servicemix.396122.n5.nabble.com/SMXCOMP-594-persists-in-2009-02-tp4483715p4483715.html
> Sent from the ServiceMix - Dev mailing list archive at Nabble.com.