Email notifications no longer work

[alex_s]

We no longer receive email notifications from XWiki (v.15.0) although the notifications themselves (the bell) work.

Sharing a page works, the email arrives fine - the settings entered in the SMTP configuration page are correct.

Mails do not arrive in our “junk” folders.

The log file /var/log/tomcat9/catalina.out does not give much information:

[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,718 [Mail Prepare Thread] ERROR o.a.v.d.null - Exception in macro #link called at /templates/notification/email/default.html.vm[line 100, column 1]
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,719 [Mail Prepare Thread] ERROR o.a.v.d.null - Exception in macro #displayNotificationPage called at /templates/notification/email/default.html.vm[line 132, column 1]
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,719 [Mail Prepare Thread] ERROR o.a.v.d.null - Exception in macro #displayNotificationRightCell called at /templates/notification/email/default.html.vm[line 27, column 7>
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,719 [Mail Prepare Thread] ERROR o.a.v.d.null - Exception in macro #displayNotificationSkeleton called at /templates/notification/email/default.html.vm[line 27, column 1]
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,720 [Mail Prepare Thread] ERROR ultPeriodicMimeMessageIterator - Failed to generate an email for the user [xwiki:XWiki.mpo].
[2023-02-06 00:00:07] [info] org.xwiki.notifications.NotificationException: Failed to render the notification.

Does anyone have any ideas?

Thanks for reading.

[surli]

Hi,

@alex_s

[2023-02-06 00:00:07] [info] org.xwiki.notifications.NotificationException: Failed to render the notification.

you should probably have a big stack trace in the logs after this line, could you share it, it probably gives the root cause of the error.
By any chance are you using a custom mail template that you might have edited recently?

[alex_s]

Thank you !

No, we don’t use a custom mail template.

Not quite sure where to stop with my copy/paste so sorry if it’s too much…

[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,718 [Mail Prepare Thread] ERROR o.a.v.d.null - Exception in macro #link called at /templates/notification/email/default.html.vm[line 100, column 1]
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,719 [Mail Prepare Thread] ERROR o.a.v.d.null - Exception in macro #displayNotificationPage called at /templates/notification/email/default.html.vm[line 132, column 1]
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,719 [Mail Prepare Thread] ERROR o.a.v.d.null - Exception in macro #displayNotificationRightCell called at /templates/notification/email/default.html.vm[line 27, column 7>
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,719 [Mail Prepare Thread] ERROR o.a.v.d.null - Exception in macro #displayNotificationSkeleton called at /templates/notification/email/default.html.vm[line 27, column 1]
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,720 [Mail Prepare Thread] ERROR ultPeriodicMimeMessageIterator - Failed to generate an email for the user [xwiki:XWiki.mpo].
[2023-02-06 00:00:07] [info] org.xwiki.notifications.NotificationException: Failed to render the notification.
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.EmailTemplateRenderer.executeTemplateInContext(EmailTemplateRenderer.java:155)
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.EmailTemplateRenderer.executeTemplate(EmailTemplateRenderer.java:113)
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.AbstractNotificationEmailRenderer.executeTemplate(AbstractNotificationEmailRenderer.java:66)
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.DefaultNotificationEmailRenderer.renderHTML(DefaultNotificationEmailRenderer.java:69)
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.AbstractMimeMessageIterator.handleEvents(AbstractMimeMessageIterator.java:270)
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.AbstractMimeMessageIterator.updateFactoryParameters(AbstractMimeMessageIterator.java:237)
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.AbstractMimeMessageIterator.next(AbstractMimeMessageIterator.java:365)
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.AbstractMimeMessageIterator.next(AbstractMimeMessageIterator.java:68)
[2023-02-06 00:00:07] [info] #011at org.xwiki.mail.internal.thread.PrepareMailRunnable.prepareMail(PrepareMailRunnable.java:126)
[2023-02-06 00:00:07] [info] #011at org.xwiki.mail.internal.thread.PrepareMailRunnable.run(PrepareMailRunnable.java:81)
[2023-02-06 00:00:07] [info] #011at java.base/java.lang.Thread.run(Thread.java:829)
[2023-02-06 00:00:07] [info] Caused by: org.xwiki.rendering.RenderingException: Failed to execute renderer
[2023-02-06 00:00:07] [info] #011at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.syncRender(DefaultAsyncRendererExecutor.java:287)
[2023-02-06 00:00:07] [info] #011at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.render(DefaultAsyncRendererExecutor.java:267)
[2023-02-06 00:00:07] [info] #011at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor.execute(DefaultBlockAsyncRendererExecutor.java:125)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.InternalTemplateManager.execute(InternalTemplateManager.java:928)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.DefaultTemplateManager.execute(DefaultTemplateManager.java:199)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.DefaultTemplateManager.execute(DefaultTemplateManager.java:193)
[2023-02-06 00:00:07] [info] #011at org.xwiki.notifications.notifiers.internal.email.EmailTemplateRenderer.executeTemplateInContext(EmailTemplateRenderer.java:153)
[2023-02-06 00:00:07] [info] #011… 10 common frames omitted
[2023-02-06 00:00:07] [info] Caused by: org.xwiki.rendering.RenderingException: Failed to evaluate template with id [/templates/notification/email/default.html.vm]
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.evaluateContent(TemplateAsyncRenderer.java:224)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.renderVelocity(TemplateAsyncRenderer.java:177)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.render(TemplateAsyncRenderer.java:138)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.render(TemplateAsyncRenderer.java:54)
[2023-02-06 00:00:07] [info] #011at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.lambda$syncRender$0(DefaultAsyncRendererExecutor.java:284)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.security.authorization.DefaultAuthorExecutor.call(DefaultAuthorExecutor.java:98)
[2023-02-06 00:00:07] [info] #011at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.syncRender(DefaultAsyncRendererExecutor.java:284)
[2023-02-06 00:00:07] [info] #011… 16 common frames omitted
[2023-02-06 00:00:07] [info] Caused by: org.xwiki.velocity.XWikiVelocityException: Failed to evaluate content with namespace [/templates/notification/email/default.html.vm]
[2023-02-06 00:00:07] [info] #011at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate(DefaultVelocityEngine.java:289)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.render.DefaultVelocityManager.evaluate(DefaultVelocityManager.java:321)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.VelocityTemplateEvaluator.evaluateContent(VelocityTemplateEvaluator.java:95)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.evaluateContent(TemplateAsyncRenderer.java:222)
[2023-02-06 00:00:07] [info] #011… 22 common frames omitted
[2023-02-06 00:00:07] [info] #011… 22 common frames omitted
[2023-02-06 00:00:07] [info] Caused by: org.apache.velocity.exception.MethodInvocationException: Invocation of method ‘getURL’ in class com.xpn.xwiki.api.Document threw exception java.lang.NullPointerException at /templates/notificatio>
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTMethod.handleInvocationException(ASTMethod.java:308)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:235)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:368)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTReference.value(ASTReference.java:704)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.VelocimacroProxy.handleArgValues(VelocimacroProxy.java:380)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:213)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:331)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:261)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:304)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:147)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:218)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:331)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:261)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:304)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:147)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:218)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:331)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:261)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:304)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:439)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTStringLiteral.value(ASTStringLiteral.java:320)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.VelocimacroProxy.handleArgValues(VelocimacroProxy.java:380)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:213)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:331)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:261)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:304)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:439)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.Template.merge(Template.java:358)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.Template.merge(Template.java:262)
[2023-02-06 00:00:07] [info] #011at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate(DefaultVelocityEngine.java:280)
[2023-02-06 00:00:07] [info] #011… 25 common frames omitted
[2023-02-06 00:00:07] [info] Caused by: java.lang.NullPointerException: null
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.web.ExternalServletURLFactory.getURL(ExternalServletURLFactory.java:56)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.doc.XWikiDocument.getURL(XWikiDocument.java:2419)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.doc.XWikiDocument.getURL(XWikiDocument.java:2430)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.doc.XWikiDocument.getURL(XWikiDocument.java:2435)
[2023-02-06 00:00:07] [info] #011at com.xpn.xwiki.api.Document.getURL(Document.java:1021)
[2023-02-06 00:00:07] [info] #011at jdk.internal.reflect.GeneratedMethodAccessor346.invoke(Unknown Source)
[2023-02-06 00:00:07] [info] #011at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-02-06 00:00:07] [info] #011at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(UberspectImpl.java:571)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:554)
[2023-02-06 00:00:07] [info] #011at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:221)
[2023-02-06 00:00:07] [info] #011… 53 common frames omitted
[2023-02-06 00:00:07] [info] 2023-02-06 00:00:07,721 [Mail Prepare Thread] ERROR o.x.m.i.DatabaseMailListener - Failure during preparation phase of thread [d3977a4a-9be8-492d-aa2c-d94a44a52f12]
[2023-02-06 00:00:07] [info] java.lang.NullPointerException: null
[2023-02-06 00:00:07] [info] #011at org.xwiki.mail.internal.thread.PrepareMailRunnable.getFrom(PrepareMailRunnable.java:274)
[2023-02-06 00:00:07] [info] #011at org.xwiki.mail.internal.thread.PrepareMailRunnable.tryToEnsureFrom(PrepareMailRunnable.java:244)
[2023-02-06 00:00:07] [info] #011at org.xwiki.mail.internal.thread.PrepareMailRunnable.completeMessage(PrepareMailRunnable.java:235)
[2023-02-06 00:00:07] [info] #011at org.xwiki.mail.internal.thread.PrepareMailRunnable.prepareSingleMail(PrepareMailRunnable.java:170)
[2023-02-06 00:00:07] [info] #011at org.xwiki.mail.internal.thread.PrepareMailRunnable.prepareMail(PrepareMailRunnable.java:127)
[2023-02-06 00:00:07] [info] #011at org.xwiki.mail.internal.thread.PrepareMailRunnable.run(PrepareMailRunnable.java:81)
[2023-02-06 00:00:07] [info] #011at java.base/java.lang.Thread.run(Thread.java:829)

Could you point out something useful for us to try and fix this ?

Thanks again anyway !