Valentino Porta created CXF-9233:
------------------------------------
Summary: 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
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)
