Email plugin error

[gokha...@gmail.com]

Hello,

I am using email plugin to send email to our customers.

But, I see that some of email were sent successfully, some of not, although there is no difference between them and I don't understand this situation.

Does anyone have any guess?

- Does error customer's parameter wrong?

- Does customer's email properties different?

What should I do ?

 

I am sharing some examples. 

1. Email sent successful; 

2021-08-25T21:58:42,791+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1169', tRId='312', Sending email to = [s***1...@gmail.com], cc= admin@r***r.com, r***r@s***s.net.au, subject = *** 25/08/2021 - 31/08/2021  *** ID: ***** body = [

***

From: *** ***

*** ***: *****

To: *** ***

*** ***: *** *** ***

*** ***, *** ***

***: ***

***: 25/08/2021 - 31/08/2021

***: $***

Need help? Email admin@r***r.com

r***r.com

*** ** ** *** ***

***: ***]

2021-08-25T21:58:42,792+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1169', tRId='312', EmailSender configured with serverName = email-smtp.us-west-2.amazonaws.com, serverPort = 587, from = admin@r***r.com, logOnly = false

2021-08-25T21:58:42,792+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1169', tRId='312', Sending email to [s***1...@gmail.com], cc [admin@r***r.com, r***r@s***s.net.au], subject *** 25/08/2021 - 31/08/2021  *** ID: ******

2021-08-25T21:58:42,870+0000 lvl='INFO', log='DefaultPaymentApi', th='Timer-0', xff='', rId='', tok='', aRId='924', tRId='320', ENTERING PaymentApi: transactionType='NOTIFY_STATE_CHANGE', accountId='**', transactionId='***', paymentControlPluginNames='__INVOICE_PAYMENT_CONTROL_PLUGIN__'

2. Email sent unsuccessful;

2021-08-24T22:13:46,609+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='902', tRId='345', Sending email to = [e***0...@gmail.com], cc= admin@r***r.com, f***n...@live.com, subject = *** 23/08/2021 - 05/09/2021  *** ID: ****** body = [

***

From: *** ***

*** ***: ***

To: *** ***

*** ***: ***

***, *** ***

***: ***

***: 23/08/2021 - 05/09/2021

***: $***

Need help? Email admin@R***r.com

R***r.com

*** *** ** * ***

***: ***]

2021-08-24T22:13:46,611+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='902', tRId='345', EmailSender configured with serverName = email-smtp.us-west-2.amazonaws.com, serverPort = 587, from = admin@r***r.com, logOnly = false

2021-08-24T22:13:46,611+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='902', tRId='345', Sending email to [e***0...@gmail.com], cc [admin@r***r.com, f***n...@live.com], subject *** 23/08/2021 - 05/09/2021  *** ID: ******

2021-08-24T22:13:47,356+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='792', tRId='319', Received event INVOICE_PAYMENT_SUCCESS for object type = INVOICE, id = ***

2021-08-24T22:13:48,580+0000 lvl='WARN', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='902', tRId='345', Fail to send email for account ***

org.apache.felix.log.LogException: org.apache.commons.mail.EmailException: Sending the email to the following server failed : email-smtp.us-west-2.amazonaws.com:587

        at org.apache.commons.mail.Email.sendMimeMessage(Email.java:1242)

        at org.apache.commons.mail.Email.send(Email.java:1267)

        at org.killbill.billing.plugin.notification.email.EmailSender.sendEmail(EmailSender.java:182)

        at org.killbill.billing.plugin.notification.email.EmailSender.sendPlainTextEmail(EmailSender.java:135)

        at org.killbill.billing.plugin.notification.setup.EmailNotificationListener.sendEmail(EmailNotificationListener.java:362)

        at org.killbill.billing.plugin.notification.setup.EmailNotificationListener.sendEmailForPayment(EmailNotificationListener.java:336)

        at org.killbill.billing.plugin.notification.setup.EmailNotificationListener.handleKillbillEvent(EmailNotificationListener.java:195)

        at org.killbill.billing.osgi.libs.killbill.OSGIKillbillEventDispatcher$1.handleKillbillEvent(OSGIKillbillEventDispatcher.java:96)

        at org.killbill.billing.osgi.libs.killbill.OSGIKillbillEventDispatcher$1.update(OSGIKillbillEventDispatcher.java:82)

        at org.killbill.billing.osgi.KillbillEventObservable.notifyObservers(KillbillEventObservable.java:38)

        at org.killbill.billing.osgi.KillbillEventObservable.setChangedAndNotifyObservers(KillbillEventObservable.java:44)

        at org.killbill.billing.osgi.KillbillEventRetriableBusHandler$1.run(KillbillEventRetriableBusHandler.java:82)

        at org.killbill.billing.osgi.KillbillEventRetriableBusHandler$1.run(KillbillEventRetriableBusHandler.java:77)

        at org.killbill.queue.retry.RetryableSubscriber$SubscriberQueueHandler.handleReadyNotification(RetryableSubscriber.java:94)

        at org.killbill.queue.retry.RetryableService$1.handleReadyNotification(RetryableService.java:87)

        at org.killbill.notificationq.NotificationQueueDispatcher.handleNotificationWithMetrics(NotificationQueueDispatcher.java:200)

        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:114)

        at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:87)

        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: org.apache.felix.log.LogException: javax.mail.AuthenticationFailedException: null

        at javax.mail.Service.connect(Service.java:319)

        at javax.mail.Service.connect(Service.java:169)

        at javax.mail.Service.connect(Service.java:118)

        at javax.mail.Transport.send0(Transport.java:188)

        at javax.mail.Transport.send(Transport.java:118)

        at org.apache.commons.mail.Email.sendMimeMessage(Email.java:1232)

        ... 25 common frames omitted

2021-08-24T22:13:48,580+0000 lvl='WARN', log='RetryableService', th='notifications-th', xff='', rId='', tok='', aRId='902', tRId='345', Error processing event, scheduling retry for event='SubscriberNotificationEvent{busEvent=OSGIBusEvent{extBusEvent=DefaultBusExternalEvent{objectId=***, accountId=***, tenantId=***, objectType=INVOICE, eventType=INVOICE_PAYMENT_SUCCESS}, extBusEventClass=class org.killbill.billing.beatrix.extbus.DefaultBusExternalEvent}, busEventClass=class org.killbill.billing.osgi.KillbillEventRetriableBusHandler$OSGIBusEvent}', effectiveDate='2021-08-24T22:58:44.000Z', retryNb='3'

org.killbill.billing.notification.plugin.api.NotificationPluginApiRetryException: org.apache.commons.mail.EmailException: Sending the email to the following server failed : email-smtp.us-west-2.amazonaws.com:587

        at org.killbill.billing.plugin.notification.setup.EmailNotificationListener.handleKillbillEvent(EmailNotificationListener.java:226)

        at org.killbill.billing.osgi.libs.killbill.OSGIKillbillEventDispatcher$1.handleKillbillEvent(OSGIKillbillEventDispatcher.java:96)

        at org.killbill.billing.osgi.libs.killbill.OSGIKillbillEventDispatcher$1.update(OSGIKillbillEventDispatcher.java:82)

        at org.killbill.billing.osgi.KillbillEventObservable.notifyObservers(KillbillEventObservable.java:38)

        at org.killbill.billing.osgi.KillbillEventObservable.setChangedAndNotifyObservers(KillbillEventObservable.java:44)

        at org.killbill.billing.osgi.KillbillEventRetriableBusHandler$1.run(KillbillEventRetriableBusHandler.java:82)

        at org.killbill.billing.osgi.KillbillEventRetriableBusHandler$1.run(KillbillEventRetriableBusHandler.java:77)

        at org.killbill.queue.retry.RetryableSubscriber$SubscriberQueueHandler.handleReadyNotification(RetryableSubscriber.java:94)

        at org.killbill.queue.retry.RetryableService$1.handleReadyNotification(RetryableService.java:87)

        at org.killbill.notificationq.NotificationQueueDispatcher.handleNotificationWithMetrics(NotificationQueueDispatcher.java:200)

        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:114)

        at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:87)

        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: org.apache.commons.mail.EmailException: Sending the email to the following server failed : email-smtp.us-west-2.amazonaws.com:587

        at org.apache.commons.mail.Email.sendMimeMessage(Email.java:1242)

        at org.apache.commons.mail.Email.send(Email.java:1267)

        at org.killbill.billing.plugin.notification.email.EmailSender.sendEmail(EmailSender.java:182)

        at org.killbill.billing.plugin.notification.email.EmailSender.sendPlainTextEmail(EmailSender.java:135)

        at org.killbill.billing.plugin.notification.setup.EmailNotificationListener.sendEmail(EmailNotificationListener.java:362)

        at org.killbill.billing.plugin.notification.setup.EmailNotificationListener.sendEmailForPayment(EmailNotificationListener.java:336)

        at org.killbill.billing.plugin.notification.setup.EmailNotificationListener.handleKillbillEvent(EmailNotificationListener.java:195)

        ... 19 common frames omitted

Caused by: javax.mail.AuthenticationFailedException: null

        at javax.mail.Service.connect(Service.java:319)

        at javax.mail.Service.connect(Service.java:169)

        at javax.mail.Service.connect(Service.java:118)

        at javax.mail.Transport.send0(Transport.java:188)

        at javax.mail.Transport.send(Transport.java:118)

        at org.apache.commons.mail.Email.sendMimeMessage(Email.java:1232)

        ... 25 common frames omitted

2021-08-24T22:15:04,620+0000 lvl='ERROR', log='CallableCallbackBase', th='notifications-th', xff='', rId='', tok='a082a420-0cf0-4dc6-abca-bb3a1ec3ad1f', aRId='545', tRId='210', Fatal NotificationQ dispatch error, data corruption...

org.killbill.notificationq.NotificationQueueException: java.lang.NullPointerException

        at org.killbill.notificationq.NotificationQueueDispatcher.handleNotificationWithMetrics(NotificationQueueDispatcher.java:202)

        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:114)

        at org.killbill.queue.dispatching.Dispatcher$CallableQueue.call(Dispatcher.java:87)

        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

        at org.killbill.billing.subscription.engine.dao.DefaultSubscriptionDao$8.inTransaction(DefaultSubscriptionDao.java:359)

        at org.killbill.billing.subscription.engine.dao.DefaultSubscriptionDao$8.inTransaction(DefaultSubscriptionDao.java:355)

        at org.killbill.billing.util.entity.dao.EntitySqlDaoTransactionalJdbiWrapper$JdbiTransaction.inTransaction(EntitySqlDaoTransactionalJdbiWrapper.java:74)

        at org.killbill.billing.util.entity.dao.EntitySqlDaoTransactionalJdbiWrapper$JdbiTransaction.inTransaction(EntitySqlDaoTransactionalJdbiWrapper.java:61)

        at org.skife.jdbi.v2.sqlobject.InTransactionHandler$1.inTransaction(InTransactionHandler.java:37)

        at org.skife.jdbi.v2.tweak.transactions.LocalTransactionHandler.inTransaction(LocalTransactionHandler.java:184)

        at org.skife.jdbi.v2.tweak.transactions.DelegatingTransactionHandler.inTransaction(DelegatingTransactionHandler.java:82)

        at org.killbill.commons.jdbi.transaction.RestartTransactionRunner.inTransaction(RestartTransactionRunner.java:60)

        at org.skife.jdbi.v2.BasicHandle.inTransaction(BasicHandle.java:328)

        at org.skife.jdbi.v2.sqlobject.InTransactionHandler.invoke(InTransactionHandler.java:32)

        at org.skife.jdbi.v2.sqlobject.SqlObject.invoke(SqlObject.java:180)

        at org.skife.jdbi.v2.sqlobject.SqlObject$2.intercept(SqlObject.java:93)

        at org.killbill.billing.util.entity.dao.EntitySqlDaoTransactionalJdbiWrapper$InitialEntitySqlDao$$EnhancerByCGLIB$$665dcbdf.inTransaction(<generated>)

        at org.killbill.billing.util.entity.dao.EntitySqlDaoTransactionalJdbiWrapper.execute(EntitySqlDaoTransactionalJdbiWrapper.java:98)

        at org.killbill.billing.subscription.engine.dao.DefaultSubscriptionDao.getSubscriptionFromId(DefaultSubscriptionDao.java:355)

        at org.killbill.billing.subscription.engine.core.DefaultSubscriptionBaseService.processEventReady(DefaultSubscriptionBaseService.java:158)

        at org.killbill.billing.subscription.engine.core.DefaultSubscriptionBaseService$1.handleReadyNotification(DefaultSubscriptionBaseService.java:125)

        at org.killbill.notificationq.NotificationQueueDispatcher.handleNotificationWithMetrics(NotificationQueueDispatcher.java:200)

        ... 10 common frames omitted

Thank you.

[gokha...@gmail.com]

I have another problem except previous one.

I sent an email at 22:58. But, as you can see the log below, the script tried to sent email many times. And also, this email was sent after 90 mins from successful payment.

The latest one looks like successful, previous logs didn't send anything. 

So, why the plugin waited 90 mins to send email?

And, why we can see more than 2 logs for just 1 successful email sending? 

Log;

178620  2021-08-26T21:58:42,870+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1334', tRId='57', Sending email to = [m*.*l...@icloud.com], cc= admin@r***r.com, h***o@h***t.com, subject = */** W*** S* R*** R*** 24/08/2021 - 23/09/2021  L*** ID: ****** body = [

178641  2021-08-26T21:58:42,871+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1334', tRId='57', Sending email to [m*.*l...@icloud.com], cc [admin@r***r.com, h***o@h***t.com], subject */** W*** S* R*** R*** 24/08/2021 - 23/09/2021  L*** ID: ******

186368  2021-08-26T22:03:44,410+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1334', tRId='57', Sending email to = [m*.*l...@icloud.com], cc= admin@r***r.com, h***o@h***t.com, subject = */** W*** S* R*** R*** 24/08/2021 - 23/09/2021  L*** ID: ****** body = [

186389  2021-08-26T22:03:44,412+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1334', tRId='57', Sending email to [m*.*l...@icloud.com], cc [admin@r***r.com, h***o@h***t.com], subject */** W*** S* R*** R*** 24/08/2021 - 23/09/2021  L*** ID: ******

187500  2021-08-26T22:13:44,516+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1334', tRId='57', Sending email to = [m*.*l...@icloud.com], cc= admin@r***r.com, h***o@h***t.com, subject = */** W*** S* R*** R*** 24/08/2021 - 23/09/2021  L*** ID: ****** body = [

187565  2021-08-26T22:13:44,519+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1334', tRId='57', Sending email to [m*.*l...@icloud.com], cc [admin@r***r.com, h***o@h***t.com], subject */** W*** S* R*** R*** 24/08/2021 - 23/09/2021  L*** ID: ******

190800  2021-08-26T22:58:44,951+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1334', tRId='57', Sending email to = [m*.*l...@icloud.com], cc= admin@r***r.com, h***o@h***t.com, subject = */** W*** S* R*** R*** 24/08/2021 - 23/09/2021  L*** ID: ****** body = [

190822  2021-08-26T22:58:44,952+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='1334', tRId='57', Sending email to [m*.*l...@icloud.com], cc [admin@r***r.com, h***o@h***t.com], subject */** W*** S* R*** R*** 24/08/2021 - 23/09/2021  L*** ID: ******

Thank you.

[stephane brossier]

On Sun, Aug 29, 2021 at 6:54 PM gokha...@gmail.com <gokha...@gmail.com> wrote:

I have another problem except previous one.

I sent an email at 22:58. But, as you can see the log below, the script tried to sent email many times.

 Which 'script' are you referring to?

Could you provide some details on what you are trying to, what is happening and what you expect happening - also not that sending emails (from the plugin, I suspect?) depends on your plugin configuration.

--
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-us...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/killbilling-users/92e589c2-be1f-4af8-aa70-e498a31e6227n%40googlegroups.com.

[gokha...@gmail.com]

Sorry, I wrote script but you are right, I wanted to say email plugin. 

I didn't try anything. The email plugin is currently working on my system. The payment was successful then I expected to sent email via this plugin. 

But, the plugin didn't send email immediately after payment. It waited to send 90 minutes. 

Question 1 - Why did plugin waited to send email ? Because, for the other customer's or other payment's I can see the successful sending email straight away successful payment.

Question 2- In the log file why I can see more than 2 rows log for the just 1 email? (I know for the 1 email it should be 2 different logs for the beginning and ending)

Thank you.

[gokha...@gmail.com]

Hi,

I want to ask one question again. 

When I check the log file for email plugin, I saw 2 logs regarding sending successful email. One of them hour is 20:58:41 UTC, another one's hour is 21:03:43 UTC. 5 minutes differences. But, I saw I  have sent an email at 20:58 UTC. I don't understand what is the second one's(21:03:43 UTC) log. Both are %100 similar log. Why do I see 2 successful logs at 5 minutes intervals although the plugin  sent just 1 successful email? Do you have any idea? 

 

These are logs;

First one - 

161030  2021-09-08T20:58:41,270+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='944', tRId='320', Sending email to = [s*4...@gmail.com], cc= admin@r*r.com, l*e...@me.com, subject = [ALERT] Rental Payment Unsuccessful  Lease ID: 1*5 body = [Failed Payment

161031

161032  Dear S* C*,

161033

161034  T**

161035  due on 06/09/2021 for  $xxx.00  was unsuccessful.

161036  T**

161037  T**

161038  P**

161039

161040  Should you have any questions or concerns, please contact admin@r*r.com

161041

161042  R*r.com.

161043  **

161044  **]

161045  2021-09-08T20:58:41,271+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='944', tRId='320', EmailSender configured with serverName = email-smtp.us-west-2.amazonaws.com, serverPort = 587, from = admin@r*r.com, logOnly = false

161046  2021-09-08T20:58:41,271+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='944', tRId='320', Sending email to [s*4...@gmail.com], cc [admin@r*r.com, l*e...@me.com], subject [ALERT] Rental Payment Unsuccessful  Lease ID: 1*5

Second one - 

164710  2021-09-08T21:03:43,463+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='944', tRId='320', Sending email to = [s*4...@gmail.com], cc= admin@r*r.com, l*e...@me.com, subject = [ALERT] Rental Payment Unsuccessful  Lease ID: 1*5 body = [Failed Payment

164711

164712  Dear S* C*,

164713

164714  T**

164715  due on 06/09/2021 for  $xxx.00  was unsuccessful.

164716  T**

164717  T**

164718  P**

164719

164720  Should you have any questions or concerns, please contact admin@r*r.com

164721

164722  R*r.com

164723  **

164724  **]

164725  2021-09-08T21:03:43,464+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='944', tRId='320', EmailSender configured with serverName = email-smtp.us-west-2.amazonaws.com, serverPort = 587, from = admin@r*r.com, logOnly = false

164726  2021-09-08T21:03:43,464+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-12', xff='', rId='', tok='', aRId='944', tRId='320', Sending email to [s*4...@gmail.com], cc [admin@r*r.com, l*e...@me.com], subject [ALERT] Rental Payment Unsuccessful  Lease ID: 1*5

Thank you. 

[stephane brossier]

I have seen your previous email, but the traces/logs provided are not sufficient to troubleshoot your issue unfortunately.

To view this discussion on the web visit https://groups.google.com/d/msgid/killbilling-users/b3a0e666-3f69-4821-84e3-ee4df9cd76d1n%40googlegroups.com.