Feature kb 390 better exception logging for dispatch with exception handling #406
Conversation
|
Example stack trace for a timeout of the Billingrecord Plugin 2015-10-09 17:43:06,605 [qtp1169015699-27] ERROR o.k.b.payment.core.ProcessorBase - TimeoutException during the execution of plugin killbill-billingrecord with requestId de1a26d6-482d-4095-b691-7d44a1b87764 |
|
Example logging for the routing plugin: 2015-10-09 18:04:22,808 [qtp1169015699-35] ERROR o.k.b.p.c.sm.OperationCallbackBase - TimeoutException while executing the plugin(s) killbill-psp-routing, killbill-psp-preprocessor with requestId e0be2cbc-52f4-456b-ac72-bc97fa495086 |
| } else { | ||
| requestId = "NotAvailableRequestId"; | ||
| } | ||
|
|
There was a problem hiding this comment.
We could use a one-liner here:
final String requestId = Request.getPerThreadRequestData() != null ? Request.getPerThreadRequestData().getRequestId() : "NotAvailableRequestId";
Also i am confused with the following:
- Why don't we pass null (@nullable) and do the mapping to
NotAvailableRequestIdat the time we need it? - Why do we need to get the requestId in this method if we don't use it here? Since this is a ThreadLocal we should extract the value where it is needed
There was a problem hiding this comment.
I agree. Therefore I moved the retrieval of the requestId to the places to the method where it is actually used and removed it here.
|
Would be nice to see a test case where this exception is generated and verify we see both the pluginName and the requestId. |
|
Hi Stephane, I pushed the changes I did regarding your comments. Tomorrow I will write an test for this feature and I will add the request id to the general logging. |
|
Hi Stephane, at the moment I am writing a test to check the expected log messages in the case of an timeout. You asked me to check for the exception, but most of the time I haven't changed the exception in any way, I have just added the logging. I seems that reading the logging from test is not so straightforward especially if you don't want to change the logging framework. We are using slf4j-simple for that in tests. The question is in which direction should we go. Should I try to create a test that checks the logging or should I completely change the way a report the error and put everything into the exception. But that would also not so easy, because unwrapExceptionFromDispatchedTask for example just get its information about the exception from the PaymentStateContext and I am not sure if we want to change that. What do you think? |
|
Just to give an update to yesterday's comment. I decided to create some testing support for logging messages. I wrote a first test that tests the logging for creating payment. Tomorrow I will have a look how I can reach the code paths that aren't tested yet. |
| @@ -79,6 +80,13 @@ protected void logAPICall(final String transactionType, final Account account, f | |||
| logLine.append(", currency = ") | |||
| .append(currency); | |||
| } | |||
|
|
|||
| final String requestId = Request.getPerThreadRequestData() != null | |||
There was a problem hiding this comment.
Let's actually get rid of all requestId logging (here and below). I've opened #409 for tracking (we should really use the user token instead, which follows bus events and notifications).
There was a problem hiding this comment.
I am not sure if I understand it correctly. How is the userToken normally filled? Is that something that happens completely on behalf of the client? So, Groupon could for example decide to put the request id into userToken? I am just wondering how we enable them to analyze cross application requests in the future, because I convinced that they don't want to lose this ability.
There was a problem hiding this comment.
At the killbill-api level, the user token is created by the client and passed in the call context. At the JAX-RS level, it is automatically generated for the client.
#409 is about setting the user token to the request id, if specified.
| for (final String pluginName : paymentControlPluginNames) { | ||
| final PaymentControlPluginApi plugin = paymentControlPluginRegistry.getServiceForName(pluginName); | ||
| if (plugin != null) { | ||
| try { | ||
| log.info("Calling onSuccessCall of plugin {} for requestId {}", pluginName, requestId); |
|
Could you also squash and rebase? It looks like there are merge conflicts. |
…dispatchWithExceptionHandling
… dispatcher and when control plugins are called
…or TimeoutException
holkra
force-pushed
the
feature_KB-390-better-exception-logging-for-dispatchWithExceptionHandling
branch
from
cd2a2fc
to
2a0064c
Compare
|
Thanks! I've fixed some trivial style issues and squashed the commits to simplify the history. |
No description provided.