Division by zero in file 'apps/settings/lib/Controller/CheckSetupController.php' line 503

[nursoda]

I just updated via settings/admin/overview from 23.0.0 to 23.0.1 RC1 (on beta channel), then reloaded settings/admin/overview three times. The first two times there was a warning that I shall update indices via occ or similar, since the third time I always get this error on settings/admin/logging:

Error | index | Exception: Division by zero in file 'apps/settings/lib/Controller/CheckSetupController.php' line 503

and in nextcloud.log respectively:

{"reqId":"pqpQOpO430mjkur7IQbW","level":3,"time":"2022-01-07T16:58:28+01:00","remoteAddr":"192.168.1.2","user":"admin","app":"index","method":"GET","url":"/settings/ajax/checksetup","message":"Division by zero in file 'apps/settings/lib/Controller/CheckSetupController.php' line 503","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:95.0) Gecko/20100101 Firefox/95.0","version":"23.0.1.0","exception":{"Exception":"Exception","Message":"Division by zero in file 'apps/settings/lib/Controller/CheckSetupController.php' line 503","Code":0,"Trace":[{"file":"lib/private/AppFramework/App.php","line":157,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"lib/private/Route/Router.php","line":302,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"lib/base.php","line":1006,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"index.php","line":36,"function":"handleRequest","class":"OC","type":"::"}],"File":"lib/private/AppFramework/Http/Dispatcher.php","Line":158,"Previous":{"Exception":"DivisionByZeroError","Message":"Division by zero","Code":0,"Trace":[{"file":"apps/settings/lib/Controller/CheckSetupController.php","line":821,"function":"getOpcacheSetupRecommendations","class":"OCA\\Settings\\Controller\\CheckSetupController","type":"->"},{"file":"lib/private/AppFramework/Http/Dispatcher.php","line":217,"function":"check","class":"OCA\\Settings\\Controller\\CheckSetupController","type":"->"},{"file":"lib/private/AppFramework/Http/Dispatcher.php","line":126,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"lib/private/AppFramework/App.php","line":157,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"lib/private/Route/Router.php","line":302,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"lib/base.php","line":1006,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"index.php","line":36,"function":"handleRequest","class":"OC","type":"::"}],"File":"apps/settings/lib/Controller/CheckSetupController.php","Line":503},"CustomMessage":"--"}}

Operating system: Arch Linux
Web server: NGINX
Database: MariaDB
PHP version: 8.0

[solracsf]

Can you replace lines 503-505 of that file

server/apps/settings/lib/Controller/CheckSetupController.php

Lines 503 to 505 in 5598638

	if ($status['interned_strings_usage']['used_memory'] / $status['interned_strings_usage']['free_memory'] > 9) {
	$recommendations[] = 'The OPcache interned strings buffer is nearly full. To assure that repeating strings can be effectively cached, it is recommended to apply <code>opcache.interned_strings_buffer</code> to your PHP configuration with a value higher than <code>' . ($this->iniGetWrapper->getNumeric('opcache.interned_strings_buffer') ?: 'currently') . '</code>.';
	}

by

if (!empty($status['interned_strings_usage'])) {
	if ($status['interned_strings_usage']['used_memory'] / $status['interned_strings_usage']['free_memory'] > 9) {
		$recommendations[] = 'The OPcache interned strings buffer is nearly full. To assure that repeating strings can be effectively cached, it is recommended to apply <code>opcache.interned_strings_buffer</code> to your PHP configuration with a value higher than <code>' . ($this->iniGetWrapper->getNumeric('opcache.interned_strings_buffer') ?: 'currently') . '</code>.';
	}
}

and check if error is fixed?

[MichaIng]

Thanks for reporting. I'll add a check for the value being zero, before doing the division. It makes sense that during updates, where the cache is invalidated, there are short time frames where the interned strings buffer has not been used yet.

@acsfer
Thanks, just verified that empty(0) is false 🙂. I'll apply this to all three checks. It is actually impossible in case of the other two, since at least CheckSetupController.php itself should be in the cache already, as one key and non-zero usage, but it doesn't hurt to cover all edge cases.

EDIT: Ah, it's free strings buffer which is divided by. Now I'm wondering, if zero internet strings buffer is free, then the warning should actually be shown 🤔.

@nursoda
Could you show your actual OPcache stats, please, e.g. by creating this little test PHP script:

<?php echo '<pre>'; print_r(opcache_get_status(false)); echo '</pre>';

[nursoda]

test.php yields

Array
(
    [opcache_enabled] => 1
    [cache_full] => 1
    [restart_pending] => 
    [restart_in_progress] => 
    [memory_usage] => Array
        (
            [used_memory] => 134181200
            [free_memory] => 33432
            [wasted_memory] => 3096
            [current_wasted_percentage] => 0.0023066997528076
        )

    [interned_strings_usage] => Array
        (
            [buffer_size] => 6291008
            [used_memory] => 6291008
            [free_memory] => 0
            [number_of_strings] => 85777
        )

    [opcache_statistics] => Array
        (
            [num_cached_scripts] => 6581
            [num_cached_keys] => 12256
            [max_cached_keys] => 16229
            [hits] => 8431707
            [start_time] => 1641489929
            [last_restart_time] => 1641570853
            [oom_restarts] => 0
            [hash_restarts] => 0
            [manual_restarts] => 2
            [misses] => 871079
            [blacklist_misses] => 0
            [blacklist_miss_ratio] => 0
            [opcache_hit_rate] => 90.636364203154
        )

    [jit] => Array
        (
            [enabled] => 
            [on] => 
            [kind] => 5
            [opt_level] => 4
            [opt_flags] => 6
            [buffer_size] => 0
            [buffer_free] => 0
        )

)

[nursoda]

Can you replace lines 503-505 of that file […] by […] and check if error is fixed?

I inserted the !empty check and the error persists, now in line 504…which is logical since the array does contain data but free_memory yields "0". Strange, that does free_memory mean here? Here's my output of the free command:

              gesamt       benutzt     frei      gemns.  Puffer/Cache verfügbar
Speicher:   32773768     1411432    17758344      145112    13603992    30749904
Swap:       16674812           0    16674812

[nursoda]

It's free strings buffer which is divided by. Now I'm wondering, if zero internet strings buffer is free, then the warning should actually be shown.

That server was booted just a day ago and did run without opcache issues for at least two years now, including all NC updates done the same way. So, what is special about NC23.0.1RC1 that causes opcache to be full after just a few minutes?

[nursoda]

After inserting empty($status['interned_strings_usage']['free_memory']) || in line (now 504 due to the !empty check), I now get the intended warning instead of the error:

The PHP OPcache module is not properly configured:

    The OPcache buffer is nearly full. To assure that all scripts can be hold in cache, it is recommended to apply opcache.memory_consumption to your PHP configuration with a value higher than 128.
    The OPcache interned strings buffer is nearly full. To assure that repeating strings can be effectively cached, it is recommended to apply opcache.interned_strings_buffer to your PHP configuration with a value higher than 8.

What I consider strange about this is that I never saw this warning in the last two years, in fact never since I run NCs on my machines. So, the only thing I changed was … the update to NC 23.0.1 RC1.

[MichaIng]

Okay, so the OPcache interned strings buffer was completely filled. In this case the aim is to show a warning that it should be increased. In your PHP settings, you can do that via opcache.internet_strings_buffer=16, which doubles it to effectively 12 MiB (25% are space for metadata). But the whole OPcache is also nearly full, hence it makes sense to raise it as well, e.g. opcache.memory_consumption=256.

Strange, that does free_memory mean here? Here's my output of the free command:

It is not about the system memory, but the amount of memory which the PHP OPcache is allowed to use, for caching PHP scripts in opcode, to increase access performance.

What I consider strange about this is that I never saw this warning in the last two years

Prior to NC23, the admin panel basically checked whether the default values (or higher) for OPcache are applied, and if not showed a recommendation to apply the defaults. Now the recommendation is based on the actual usage, hence when any of the three possible OPcache limits (number of cached keys/strings, overall memory usage, interned strings buffer) is more than 90% filled, you see a recommendation to raise the setting.

However, actually I tried hard to get the default 128 MiB OPcache filled with a test Nextcloud instance by installing and accessing literally all available apps, and I wasn't able to reach more than a little over 64 MiB only. So it is quite interesting that in your case 128 MiB are nearly fully used. Do you run other PHP applications on the same webserver/PHP instance?

[nursoda]

Do you run other PHP applications on the same webserver/PHP instance?

Yes. The server currently runs 9 NC instances, 3 WP instances and one Contao instance, all PHP based. And some handmade PHP scripts (called rarely).

I might have overdone it, but I set the opcache values as follows …

opcache.memory_consumption=128 → 1024
opcache.interned_strings_buffer=8 → 64
opcache.max_accelerated_files=10000 → 100000

… and restarted php-fpm. After that, I see "All checks passed." in settings/admin/overview and these opcache stats:

Array
(
    [opcache_enabled] => 1
    [cache_full] => 
    [restart_pending] => 
    [restart_in_progress] => 
    [memory_usage] => Array
        (
            [used_memory] => 133077232
            [free_memory] => 940664592
            [wasted_memory] => 0
            [current_wasted_percentage] => 0
        )

    [interned_strings_usage] => Array
        (
            [buffer_size] => 50331200
            [used_memory] => 6806056
            [free_memory] => 43525144
            [number_of_strings] => 86703
        )

    [opcache_statistics] => Array
        (
            [num_cached_scripts] => 3631
            [num_cached_keys] => 6927
            [max_cached_keys] => 130987
            [hits] => 13589
            [start_time] => 1641593154
            [last_restart_time] => 0
            [oom_restarts] => 0
            [hash_restarts] => 0
            [manual_restarts] => 0
            [misses] => 3631
            [blacklist_misses] => 0
            [blacklist_miss_ratio] => 0
            [opcache_hit_rate] => 78.914053426249
        )

    [jit] => Array
        (
            [enabled] => 
            [on] => 
            [kind] => 5
            [opt_level] => 4
            [opt_flags] => 6
            [buffer_size] => 0
            [buffer_free] => 0
        )

)

As I can confirm that the PR closes the issue, it's all fine with me now. Thanks for the explanation.

Yet, I expect the warning to propose reasonable values, not only "set it to more than [current setting]".

[MichaIng]

Yet, I expect the warning to propose reasonable values

That is practically impossible do achieve, I'm afraid 🤔. We can only see how much the OPcache is currently used, but we have no change to know how much would be used when raising the settings.

What could make sense is in case of the interned strings buffer is to show the next power of 2 as recommendation, since powers of 2 seem to be expected. Though other values work, it behaves a bit strange and is badly documented. I tried to get some clarification via PHP developers channel and StackExchange, but there are still open questions: https://stackoverflow.com/questions/67853338/opcache-interned-strings-buffer-size-lower-than-opcache-interned-strings-buffer

In case of the number of cached keys we should recommend to apply the next of the effectively used prime numbers: When e.g. 10000 is applied (the PHP default, funnily), it is rounded up to 16229, so it would make sense to show the next prime number in the first place: https://www.php.net/manual/de/opcache.configuration.php#ini.opcache.interned-strings-buffer
You see the same in your case, where 100,000 was rounded up to 130,987.

So in your case it could have been iterative, e.g. you double the settings until the recommendations are gone. At least there is now one, in your case with still plenty of free system RAM you may get a notable performance benefit 🙂.

I might have overdone it, but I set the opcache values as follows …

Looks like 😄. Btw, while the stats script works fine already, there is actually a nice GUI for monitoring and managing (invalidating all or individual scripts) the OPcache: https://github.com/amnuts/opcache-gui

[nursoda]

Thanks again for all the explanation, I think this "bug" is worth reading. opcache-gui is just "wget index.php" and using it, nice! The values I chose seem to be a little high but not insanely high since I see a opcache memory usage of 33% now (which I consider healthy) and a keys usage of 21% (which is a bit much but I don't care). Also I only see 16000 files (out of 130000).

Recommendation could have been iterative, e.g. you double the settings until the recommendations are gone.

I consider this a good proposal to users/admins. Probably not in the warning itself but in a section within the admin manual. Also, links to https://www.php.net/manual/en/opcache.configuration.php and https://github.com/amnuts/opcache-gui would be nice in the admin manual.

To me it's still unclear what impact max_accelerated_files has on memory usage and how it should be set in relation to memory_consumption and interned_strings_buffer. From the stackoverflow answer I deduct that interned_strings_buffer is a subset of memory_consumption, so a reasonaby ratio may be 1:4 or 1:100? But for max_accelerated_files?

you may get a notable performance benefit

I'd be happy if there were a speedup but I doubt it and don't have means to compare/measure it. As I already had basic opcache, redis is set up, my system does not use swap and is SSD only, I don't expect a leap in speed.

[MichaIng]

Too much info right in the admin panel isn't good either, the proposed changes to the Nextcloud documentation are here (which includes the two links you suggested 🙂): nextcloud/documentation#7859
What does make sense is to add a link to those docs (ones merged and fitting the recommendations), in case a recommendation is shown. I'll open another PR then.

To me it's still unclear what impact max_accelerated_files has on memory usage

Basically none, as long as the limit is not hit (it never was in your case).

From the stackoverflow answer I deduct that interned_strings_buffer is a subset of memory_consumption, so a reasonaby ratio may be 1:4 or 1:100?

Yes, the interned strings buffer is shown as "used" from the overall OPcache memory consumption right from the start, so increasing the interned strings buffer may require increasing the overall OPcache memory consumption as well. The default ratio is 128:8 = 16:1, but it depends highly on the applications. E.g. a forum or blog usually stores a lot more strings compared to Nextcloud. So best is to not think in ratios here but simply check the actual usage and increase (or reduce) the one or the other so that each is not full + has a little space to grow.

As I already had basic opcache, redis is set up, my system does not use swap and is SSD only, I don't expect a leap in speed.

Probably not. Also the 133077232 bytes used when you posted the stats above are ~128 MiB, so on that end, considering that likely not all scripts are regularly called, not much changed. But aside of access performance from user perspective, also CPU usage is an argument, since OPcache does not store the scripts but their ~partly compiled and optimised "opcode". So less processing on server side required when serving from OPcache compared to serving from the original script in PHP code.