Freemarker template stopped worked with recent ubuntu package upgrade

[Ian Badcoe (Sumo Digital)]

Hi all, I hope somebody can help me...

TL;DR in the last month newly deployed ubuntu 12.04 LTS servers stopped running our legacy web-site (using a Java web-app containing freemarker templates; deployed into catalina/tomcat6...) Problem traces to an InvalidReferenceException generated when freemarker (2.3.19) attempts to access a property on an object passed to it from the Java servlet code. The object is not null and nothing has changed in the source code that could remove the getXXX method that previously supplied the property...

...I am hoping that somebody can tell me this is a known issue, something like a side-effect of a security fix that strengthens restrictions on introspecting Java classes...?

---

Long form

((Also please forgive me if terminology is off or I seem ignorant of basic things -- I am a very experienced developer but my history with java servlets started only a few months ago, and has been very "reactive" since then...))

I am maintaining a legacy web-site that runs using a web-app built with Java in Maven and deployed via a WAR file to be run on ubuntu 12.04 using catalina, tomcat6, openjdk-6 etc (for exact versions see below).

Roughly a month ago I redeployed this web-site to make a minor upgrade and everything worked perfectly.

Last Friday (9th Dec 2016) I attempted to deploy a copy into a development environment and it doesn't work any more -- nothing has changed in the web-app (in fact initially I deployed precisely the same WAR file...)

So my theory is that in the last month, some change to the latest version of a deployed package (the deployment process takes latest versions from the ubuntu 12.04 LTS release. The exact error is:

3    [http-8080-1] ERROR freemarker.runtime  - Template processing error: "Expression efg.getHomepageVideoOn() is undefined on line 8, column 14 in home.ftl."
Expression efg.getHomepageVideoOn() is undefined on line 8, column 14 in home.ftl.
The problematic instruction:
----------
==> if-else  [on line 8, column 9 in home.ftl]
 in user-directive m_main.template [on line 7, column 5 in home.ftl]
----------

Java backtrace for programmers:
----------
freemarker.core.InvalidReferenceException: Expression efg.getHomepageVideoOn() is undefined on line 8, column 14 in home.ftl.
        at freemarker.core.TemplateObject.assertNonNull(TemplateObject.java:125)
        at freemarker.core.ComparisonExpression.isTrue(ComparisonExpression.java:121)
        at freemarker.core.IfBlock.accept(IfBlock.java:80)
        at freemarker.core.Environment.visit(Environment.java:221)
        at freemarker.core.Environment.visit(Environment.java:406)
        at freemarker.core.BodyInstruction.accept(BodyInstruction.java:93)
        at freemarker.core.Environment.visit(Environment.java:221)
        at freemarker.core.MixedContent.accept(MixedContent.java:92)
        at freemarker.core.Environment.visit(Environment.java:221)
        at freemarker.core.Macro$Context.runMacro(Macro.java:172)
        at freemarker.core.Environment.visit(Environment.java:614)
        at freemarker.core.UnifiedCall.accept(UnifiedCall.java:106)
        at freemarker.core.Environment.visit(Environment.java:221)
        at freemarker.core.EscapeBlock.accept(EscapeBlock.java:84)
        at freemarker.core.Environment.visit(Environment.java:221)
        at freemarker.core.MixedContent.accept(MixedContent.java:92)
        at freemarker.core.Environment.visit(Environment.java:221)
        at freemarker.core.Environment.process(Environment.java:199)
        at freemarker.template.Template.process(Template.java:259)
        at org.springframework.web.servlet.view.freemarker.FreeMarkerView.processTemplate(FreeMarkerView.java:366)
        at org.springframework.web.servlet.view.freemarker.FreeMarkerView.doRender(FreeMarkerView.java:283)
        at org.springframework.web.servlet.view.freemarker.FreeMarkerView.renderMergedTemplateModel(FreeMarkerView.java:233)
        at org.springframework.web.servlet.view.AbstractTemplateView.renderMergedOutputModel(AbstractTemplateView.java:167)
        at org.springframework.web.servlet.view.AbstractView.render(AbstractView.java:262)
        at org.springframework.web.servlet.DispatcherServlet.render(DispatcherServlet.java:1180)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:950)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
...

(there's more callstack but this shows the broad location.) After a bit of investigation, it looks as if a method that used to be accessible "efg" object has suddenly stopped being accessible. As I said there has been no change to the source code (and no upgrade of the java compilation environment used to build the WAR file) so this must be caused by a change of environment on the server.

I diffed the two sets of installed package versions (from production (working) and develop (crashing)):

Package	Working Version	Crashing Version
chef	12.5.1-1	11.12.4-1
dbus-x11	1.4.18-1ubuntu1.7	1.4.18-1ubuntu1.8
fontconfig	2.8.0-3ubuntu9.1	2.8.0-3ubuntu9.2
fontconfig-config	2.8.0-3ubuntu9.1	2.8.0-3ubuntu9.2
icedtea-6-jre-cacao	6b35-1.13.7-1ubuntu0.12.04.2	6b40-1.13.12-0ubuntu0.12.04.2
icedtea-6-jre-jamvm	6b35-1.13.7-1ubuntu0.12.04.2	6b40-1.13.12-0ubuntu0.12.04.2
libavahi-client3	0.6.30-5ubuntu2.1	0.6.30-5ubuntu2.2
libavahi-common-data	0.6.30-5ubuntu2.1	0.6.30-5ubuntu2.2
libavahi-common3	0.6.30-5ubuntu2.1	0.6.30-5ubuntu2.2
libfontconfig1	2.8.0-3ubuntu9.1	2.8.0-3ubuntu9.2
libgdk-pixbuf2.0-0	2.26.1-1ubuntu1.3	2.26.1-1ubuntu1.5
libgdk-pixbuf2.0-common	2.26.1-1ubuntu1.3	2.26.1-1ubuntu1.5
libgtk-3-0	3.4.2-0ubuntu0.8	3.4.2-0ubuntu0.9
libgtk-3-bin	3.4.2-0ubuntu0.8	3.4.2-0ubuntu0.9
libgtk-3-common	3.4.2-0ubuntu0.8	3.4.2-0ubuntu0.9
libjasper1	1.900.1-13ubuntu0.2	1.900.1-13ubuntu0.3
libmysqlclient18	5.5.46-0ubuntu0.12.04.2	5.5.53-0ubuntu0.12.04.1
libnspr4	4.10.7-0ubuntu0.12.04.1	4.12-0ubuntu0.12.04.1
libnss3	3.17.4-0ubuntu0.12.04.1	2:3.23-0ubuntu0.12.04.1
libnss3-1d	3.17.4-0ubuntu0.12.04.1	2:3.23-0ubuntu0.12.04.1
libperl5.14	5.14.2-6ubuntu2.4	5.14.2-6ubuntu2.5
libpixman-1-0	0.30.2-1ubuntu0.0.0.0.2	0.30.2-1ubuntu0.0.0.0.3
libpq5	9.1.19-0ubuntu0.12.04	9.1.24-0ubuntu0.12.04
libservlet2.5-java	6.0.35-1ubuntu3.6	6.0.35-1ubuntu3.8
libtiff4	3.9.5-2ubuntu1.8	3.9.5-2ubuntu1.9
libtomcat6-java	6.0.35-1ubuntu3.6	6.0.35-1ubuntu3.8
libvirt0	0.9.8-2ubuntu17.22	0.9.8-2ubuntu17.23
libxenstore3.0	4.1.6.1-0ubuntu0.12.04.6	4.1.6.1-0ubuntu0.12.04.12
mysql-common	5.5.46-0ubuntu0.12.04.2	5.5.53-0ubuntu0.12.04.1
openjdk-6-jre-headless	6b35-1.13.7-1ubuntu0.12.04.2	6b40-1.13.12-0ubuntu0.12.04.2
openjdk-6-jre-lib	6b35-1.13.7-1ubuntu0.12.04.2	6b40-1.13.12-0ubuntu0.12.04.2
perl	5.14.2-6ubuntu2.4	5.14.2-6ubuntu2.5
perl-base	5.14.2-6ubuntu2.4	5.14.2-6ubuntu2.5
perl-modules	5.14.2-6ubuntu2.4	5.14.2-6ubuntu2.5
stunnel4	3:4.42-1ubuntu0.1	n/a
tomcat6	6.0.35-1ubuntu3.6	6.0.35-1ubuntu3.8
tomcat6-common	6.0.35-1ubuntu3.6	6.0.35-1ubuntu3.8
tzdata	2015d-0ubuntu0.12.04	2016j-0ubuntu0.12.04
tzdata-java	2015d-0ubuntu0.12.04	2016j-0ubuntu0.12.04

Obviously I suspected the changed tomcat and openjdk packages, however I have tried downgrading those on the dev machine down to what's on the production machine without fixing the problem. I am now wondering whether the libnspr4/libnss3/libnss3-1d libraries are involved... I do not think icedtea is involved as the web-server will start with that removed...

Does anybody have any idea what the underlying cause of this issue is? Even if I narrow it down to a single package it would be nice if there were a fix I could apply in the code to permit the newer package to continue operating.

Upgrading this system to newer versions is possible, however it would be a real pain to have to do that in the middle of the other project I am trying to work on... To give context, the reason I want to deploy the web-site is so I can test some other (back-end) systems which I am in the process of upgrading to ubuntu 16.04 -- it is highly prefereable to complete upgrading/testing and then deploying those systems before introducing another source of errors/problems/differences...

I have done quite a lot of web-searches around this area, however I have the usual problem of many hits from people with the same error from but completely different causes...

Thanks for any suggestions,

Ian

[Dániel Dékány]

I suspect that FreeMarker works fine (and I'm not aware of any similar bugs), it just tells you the truth, which I help to translate to plain English: the getHomepageVideoOn() method has returned null. Why does that Java method return null? Is it expected to? Maybe this null comes from a recent database content change? BTW, FreeMarker can handle such cases as far as you specify a default value as maybeNullExp!defaultExp.

[Ian Badcoe (Sumo Digital)]

Hi Dániel and thank you,

That is an interesting idea... my impression was that it wasn't getting as far as calling getHomepageVideoOn() but realise I thought this because of the message phrasing ("undefined" to me implies something cannot be evaluated) and I (unconsciously) assumed that a null could have been compared with true (which is from my C/C++ upbringing, where such a comparison is a low-level capability, however I realise now that don't know how freemarker implements the comparison and if it wants to call "equals" on the left object...)

Thanks! I'll investigate it from this angle. That method shouldn't return null, and it doesn't come from a DB, it is actually a configuration parameter passed in by the deployment. None of that has changed, so I still suspect the ultimate cause must still be a change to the installed packages... However this gives me a different place to start looking.

Regards,

Ian

[Dániel Dékány]

It's the presence of the () that tells that the method was invoked, and the problem is with the return value. If the method itself is missing, the error message complains about efg.getHomepageVideoOn without the (). (BTW, nowadays it would say "The following has evaluated to null or missing: efg.getHomepageVideoOn()", which is better. It could be made better though. Anyway, if anyone plans to fiddle with the templates, upgrading from that 5 years old version worths it even for the better error messages alone.)

[Ian Badcoe (Sumo Digital)]

Thanks again Dániel,

When I come to upgrade the site I'll think carefully about upgrading the version (of freemarker and other things)...

There has to be a bit of a calculation, however, because it is a legacy site, so it won't make sense if I do the upgrade but that turns out to be the last time anybody touches it...

Just to close the query I started with I have found out what was wrong, there was a different config variable set incorrectly that meant it was looking in the wrong store for the return value of getHomepageVideoOn()... hence the value was null even though it was read correctly during the start-up... how the other variable became incorrect is a different question :-(

Regards,

Ian