[
https://issues.apache.org/jira/browse/CXF-9233?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18100970#comment-18100970
]
Valentino Porta edited comment on CXF-9233 at 8/1/26 3:41 PM:
--------------------------------------------------------------
I added a minimal spring-camel-cxf project.
([https://github.com/vp340/cxf-log-example] )
I wrote a simple example service and a camel route to proxy that service.
I add in test resources the SoapUI project and the wiremock configuration file
to run the backend if U want to simulate the bug locally.
CxfEndpoint(Server) -> Camel -> CxfEndpointBE (BackEnd client)
In both I add the default logging feature.
If U go in debug mode in the handleMessage() method of LoggingOutInteceptor
...during RESP_OUT... U will see that the LIVE_LOGGING_PROP = false is already
there and so the RESP_OUT log will be ignored.
I tryed to track back the problem. I notice that after RESP_IN (where the
'false' prop is set for RESP_IN flow) ... camel has that very prop in
Exchange.getIn.getHeaders.get("ResponseContext") ... so there is something that
propagate the headers into the Message RESP_OUT properties ( I assume ).
(If .to() is the last istruction... camel copies all the IN into the OUT,
...the the OUT headers are propagated into Message props).
Instead ...if I add a camel processor that does:
exchange.getOut().setBody(exchange.getIn().getBody());
The problem vanish and the RESP_OUT log reapper cause the LIVE_LOGGING_PROP
isn't propagated!
I understand that the this is not a cxf problem itself ... but It's a silent
error-prone situation (the service itself works fine even without that
processor).
Adding the IDEMPOTENT_LOGGING_PROP can be "confusing", but so is not finding
the RESP_OUT log :( because a generic property has already been set somewhere
else and the framework propagates it, if U don't manually intervene .
My goal with the IDEMPOTENT_LOGGING_PROP was to fullfill the use case "not log
twice" without using the same property used to disable completely the log from
the Bus (and that can lead to these sneaky situations :D) .
In my project it worked fine without adding manual processor.
P.S.
The fact that RESP_IN properties are propagated to RESP_OUT Message maybe can
lead to other problems than the ghost logging!
I don't have any evidence to other 'bug' due to this, but It may be useful to
explore this further.
Thank you.
Good work!
Valentino Porta
was (Author: JIRAUSER314106):
I added a zip with a minimal spring-camel-cxf project.
I wrote a simple example service and a camel route to proxy that service.
I add in test resources the SoapUI project and the wiremock configuration file
to run the backend if U want to simulate the bug locally.
CxfEndpoint(Server) -> Camel -> CxfEndpointBE (BackEnd client)
In both I add the default logging feature.
If U go in debug mode in the handleMessage() method of LoggingOutInteceptor
...during RESP_OUT... U will see that the LIVE_LOGGING_PROP = false is already
there and so the RESP_OUT log will be ignored.
I tryed to track back the problem. I notice that after RESP_IN (where the
'false' prop is set for RESP_IN flow) ... camel has that very prop in
Exchange.getIn.getHeaders.get("ResponseContext") ... so there is something that
propagate the headers into the Message RESP_OUT properties ( I assume ).
(If .to() is the last istruction... camel copies all the IN into the OUT,
...the the OUT headers are propagated into Message props).
Instead ...if I add a camel processor that does:
exchange.getOut().setBody(exchange.getIn().getBody());
The problem vanish and the RESP_OUT log reapper cause the LIVE_LOGGING_PROP
isn't propagated!
I understand that the this is not a cxf problem itself ... but It's a silent
error-prone situation (the service itself works fine even without that
processor).
Adding the IDEMPOTENT_LOGGING_PROP can be "confusing", but so is not finding
the RESP_OUT log :( because a generic property has already been set somewhere
else and the framework propagates it, if U don't manually intervene .
My goal with the IDEMPOTENT_LOGGING_PROP was to fullfill the use case "not log
twice" without using the same property used to disable completely the log from
the Bus (and that can lead to these sneaky situations :D) .
In my project it worked fine without adding manual processor.
P.S.
The fact that RESP_IN properties are propagated to RESP_OUT Message maybe can
lead to other problems than the ghost logging!
I don't have any evidence to other 'bug' due to this, but It may be useful to
explore this further.
Thank you.
Good work!
Valentino Porta
> AbstractLoggingInterceptor.LIVE_LOGGING_PROP already set in the message
> properties, so RESP_OUT log is disable :(
> -------------------------------------------------------------------------------------------------------------------
>
> Key: CXF-9233
> URL: https://issues.apache.org/jira/browse/CXF-9233
> Project: CXF
> Issue Type: Improvement
> Components: logging
> Reporter: Valentino Porta
> Priority: Minor
> Labels: cxf, logging
>
> Hi there,
> I would like to point out a possible improvement within the cxf default
> logging module.
> I'm currently working on a custom logging library based on apache cxf, but I
> notice a strange behaviour with the use of the property
> AbstractLoggingInterceptor.LIVE_LOGGING_PROP =
> "org.apache.cxf.logging.enable";
>
> According to the comments and documentation this properties is set to false
> when the Message enter the handleMessage() method in order to avoid double
> logging of the same flow (REQ_IN / REQ_OUT/...etc..) if an exception happen
> in subsequent phases of the cxf chain. (rewind calls) .
>
> The 'problem' is that if this properties is already present in the Message
> (propagated or copied form other previous Message) the log doesn't happen at
> all!
> I know that it's not a cxf bug itself, but how other manipulate the Message
> object, (in fact i open this issue as an improvement not a bug), but It could
> be a good idea to make this framework more resilient againt error or misuse
> of other framework.
>
> In my example we have a cxf-spring-camel configuration.
>
> CxfEndpoint(server) -> Camel Routes -> CxfEnpoint (backend client)
> REQ_IN/RESP_OUT --------------------> REQ_OUT/RESP_IN
>
> Going in debug mode I notice that the LIVE_LOGGING_PROP property set in
> RESP_IN flow stays in the Message and it's propagated to the Message passing
> through RESP_OUT, so the Interceptor doesn't log RESP_OUT thinking it has
> already log it and that is a (fake) rewind call.
>
> Maybe it's a Camel CxfProducer/CxfConsumer bug... (or more probably our
> internal bug with the management of camel routes)....
> Anyway It would be better if also cxf was idempotent per flow per ExchangeId
> against this this of issues. (logging once per each flow per each ExchangeId)
>
> I propose (if U don't see any other counter effect) to add to the
> LIVE_LOGGING_PROP the flow normalized (so only REQ_IN, REQ_OUT, RESP_IN,
> RESP_OUT) ...(FAULT_IN-> RESP_IN, FAULT_OUT-> RESP_OUT because conceptually
> they are the same flow) and also the ExchangeId.
>
> So the property will became LIVE_LOGGING_PROP + RESP_IN +'.' + ExchangeId...
> if rewind calls happend in the same flow (RESP_IN) and same ExchangeId... the
> log will not be logged twice.
> If in the RESP_OUT it happens to find other properties set from other flow /
> other exchangeId it ignores them.
>
> Note: I add also the ExchangeId because usually in an orchestrated service
> there is only 1 REQ_IN and 1 RESP_OUT... , but there could be N times
> REQ_OUTs and RESP_INs ... so adding the ExchangeId we can discern also those
> from other backend-client call!
>
> Let me know what U think about this solution. I'll implement this method in
> my project (based on the test I conducted right now it solved my problem with
> ghost RESP_OUT logging).
> I wanted to share this issue to help other developer that maybe had encounter
> the same situation.
> I will open a PR in case U find this solution suitable.
> Hope it helps!
>
> Have a great job!
>
> Valentino Porta
>
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
