5.1 FreeMarker template error: The following has evaluated to null or missing:

[briant]

UPDATE:

1. Without changing anything at all, nor restarting any process, the emails were delivered last night successfully... We are both happy and concerned simultaneously.

2. The system was actually built 2+ years ago (Jan 2015) using Linux all in one installer for version 5.0.x, then the tomcat directory was relocated to a FreeBSD system (with native BSD tomcat, imagemagick, openoffice, swftools, etc), database moved into a separate dedicated server, and the lot upgraded to 5.1.  That was done a few months ago.

5.1 System built a few months 2 years ago. Working perfectly.

1 month ago we enabled multi tenancy, created 1 site, added 3 users, added content. System has been fine since the multi tenancy was enabled - ie:no errors logged.

Yesterday we removed a (testing) user from the site.

Last night the activity feed email failed (logs below).

The email ftl template from the log below ("workspace://SpacesStore/5068a46c-83b8-4377-8f77-3a669183e5d9") is unchanged from default.

Line 53 is:

<#assign itemLink="<a href=\"${shareUrl}/page/site/${activity.siteNetwork?html}/${activity.activitySummary.page?html!\"\"}\">${activity.activitySummary.title?html!\"\"}</a>">

Col 130 starts here => ${activity.activitySummary.page?html.....

2017-03-21 00:00:00,476 ERROR [freemarker.runtime] [FeedNotifier1] Error executing FreeMarker template
FreeMarker template error:
The following has evaluated to null or missing:
==> {activity.activitySummary.pag [in template "workspace://SpacesStore/5068a46c-83b8-4377-8f77-3a669183e5d9" at line 53, column 130]

Tip: [briant: removed, superfluous]

The failing instruction (FTL stack trace):
----------
==> ${activity.activitySummary.page?html!""} [in template "workspace://SpacesStore/5068a46c-83b8-4377-8f77-3a669183e5d9" at line 53, column 128]
#assign itemLink = "\la href=\"\${sha... [in template "workspace://SpacesStore/5068a46c-83b8-4377-8f77-3a669183e5d9" at line 53, column 49]
----------

Java stack trace (for programmers):
----------
freemarker.core.InvalidReferenceException: [... Exception message was already printed; see it above ...]

at freemarker.core.InvalidReferenceException.getInstance(InvalidReferenceException.java:98)
at freemarker.core.EvalUtil.coerceModelToString(EvalUtil.java:382)
at freemarker.core.Expression.evalAndCoerceToString(Expression.java:115)
at freemarker.core.StringBuiltins$StringBuiltIn._eval(StringBuiltins.java:87)
at freemarker.core.Expression.eval(Expression.java:111)
at freemarker.core.DefaultToExpression._eval(DefaultToExpression.java:116)
at freemarker.core.Expression.eval(Expression.java:111)
at freemarker.core.Expression.evalAndCoerceToString(Expression.java:115)
at freemarker.core.DollarVariable.accept(DollarVariable.java:76)
at freemarker.core.Environment.visit(Environment.java:265)
at freemarker.core.MixedContent.accept(MixedContent.java:93)
at freemarker.core.Environment.visit(Environment.java:265)
at freemarker.core.Environment.renderElementToString(Environment.java:1798)
at freemarker.core.StringLiteral.evalAndCoerceToString(StringLiteral.java:116)
at freemarker.core.StringLiteral._eval(StringLiteral.java:93)
at freemarker.core.Expression.eval(Expression.java:111)
at freemarker.core.Assignment.accept(Assignment.java:106)
at freemarker.core.Environment.visit(Environment.java:265)
at freemarker.core.MixedContent.accept(MixedContent.java:93)
at freemarker.core.Environment.visitByHiddingParent(Environment.java:286)
at freemarker.core.ConditionalBlock.accept(ConditionalBlock.java:86)
at freemarker.core.Environment.visitByHiddingParent(Environment.java:286)
at freemarker.core.IteratorBlock$Context.runLoop(IteratorBlock.java:193)
at freemarker.core.Environment.visitIteratorBlock(Environment.java:509)
at freemarker.core.IteratorBlock.accept(IteratorBlock.java:103)
at freemarker.core.Environment.visitByHiddingParent(Environment.java:286)
at freemarker.core.ConditionalBlock.accept(ConditionalBlock.java:86)
at freemarker.core.Environment.visit(Environment.java:265)
at freemarker.core.MixedContent.accept(MixedContent.java:93)
at freemarker.core.Environment.visit(Environment.java:265)
at freemarker.core.Environment.process(Environment.java:243)
at org.alfresco.repo.template.FreeMarkerProcessor.process(FreeMarkerProcessor.java:223)
at org.alfresco.repo.processor.TemplateServiceImpl.processTemplate(TemplateServiceImpl.java:177)
at org.alfresco.repo.processor.TemplateServiceImpl.processTemplate(TemplateServiceImpl.java:240)
at org.alfresco.repo.action.executer.MailActionExecuter$3.prepare(MailActionExecuter.java:958)
at org.alfresco.repo.action.executer.MailActionExecuter.prepareEmail(MailActionExecuter.java:1019)
at org.alfresco.repo.action.executer.MailActionExecuter.prepareEmails(MailActionExecuter.java:578)
at org.alfresco.repo.action.executer.MailActionExecuter.executeImpl(MailActionExecuter.java:483)
at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:267)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.alfresco.repo.management.subsystems.SubsystemProxyFactory$1.invoke(SubsystemProxyFactory.java:72)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy312.execute(Unknown Source)
at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:839)
at org.alfresco.repo.action.ActionServiceImpl.executeActionImpl(ActionServiceImpl.java:740)
at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:574)
at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:560)
at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:848)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.alfresco.repo.security.permissions.impl.AlwaysProceedMethodInterceptor.invoke(AlwaysProceedMethodInterceptor.java:34)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:46)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.alfresco.repo.audit.AuditMethodInterceptor.invoke(AuditMethodInterceptor.java:159)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy47.executeAction(Unknown Source)
at org.alfresco.repo.activities.feed.EmailUserNotifier.notifyUser(EmailUserNotifier.java:180)
at org.alfresco.repo.activities.feed.AbstractUserNotifier.notifyUser(AbstractUserNotifier.java:221)
at org.alfresco.repo.activities.feed.FeedNotifierImpl$2.processInternal(FeedNotifierImpl.java:386)
at org.alfresco.repo.activities.feed.FeedNotifierImpl$2.access$2(FeedNotifierImpl.java:381)
at org.alfresco.repo.activities.feed.FeedNotifierImpl$2$1$1.execute(FeedNotifierImpl.java:372)
at org.alfresco.repo.activities.feed.FeedNotifierImpl$2$1$1.execute(FeedNotifierImpl.java:1)
at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:457)
at org.alfresco.repo.activities.feed.FeedNotifierImpl$2$1.doWork(FeedNotifierImpl.java:368)
at org.alfresco.repo.activities.feed.FeedNotifierImpl$2$1.doWork(FeedNotifierImpl.java:1)
at org.alfresco.repo.tenant.TenantUtil.runAsWork(TenantUtil.java:119)
at org.alfresco.repo.tenant.TenantUtil.runAsTenant(TenantUtil.java:88)
at org.alfresco.repo.activities.feed.FeedNotifierImpl$2.process(FeedNotifierImpl.java:363)
at org.alfresco.repo.activities.feed.FeedNotifierImpl$2.process(FeedNotifierImpl.java:1)
at org.alfresco.repo.batch.BatchProcessor$TxnCallback.execute(BatchProcessor.java:713)
at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:457)
at org.alfresco.repo.batch.BatchProcessor$TxnCallback.run(BatchProcessor.java:757)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

2017-03-21 00:00:00,512 ERROR [freemarker.runtime] [FeedNotifier1] Error executing FreeMarker template

...

2017-03-21 00:00:00,628 ERROR [freemarker.runtime] [FeedNotifier1] Error executing FreeMarker template

...

2017-03-21 00:00:00,630 ERROR [freemarker.runtime] [FeedNotifier1] Error executing FreeMarker template

...

2017-03-21 00:00:00,790 ERROR [freemarker.runtime] [FeedNotifier1] Error executing FreeMarker template

...

2017-03-21 00:00:00,792 ERROR [freemarker.runtime] [FeedNotifier1] Error executing FreeMarker template

...

No 'caused by' line. Same error repeats 6 times as shown.

First occurrence last night, the only likely change we can think of is the removal of the testuser account (who was previously receiving email activity feeds successfully, as were the other 2 users).

No emails were sent last night. This is a concern for us.

[afaust]

The error is pretty clear in the message:

${activity.activitySummary.page?html!""} [in template "workspace://SpacesStore/5068a46c-83b8-4377-8f77-3a669183e5d9" at line 53, column 128]

That means the data model prepared for the activity that is to be included in an email is incomplete and does not contain a "page" property. Interestingly, the expression already contains a "!" operator to fallback to an empty string if there is no data - but it is placed in the wrong place. The expression should be ${(activity.activitySummary.page!"")?html}

You can correct it by editing the template document specified by the NodeRef.

[briant]

Axel Faust wrote:

The error is pretty clear in the message:

${activity.activitySummary.page?html!""} [in template "workspace://SpacesStore/5068a46c-83b8-4377-8f77-3a669183e5d9" at line 53, column 128]

It's only "pretty clear" if you know what the expression should be Experience is a wonderful thing after you have it.

Checking the other language email templates in the tenant instance all reveal they have identical line 53's, sample from activities-email_de.ftl in the tenant:

<#assign itemLink="<a href=\"${shareUrl}/page/site/${activity.siteNetwork?html}/${activity.activitySummary.page?html!\"\"}\">${activity.activitySummary.title?html!\"\"}</a>">

Axel Faust‌: Do the double quotes need escaping?

ie: you said it needs to be: ${(activity.activitySummary.page!"")?html}

Should it be entered verbatim like this:

<#assign itemLink="<a href=\"${shareUrl}/page/site/${activity.siteNetwork?html}/${(activity.activitySummary.page!"")?html}\">${activity.activitySummary.title?html!\"\"}</a>">

...or like this with \"\" ?

<#assign itemLink="<a href=\"${shareUrl}/page/site/${activity.siteNetwork?html}/${(activity.activitySummary.page!\"\")?html}\">${activity.activitySummary.title?html!\"\"}</a>">

Hmm - It seems the primary (non-tenant) instance is different? This file was created at install time on 19/Jan/2015, over two years ago. We would expect the tenant versions to be identical, no?

<#assign itemLink="<a href=\"${shareUrl}/page/site/${activity.siteNetwork?html}/${activity.activitySummary.page!\"\"}\">${activity.activitySummary.title!\"\"}</a>">

Does the primary non-tenant need the () and ?html appended per your example?

We also note that a similar pattern appears several times in these templates - do we need to change them all?

We really need these emails to be delivered.

Many thanks in advance for your help and advice.

[afaust]

I actually meant "pretty clear" because the message states that as the failing instruction. Most other error stacktraces won't show any detail that comes even close to this...

Ugh - these activities templates are a mess. I am glad I never had to look too closely at them. Inside of an &lt;#assign&gt; section things do indeed become tricky when you use interpolation instead of simple string concatenation. As far as I can tell - yes, you should add the expression I provided with encoded double quotes in that case.

These email templates are initialised when the tenant is first created with the email templates that Alfresco provides at that point. After initialisation, each template in each tenant may be individually modified / updated. From my experience Alfresco typically neglects the multi-tenant use case, and new versions of Alfresco may only provide patches to update the templates in the default tenant but not any other tenants.

In order to avoid similar issues in other expressions the pattern should probably changed in all occurrences you can find. Though the pattern itself is likely not the immediate cause of the issue - the fact that the "page" attribute in that data structure has not been provided for at least on activity is the cause. Alfresco never really expected that or tested against that, which is why they have not realised the patterns are not able to deal with such a situation.