0.8.12 NPE without stack trace when computing invoice
77 views
Skip to first unread message
Matt Magoffin
Jun 25, 2018, 6:17:11 PM6/25/18
to Kill Bill users mailing-list
Hello,
I am experiencing an odd NullPointerException when a specific invoice is getting generated. The logs contain messages like this:
-----
2018-06-25 19:03:43,743 [notifications-th] INFO o.k.b.i.g.FixedAndRecurringInvoiceItemGenerator - Proposed fixed items for invoiceId='28422a57-97f3-49b3-861b-a622b733249d', accountId='da79d513-0fc4-4dde-92c7-12ae7bf4cb88'
DefaultBillingEvent{type=CREATE, effectiveDate=2017-07-24T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=8d8962ef-fde9-46c7-b4b8-9888296e8cee, totalOrdering=111}
FIXED{startDate=2017-07-25, endDate=null, amount=0.00, rate=null, subscriptionId=8d8962ef-fde9-46c7-b4b8-9888296e8cee, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2016-05-02T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=a909e162-20a8-4c8a-9bb0-c7feefcba747, totalOrdering=105}
FIXED{startDate=2016-05-03, endDate=null, amount=0.00, rate=null, subscriptionId=a909e162-20a8-4c8a-9bb0-c7feefcba747, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2016-12-22T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=c29f7152-ac5b-455a-81fb-ed80af000ab8, totalOrdering=109}
FIXED{startDate=2016-12-23, endDate=null, amount=0.00, rate=null, subscriptionId=c29f7152-ac5b-455a-81fb-ed80af000ab8, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2016-11-03T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=f8f3854a-2553-4f1b-80c5-16583140abf6, totalOrdering=107}
FIXED{startDate=2016-11-04, endDate=null, amount=0.00, rate=null, subscriptionId=f8f3854a-2553-4f1b-80c5-16583140abf6, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2014-07-02T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=05518b8d-5547-4b7f-b0dc-15eb41e50c7f, totalOrdering=103}
FIXED{startDate=2014-07-03, endDate=null, amount=0.00, rate=null, subscriptionId=05518b8d-5547-4b7f-b0dc-15eb41e50c7f, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2017-08-16T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=6e1145b4-6649-4186-81ab-298f62f6bc3e, totalOrdering=113}
FIXED{startDate=2017-08-17, endDate=null, amount=0.00, rate=null, subscriptionId=6e1145b4-6649-4186-81ab-298f62f6bc3e, linkedItemId=null}
2018-06-25 19:03:43,782 [notifications-th] INFO o.k.q.d.CallableCallbackBase - Dispatch error, will attempt a retry
org.killbill.notificationq.NotificationQueueException: java.lang.NullPointerException
at org.killbill.notificationq.NotificationQueueDispatcher.handleNotificationWithMetrics(NotificationQueueDispatcher.java:205)
at org.killbill.notificationq.dispatching.NotificationCallableCallback.dispatch(NotificationCallableCallback.java:51)
at org.killbill.notificationq.dispatching.NotificationCallableCallback.dispatch(NotificationCallableCallback.java:32)
at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:103)
at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:86)
at org.killbill.commons.concurrent.WrappedCallable.call(WrappedCallable.java:42)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.killbill.commons.concurrent.WrappedRunnable.run(WrappedRunnable.java:48)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException: null
-----
Eventually, the system gives up with
-----
ERROR o.k.q.d.CallableCallbackBase - Fatal NotificationQ dispatch error, data corruption...
org.killbill.notificationq.NotificationQueueException: java.lang.NullPointerException
at org.killbill.notificationq.NotificationQueueDispatcher.handleNotificationWithMetrics(NotificationQueueDispatcher.java:205)
at org.killbill.notificationq.dispatching.NotificationCallableCallback.dispatch(NotificationCallableCallback.java:51)
at org.killbill.notificationq.dispatching.NotificationCallableCallback.dispatch(NotificationCallableCallback.java:32)
at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:103)
at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:86)
at org.killbill.commons.concurrent.WrappedCallable.call(WrappedCallable.java:42)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.killbill.commons.concurrent.WrappedRunnable.run(WrappedRunnable.java:48)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException: null
-----
This is Killbill version 0.8.12, using Killbill Commons 0.20.11, where line NotificationQueueDispatcher.java:205 is just a re-throw of the original exception. There is no stacktrace included with the NPE, however, so I am wondering a couple of things:
1) How might I best track down where that NPE is happening? This is a production system, so I am slightly constrained in what I can do to it.
2) Is there a way to get Killbill to re-try generating this invoice, now that it has given up re-trying?
Thanks for any help,
Matt
I am experiencing an odd NullPointerException when a specific invoice is getting generated. The logs contain messages like this:
-----
2018-06-25 19:03:43,743 [notifications-th] INFO o.k.b.i.g.FixedAndRecurringInvoiceItemGenerator - Proposed fixed items for invoiceId='28422a57-97f3-49b3-861b-a622b733249d', accountId='da79d513-0fc4-4dde-92c7-12ae7bf4cb88'
DefaultBillingEvent{type=CREATE, effectiveDate=2017-07-24T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=8d8962ef-fde9-46c7-b4b8-9888296e8cee, totalOrdering=111}
FIXED{startDate=2017-07-25, endDate=null, amount=0.00, rate=null, subscriptionId=8d8962ef-fde9-46c7-b4b8-9888296e8cee, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2016-05-02T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=a909e162-20a8-4c8a-9bb0-c7feefcba747, totalOrdering=105}
FIXED{startDate=2016-05-03, endDate=null, amount=0.00, rate=null, subscriptionId=a909e162-20a8-4c8a-9bb0-c7feefcba747, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2016-12-22T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=c29f7152-ac5b-455a-81fb-ed80af000ab8, totalOrdering=109}
FIXED{startDate=2016-12-23, endDate=null, amount=0.00, rate=null, subscriptionId=c29f7152-ac5b-455a-81fb-ed80af000ab8, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2016-11-03T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=f8f3854a-2553-4f1b-80c5-16583140abf6, totalOrdering=107}
FIXED{startDate=2016-11-04, endDate=null, amount=0.00, rate=null, subscriptionId=f8f3854a-2553-4f1b-80c5-16583140abf6, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2014-07-02T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=05518b8d-5547-4b7f-b0dc-15eb41e50c7f, totalOrdering=103}
FIXED{startDate=2014-07-03, endDate=null, amount=0.00, rate=null, subscriptionId=05518b8d-5547-4b7f-b0dc-15eb41e50c7f, linkedItemId=null}
DefaultBillingEvent{type=CREATE, effectiveDate=2017-08-16T19:02:31.000Z, planPhaseName=api-posted-datum-metric-monthly-usage-trial, subscriptionId=6e1145b4-6649-4186-81ab-298f62f6bc3e, totalOrdering=113}
FIXED{startDate=2017-08-17, endDate=null, amount=0.00, rate=null, subscriptionId=6e1145b4-6649-4186-81ab-298f62f6bc3e, linkedItemId=null}
2018-06-25 19:03:43,782 [notifications-th] INFO o.k.q.d.CallableCallbackBase - Dispatch error, will attempt a retry
org.killbill.notificationq.NotificationQueueException: java.lang.NullPointerException
at org.killbill.notificationq.NotificationQueueDispatcher.handleNotificationWithMetrics(NotificationQueueDispatcher.java:205)
at org.killbill.notificationq.dispatching.NotificationCallableCallback.dispatch(NotificationCallableCallback.java:51)
at org.killbill.notificationq.dispatching.NotificationCallableCallback.dispatch(NotificationCallableCallback.java:32)
at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:103)
at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:86)
at org.killbill.commons.concurrent.WrappedCallable.call(WrappedCallable.java:42)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.killbill.commons.concurrent.WrappedRunnable.run(WrappedRunnable.java:48)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException: null
-----
Eventually, the system gives up with
-----
ERROR o.k.q.d.CallableCallbackBase - Fatal NotificationQ dispatch error, data corruption...
org.killbill.notificationq.NotificationQueueException: java.lang.NullPointerException
at org.killbill.notificationq.NotificationQueueDispatcher.handleNotificationWithMetrics(NotificationQueueDispatcher.java:205)
at org.killbill.notificationq.dispatching.NotificationCallableCallback.dispatch(NotificationCallableCallback.java:51)
at org.killbill.notificationq.dispatching.NotificationCallableCallback.dispatch(NotificationCallableCallback.java:32)
at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:103)
at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:86)
at org.killbill.commons.concurrent.WrappedCallable.call(WrappedCallable.java:42)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.killbill.commons.concurrent.WrappedRunnable.run(WrappedRunnable.java:48)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException: null
-----
This is Killbill version 0.8.12, using Killbill Commons 0.20.11, where line NotificationQueueDispatcher.java:205 is just a re-throw of the original exception. There is no stacktrace included with the NPE, however, so I am wondering a couple of things:
1) How might I best track down where that NPE is happening? This is a production system, so I am slightly constrained in what I can do to it.
2) Is there a way to get Killbill to re-try generating this invoice, now that it has given up re-trying?
Thanks for any help,
Matt
Pierre-Alexandre Meyer
Jun 26, 2018, 7:38:08 AM6/26/18
to Matt Magoffin, Kill Bill users mailing-list
Hi Matt,
On Mon, Jun 25, 2018 at 3:17 PM, Matt Magoffin <ma...@solarnetwork.net> wrote:
1) How might I best track down where that NPE is happening? This is a production system, so I am slightly constrained in what I can do to it.
Could you try upgrading to the latest 0.18.20 release first? 0.18.12 is 1 year old already and there have been quite a few fixes since.
2) Is there a way to get Killbill to re-try generating this invoice, now that it has given up re-trying?
Yes, by using the POST /1.0/kb/invoices endpoint (https://github.com/killbill/killbill/blob/499a2d39278decc42f27a8d5dac43890f15126a5/jaxrs/src/main/java/org/killbill/billing/jaxrs/resources/InvoiceResource.java#L294-L320). This is also available in Kaui, on the main account screen.
Pierre
Matt Magoffin
Jun 26, 2018, 5:00:54 PM6/26/18
to Pierre-Alexandre Meyer, Kill Bill users mailing-list
Hi Pierre,
I had the same thought of upgrading, so I’ve done that now to 0.8.20. I am getting this stack trace how:
java.lang.NullPointerException: null
at org.killbill.billing.invoice.usage.ContiguousIntervalUsageInArrear.getRolledUpUsage(ContiguousIntervalUsageInArrear.java:267)
at org.killbill.billing.invoice.usage.ContiguousIntervalUsageInArrear.computeMissingItemsAndNextNotificationDate(ContiguousIntervalUsageInArrear.java:184)
at org.killbill.billing.invoice.usage.SubscriptionUsageInArrear.computeMissingUsageInvoiceItems(SubscriptionUsageInArrear.java:115)
at org.killbill.billing.invoice.generator.UsageInvoiceItemGenerator.generateItems(UsageInvoiceItemGenerator.java:134)
at org.killbill.billing.invoice.generator.DefaultInvoiceGenerator.generateInvoice(DefaultInvoiceGenerator.java:87)
at org.killbill.billing.invoice.InvoiceDispatcher.processAccountWithLockAndInputTargetDate(InvoiceDispatcher.java:473)
at org.killbill.billing.invoice.InvoiceDispatcher.processDryRun_TARGET_DATE_Invoice(InvoiceDispatcher.java:423)
at org.killbill.billing.invoice.InvoiceDispatcher.processAccountWithLock(InvoiceDispatcher.java:333)
at org.killbill.billing.invoice.InvoiceDispatcher.processAccount(InvoiceDispatcher.java:250)
at org.killbill.billing.invoice.api.user.DefaultInvoiceUserApi.triggerInvoiceGeneration(DefaultInvoiceUserApi.java:215)
at org.killbill.billing.util.glue.KillbillApiAopModule$ProfilingMethodInterceptor$1.execute(KillbillApiAopModule.java:52)
at org.killbill.commons.profiling.Profiling.executeWithProfiling(Profiling.java:33)
at org.killbill.billing.util.glue.KillbillApiAopModule$ProfilingMethodInterceptor.invoke(KillbillApiAopModule.java:49)
at org.killbill.billing.util.security.AopAllianceMethodInvocationAdapter.proceed(AopAllianceMethodInvocationAdapter.java:45)
at org.apache.shiro.authz.aop.AuthorizingAnnotationMethodInterceptor.invoke(AuthorizingAnnotationMethodInterceptor.java:68)
at org.killbill.billing.util.security.AopAllianceMethodInterceptorAdapter.invoke(AopAllianceMethodInterceptorAdapter.java:32)
at org.killbill.billing.jaxrs.resources.InvoiceResource.generateDryRunInvoice(InvoiceResource.java:399)
at org.killbill.commons.skeleton.metrics.TimedResourceInterceptor.invoke(TimedResourceInterceptor.java:69)
which I haven’t looked into yet, but thought you might have a clue faster than me?
Cheers,
Matt
stephane brossier
Jun 26, 2018, 5:20:40 PM6/26/18
to Matt Magoffin, Pierre-Alexandre Meyer, Kill Bill users mailing-list
Matt,
It probably means that the code expectation either does not match your data or you catalog config. Since we don't have access to any of those, this will be difficult. If you could set a breakpoint and provide more info, maybe we could help further.
Stéphane
--
You received this message because you are subscribed to the Google Groups "Kill Bill users mailing-list" group.
To unsubscribe from this group and stop receiving emails from it, send an email to killbilling-users+unsubscribe@googlegroups.com.
To post to this group, send email to killbilling-users@googlegroups.com.
Visit this group at https://groups.google.com/group/killbilling-users.
To view this discussion on the web visit https://groups.google.com/d/msgid/killbilling-users/C3E0340E-B306-4561-AD4D-F353E27F1BC9%40solarnetwork.net.
Matt Magoffin
Jun 26, 2018, 5:21:14 PM6/26/18
to Pierre-Alexandre Meyer, Kill Bill users mailing-list
I was able to debug this NPE, and found that on line 267 the prevRawUsage variable was null. The rawUsageIterator was from a list with one item in it:
[DefaultRawUsage{subscriptionId=6e1145b4-6649-4186-81ab-298f62f6bc3e, recordDate=2017-08-17, unitType='DatumMetrics', amount=22}]
and transitionTimes contains
[2017-09-16, 2017-10-01]
and I was requesting an invoice for the target date of 2017-10-01.
Does this help?
Cheers,
Matt
Matt Magoffin
Jun 26, 2018, 6:00:51 PM6/26/18
to stephane brossier, Pierre-Alexandre Meyer, Kill Bill users mailing-list
I was able to solve the NPE with this change:
I have to test out this change on the server in question still, however. Would you like a PR for this?
— m@
Matt Magoffin
Jun 26, 2018, 6:33:23 PM6/26/18
to stephane brossier, Pierre-Alexandre Meyer, Kill Bill users mailing-list
I tested out this fix on the server in question, and it has allowed the invoice to be generated without the NPE now.
I’m happy to submit a PR with that commit if you like.
— m@
stephane brossier
Jun 26, 2018, 9:30:49 PM6/26/18
to Matt Magoffin, Pierre-Alexandre Meyer, Kill Bill users mailing-list
Matt,
Your fix looks good - if you want to submit the PR, i 'll merge it and create a release for you.
Thanks for the debugging and quick fix.
Stéphane
Matt Magoffin
Jun 26, 2018, 10:19:59 PM6/26/18
to stephane brossier, Pierre-Alexandre Meyer, Kill Bill users mailing-list
stephane brossier
Jun 27, 2018, 1:45:40 PM6/27/18
to Matt Magoffin, Pierre-Alexandre Meyer, Kill Bill users mailing-list
fyi: Release 0.18.21 created with the fix.
Matt Magoffin
Jun 27, 2018, 4:55:19 PM6/27/18
to stephane brossier, Pierre-Alexandre Meyer, Kill Bill users mailing-list
Excellent, thank you!
— m@
— m@
Reply all
Reply to author
Forward
0 new messages