cxf-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sergey Beryozkin (JIRA)" <>
Subject [jira] [Commented] (CXF-6930) Race-Condition with JMS-transport, LoggingInInterceptor spoils the payload while logging it
Date Fri, 25 Nov 2016 14:16:58 GMT


Sergey Beryozkin commented on CXF-6930:

I believe Dan had fixed it, can you try 3.1.8 please ?

> Race-Condition with JMS-transport, LoggingInInterceptor spoils the payload while logging
> -------------------------------------------------------------------------------------------
>                 Key: CXF-6930
>                 URL:
>             Project: CXF
>          Issue Type: Bug
>          Components: JMS
>    Affects Versions: 3.1.6
>            Reporter: Tobias Schöneberg
>             Fix For: 3.1.8
> Hi,
> I think we stumbled over a problem with cxf and the JMS-transport, 
> if the {{LoggingFeature}} is used to log incoming response messages.
> The problem is that sometimes, {{ClientProxyImpl.invoke(...)}} returns {{null}}, 
> but from the logged message payload, it's clear that there is a not-null response payload
coming from the sever.
> I believe, I just figured out that it is in fact the logging of that very payload which
causes {{ClientProxyImpl.invoke(...)}} to return {{null}}.
> How?
> There is a race between the actual "client thread" which waited for the server's response

> (i.e. {{exchange.wait()}} in {{JMSConduit.sendAndReceiveMessage(...)}} ) 
> until notified by the ActiveMQ Session Task thread 
> (i.e. {{exchange.notifyAll()}} in {{JMSConduit.processReplyMessage(...)}} )
> one one side and the ActiveMQ Session Task thread itself on the other side.
> Once the client thread is notified, it goes on with {{preProcessResult(...)}} and {{handleResponse(...)}}
and somewhere in there the message's {{ByteArrayStream}} is read and the return object is
> However, at the same time, back in the ActiveMQ thread, the interceptor chain is run.

> In my case it contains the {{LoggingInInterceptor}} which accesses the message's *same*
{{ByteArrayInputStream}}, in the method {{LoggingInInterceptor.logInputStream(...)}} ).
> Now, in {{logInputStream(...)}}, we have
> {code:java}
> IOUtils.copyAtLeast(bis, bos, limit == -1 ? Integer.MAX_VALUE : limit);
> bos.flush();
> bis = new SequenceInputStream(bos.getInputStream(), bis);
> // restore the delegating input stream or the input stream
> if (is instanceof DelegatingInputStream) {
>     ((DelegatingInputStream)is).setInputStream(bis);
> } else {
>     message.setContent(InputStream.class, bis);
> }
> {code}
> My problem happens if the client thread tries to read the message while "{{bis}}" was
read, but not yet restored. During that time, "{{bis}}" is closed for the in the client thread
and it will skip over it (or throw an Exception, based on its config).
> My current best and maybe naive guess on how to solve this is to change the method {{JMSConduit.processReplyMessage(...)}}

> and execute the if-block around {{exchange.notifyAll();}} only after the if-block around
> Best reagards
> Tobias

This message was sent by Atlassian JIRA

View raw message