A non-regular client of ours, after updating their Joomla website to 3.9.1 a couple of weeks ago, started seeing the following classical error on their homepage:
Internal Server Error
What was interesting was 2 things: 1) the error didn’t happen immediately after the update, but rather a few hours later, and 2) the error disappeared after clearing the Joomla cache (the error was only on the frontend, and not the backend).
Naturally, the first thing that we did was investigating the server logs, which we did, and this is what we saw in the error_log file which is located in the the /usr/local/apache/logs folder (the client was using a WHM/CentOS environment):
[Fri Dec 14 13:18:13.607733 2018] [core:error] [pid 11040:tid 47479697520384] [client ip_number:59084] End of script output before headers: index.php
As you can see from the above, the problem was in the index.php file, but was it really? We looked at the index.php file, and it was exactly as the one in the Joomla distribution, so the problem wasn’t there, which was logical, but not very helpful. What was even more unhelpful was the fact that the problem was erratic, and it was oddly taking place every morning around 11:30 AM.
We didn’t have much to go on, but the fact that the problem was resolved after clearing the cache gave us a lead. So, we compared the generated cache file of the homepage (located under the system/page folder) immediately after deleting the cache, and the generated cache file of the homepage immediately after seeing the problem. Everything was more or less the same, except for the last line: the below entry was repeated hundreds of times in the second cache file (the one that is not working):
CP="NOI ADM DEV PSAi COM NAV OUR OTRo STP IND DEM"
The above line existed in the first cache file, but just once, and, in case you’re wondering, it is generated by the P3P (Platform for Privacy Preferences) system plugin, which injects the (now mostly obsolete) P3P policy header tags into the HTML response.
So, we disabled the P3P system plugin, and tried our tests again, and this time, we saw 2 other HTML response tags that were repeated: Pragma: no-cache and Cache-Control: no-cache. Clearly, there was something else going on, and the P3P plugin was not the cause of the problem.
We spent hours debugging the problem while wondering why this was suddenly a problem after updating to Joomla 3.9.1. We kept looking into the wrong places, until it hit us: why not trace the System – P3P plugin and see at what point it injects its headers, and we quickly discovered that the headers were sent on the onAfterRespond event, we even discovered something even more important, is that, when the System – Page Cache plugin is enabled, the onAfterRespond event can only be triggered by the following lines in the cache.php file which is located in the plugins/system/cache folder:
if (JDEBUG) { JProfiler::getInstance('Application')->mark('afterCache'); JEventDispatcher::getInstance()->trigger('onAfterRespond'); }
But, why was the above code running when the Joomla debug was turned off? Or was it really turned off? So, we checked the Joomla configuration under System -> Global Configuration -> System, and, indeed the “Debug System” under “Debug Settings” was set to “On”. Huh?
We quickly turned it off and the problem was immediately resolved, but why wasn’t the problem happening in previous versions of Joomla, and why didn’t we notice it? The answer to the second question was obvious, the client was using a template that didn’t have any position for debugging. As for the first question, the answer was more alarming: it seems that Joomla 3.9.1 (and perhaps Joomla 3.9.0 as well) has a very quirky bug when the system is in debug mode, where the headers keep piling up in the cache file as the onAfterRespond event is triggered. Reproducing the problem couldn’t be easier:
- Create a Joomla website from scratch with the default data.
- Enable the System – Page Cache plugin.
- Enable debugging in the Joomla configuration.
- Go to the homepage on the frontend (load it a couple of times), and then check the generated cached file under the cache folder, you should see 2 things: 1) the cached file is changing on every refresh (which shouldn’t be the case), and 2) the Cache-Control and the Pragma headers keep getting added to the cache file with every refresh. The end of the cache file would look something like the below after 2 homepage refreshes:
s:13:"mime_encoding";s:9:"text/html";s:7:"headers";a:8:{i:0;a:2:{s:4:"name";s:12:"Content-Type";s:5:"value";s:24:"text/html; charset=utf-8";}i:1;a:2:{s:4:"name";s:7:"Expires";s:5:"value";s:29:"Wed, 17 Aug 2005 00:00:00 GMT";}i:2;a:2:{s:4:"name";s:13:"Last-Modified";s:5:"value";s:29:"Wed, 19 Dec 2018 04:42:56 GMT";}i:3;a:2:{s:4:"name";s:13:"Cache-Control";s:5:"value";s:62:"no-store, no-cache, must-revalidate, post-check=0, pre-check=0";}i:4;a:2:{s:4:"name";s:6:"Pragma";s:5:"value";s:8:"no-cache";}i:5;a:2:{s:4:"name";s:4:"ETag";s:5:"value";s:34:""f0c25fdc4c9774cdd8632f0a1e83d791"";}i:6;a:2:{s:4:"name";s:13:"Cache-Control";s:5:"value";s:8:"no-cache";}i:7;a:2:{s:4:"name";s:6:"Pragma";s:5:"value";s:8:"no-cache";}}}
So, this was definitely a Joomla bug and not caused by 3rd party extension. Having said that, there shouldn’t be many Joomla websites out there with debugging turned on!
We hope that you found this post exciting, informative, and helpful! If you need help with solving an “Internal Server Error” problem on your Joomla website, or if you need help with any other Joomla issue, then please contact us. We are always excited for help, our fees are affordable, and our quality is top notch!