cxf-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Tobias Schöneberg (JIRA) <j...@apache.org>
Subject [jira] [Commented] (CXF-6930) Race-Condition with JMS-transport, LoggingInInterceptor spoils the payload while logging it
Date Thu, 08 Dec 2016 05:53:58 GMT

    [ https://issues.apache.org/jira/browse/CXF-6930?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15731211#comment-15731211
] 

Tobias Schöneberg commented on CXF-6930:
----------------------------------------

sorry, didn't get to it yet. it's high in my backlog

> Race-Condition with JMS-transport, LoggingInInterceptor spoils the payload while logging
it
> -------------------------------------------------------------------------------------------
>
>                 Key: CXF-6930
>                 URL: https://issues.apache.org/jira/browse/CXF-6930
>             Project: CXF
>          Issue Type: Bug
>          Components: JMS
>    Affects Versions: 3.1.6
>            Reporter: Tobias Schöneberg
>            Assignee: Daniel Kulp
>             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
created.
> 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
{{incomingObserver.onMessage(exchange.getInMessage());}}
> WDYT?
> Best reagards
> Tobias



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message