XF 1.4 PHP Fatal error: Allowed memory size of 256MB exhausted in library/Zend/Db/Statement/Mysqli.php

[imthebest]

Hello,

Today I saw the following errors logged on my php.log file:

[13-Jan-2015 19:38:07 UTC] PHP Fatal error:  Allowed memory size of 268435456 bytes exhausted (tried to allocate 78 bytes) in /var/www/html/library/Zend/Db/Statement/Mysqli.php on line 304
[13-Jan-2015 19:38:23 UTC] PHP Fatal error:  Allowed memory size of 268435456 bytes exhausted (tried to allocate 78 bytes) in /var/www/html/library/Zend/Db/Statement/Mysqli.php on line 304
[13-Jan-2015 19:38:37 UTC] PHP Fatal error:  Allowed memory size of 268435456 bytes exhausted (tried to allocate 80 bytes) in /var/www/html/library/Zend/Db/Statement/Mysqli.php on line 304
[13-Jan-2015 19:39:07 UTC] PHP Fatal error:  Allowed memory size of 268435456 bytes exhausted (tried to allocate 78 bytes) in /var/www/html/library/Zend/Db/Statement/Mysqli.php on line 304
[13-Jan-2015 19:39:42 UTC] PHP Fatal error:  Allowed memory size of 268435456 bytes exhausted (tried to allocate 78 bytes) in /var/www/html/library/Zend/Db/Statement/Mysqli.php on line 304
[13-Jan-2015 19:40:13 UTC] PHP Fatal error:  Allowed memory size of 268435456 bytes exhausted (tried to allocate 1699 bytes) in /var/www/html/library/Zend/Db/Statement/Mysqli.php on line 294

Unfortunately XenForo didn't logged these errors on the Server Error Log so I don't have more information about these.

I'm using XF 1.4.4 and XFES 1.1.1

Thanks,
Super120

 

[Mike]

Because PHP's fatal errors are generally useless, unfortunately not much can be said about what's happening. It's only evident that it relates to retrieving (presumably) a large amount of data from MySQL.

 

[Xon]

Likely a reports issue? Didn't @Super120 have some crazy number of reports driving memory usage up before?

 

[Jim Boy]

256MB is a large amount of memory, unless you are running a large amount of concurrent users (6000+), then memory shouldn't be an issue for core code - add-ons are a different matter entirely....

You should scan your web server error logs for the offending url

 

[TPerry]

I think you are right @Xon. I think he had something like 4,000 reports or something that he hadn't taken care of and let build up about 3 weeks ago? Don't know if he ever got those cleaned up, but they could be causing other problems.

 

[imthebest]

The reports page (more than 4,000 active reports now) has been loading fine since I increased the PHP memory limit from 128MB to 256MB. Btw that particular error was catched by XenForo and logged into the Server Error Log as you can see here. This time however nothing gets logged into the Server Error Log but only on my internal php.log file (Linux). This is rare because OOM errors were successfully logged on XF 1.4.2 however now on 1.4.4 they are not being catched!

The OOM error that I'm reporting here started happening today since I upgraded from XF 1.4.2 to XF 1.4.4. This makes me think that maybe there is something new in 1.4.3 or 1.4.4 that is using a lot of memory?

 

[Jim Boy]

When you work out what the URI used is, which you can do from the web server log (I assume you were using a separate php error log), then go into debug mode and see what sql query is creating the issue.

 

[imthebest]

Access logs are disabled at the web server because it's a big site with a lot of traffic.

Again, this started happening since I upgraded from XF 1.4.2 to XF 1.4.4. This makes me think that maybe there is something new in 1.4.3 or 1.4.4 that is using a lot of memory? And... why XenForo isn't catching this error in the Server Error Log?

 

[Mike]

It's unlikely to be a change in the recent versions, but more likely to be something specific that happened based on your data.

Not all fatal PHP errors can be logged by a PHP script. It's a hack to manage to log any of them...

 

[Xon]

Access logs are disabled at the web server because it's a big site with a lot of traffic.

Again, this started happening since I upgraded from XF 1.4.2 to XF 1.4.4. This makes me think that maybe there is something new in 1.4.3 or 1.4.4 that is using a lot of memory?

You need configure php-fpm so it dump error logs to disk via the directives:

php_admin_value[error_log] = /var/log/php-fpm/forum-error.log
php_admin_flag[log_errors] = on

Your php-fpm user needs write access to this directory! So be careful otherwise php will silently discard errors.

Additionally, you can do conditional logging of access logs in nginx and should be able to for other webservers.

And... why XenForo isn't catching this error in the Server Error Log?

Because it is out of memory, so the error handler can't run.

OOM conditions are non-trivial to safely handle (or even at all).

 

[imthebest]

@Xon PHP errors are being logged to a file called php.log on my system, that's from where I got the OOM logs posted on the first post of this thread.

Btw even when I believe that in this case the problem isn't related to the report system I have made the following suggestion: New automatic status for unattended reports based on start date (or last comment date if apply)

 

[Jim Boy]

Access logs are disabled at the web server because it's a big site with a lot of traffic.

You should configure the web server to only log error messages

 

[imthebest]

I can't find anything related to these PHP OOM errors on my Apache error logs (I'm using nginx as reverse proxy for images while Apache is serving PHP files).

How I can find what URL is causing this problem?

 

[imthebest]

This problem isn't XenForo related but XenForo Media Gallery 1.0.2.

If you're interested you can follow up here: https://xenforo.com/community/threa...rors-when-viewing-user-profiles-random.91031/

 

[Chris D]

It isn't XenForo Media Gallery related.

 

[imthebest]

Well, I have been able to reproduce the problem.
It appears randomly when viewing member profiles... I'll keep an eye to try to identify the offending query.

 

[Mike]

Well the standard queries on the profile are all well limited, returning only a few results or results based on specific IDs. As such, if it's part of that page specifically, it may well be from an add-on.

There is also a definite possibility of it being related to the reports that you have open; this value has to be calculated in some scenarios so it could be triggering an issue (though I would imagine that you'd hear from a moderator in that case).

 

[Jim Boy]

I can't find anything related to these PHP OOM errors on my Apache error logs (I'm using nginx as reverse proxy for images while Apache is serving PHP files).

How I can find what URL is causing this problem?

If you're send errors to a defined php log, you may have to do a time based comparison between the two logs. You could also just turn off the php log and let it send any errors direct to the webserver log.

This is assuming that it is being triggered through a url call, it could be related to some task being called via deferred.php.

If you can reliably reproduce the error, does debug suggest excessive memory usage? Look for any query which returns an excessive number of rows.

If your saying that it only sometimes happens, then it could be something that only runs once in a while when it cant find something in cache. During a quiet period, disable the cache in config.php and then trial. What add-ons have you got installed?

 

[imthebest]

When I'm able to replicate this issue I have noticed that disabling any add-on fixes the problem. Then if I re-enable that add-on the problem doesn't come back until a few minutes when it starts filling my php.log file again with those annoying OOMs...

This is driving me crazy.

 

[Jim Boy]

Any add-on? Weird....

Are you blank pages, or getting reports of blank pages? If it runs out of memory whilst rendering a page, you would most likely see a white screen with nothing else.

If not, then it could be an issue with a deferred job, either a cron task or a another entry from another add-on.

To troubleshoot this, temporarily disable the deferred job by removing the deferred trigger in the PAGE_CONTAINER template, remove "{xen:if $hasAutoDeferred, RunDeferred}" from the second line.

Then see what is in the deferred queue by doing "SELECT *, from_unixtime(trigger_date) FROM xf_deferred" in mysql. The standard entries are 'cron, mailqueue and emailbounce', other entries will be addons.

Wait a minute or until the final value from the last column has passed, then from a command line go to to your forum directory and run "php deferred.php" and take note of the output, if normal it should say something like "{"moreDeferred":false}". Check the error log and see if any OOM messages have been created at this time.

Dont forget to re-enable the deferred run by editing PAGE_CONTAINER