Cron.php hangs causing 100% cpu load

flotillaropes · May 21, 2021, 2:33am

Support intro

Sorry to hear you’re facing problems

help.nextcloud.com is for home/non-enterprise users. If you’re running a business, paid support can be accessed via portal.nextcloud.com where we can ensure your business keeps running smoothly.

In order to help you as quickly as possible, before clicking Create Topic please provide as much of the below as you can. Feel free to use a pastebin service for logs, otherwise either indent short log examples with four spaces:

example

Or for longer, use three backticks above and below the code snippet:

longer
example
here

Some or all of the below information will be requested if it isn’t supplied; for fastest response please provide as much as you can

Nextcloud version (eg, 20.0.5): 21.0.2
Operating system and version (eg, Ubuntu 20.04): Raspbian GNU/Linux 10 (buster)
Apache or nginx version (eg, Apache 2.4.25): nginx/1.14.2
PHP version (eg, 7.4): v8.0.5

The issue you are facing:
cron.php script hangs causing cpu usage of 100%

Is this the first time you’ve seen this error? (Y/N): Y

Steps to replicate it:

Just run cron.php every 5 mins in cron job

On first run and then every 12 hrs cron.php hangs and will run forever unless I manually kill it. It runs my cpu at 100%. All other times it runs fine.

I’ve checked my date.timezone in /etc/php/8.0/fpm/php.ini and /etc/php/8.0/cli/php.ini. And it’s set correctly. I’ve set the correct time zone for logging: timedatectl set-timezone

I’ve checked nextcloud log and it’s clean.

Attached strace to the process and this set of lines keeps repeating indefinitely until I kill it with Ctrl C

strace: Process 7485 attached
gettimeofday({tv_sec=1621744604, tv_usec=617061}, NULL) = 0
gettimeofday({tv_sec=1621744604, tv_usec=617257}, NULL) = 0
gettimeofday({tv_sec=1621744604, tv_usec=617765}, NULL) = 0
openat(AT_FDCWD, “/var/nc_data/nextcloud.log”, O_WRONLY|O_CREAT|O_APPEND|O_LARGEFILE, 0666) = 8
fstat64(8, {st_mode=S_IFREG|0640, st_size=516978614, …}) = 0
_llseek(8, 0, [0], SEEK_CUR) = 0
_llseek(8, 0, [0], SEEK_CUR) = 0
write(8, “{"reqId":"u0xEDjzmdegIXMaIQmZz",”…, 1768) = 1768
close(8)

cron.php runs under the php process. This started with php 8 so I surmise it may be an obscure bug with php 8. I noticed this issue because my fanshim LED turns red when my server is hot and it was red with no load so I investigated. If not for the red LED I would have been unaware of the issue. As such, I’m curious if others are experiencing this issue, but are unaware.

For others running php 8, I urge you to check sudo htop once a day and sort by CPU to check if it is hanging. If so, you should see it similar to the image posted above. If so, please report on this thread. Thank you.

Seeking assistance troubleshooting. Thank you!

tflidd · May 24, 2021, 9:45am

Do you use APCU?

flotillaropes · May 24, 2021, 5:35pm

Yes, I’m using APCU, but I can run occ commands fine from the command line so I’m missing the connection to my issue. Also, FYI, when I setup my nextcloud server I issued this line: sed -i '$aapc.enable_cli=1' /etc/php/8.0/mods-available/apcu.ini so all good.

I don’t know the effects of not running cron.php, but for now, I have no choice but to turn off cron.php as I can’t have it hang twice a day and burn my CPU at 100% forever unless I manually kill it. It’s impractical for me to be around to kill cron.php twice a day.

I"m totally baffled!

tflidd · May 25, 2021, 9:16am

Or just don’t run cron automatically just from time to time. You need to check the logs a bit. There are already topics around php8 incompabilities:

github.com/nextcloud/server

Several incompatibilites with PHP 8.0

opened 10:44AM - 26 Feb 21 UTC

TheColin21

1. to develop bug technical debt

### How to use GitHub * Please use the 👍 [reaction](https://blog.github.com/2016-03-10-add-reactions-to-pull-requests-issues-and-comments/) to show that you are affected by the same issue. * Please don't comment if you have no relevant information to add. It's just extra noise for everyone subscribed to this issue. * Subscribe to receive notifications on status change and new comments. ### Steps to reproduce 1. Install/Upgrade Nextcloud 21 2. Activate PHP 8 3. Watch the log grow ### Expected behaviour not that many errors ### Actual behaviour following errors showing up in the log repeatedly: ``` Error: Required parameter $internalPath follows optional parameter $mountId at /path/to/cloud/lib/private/Files/Config/CachedMountFileInfo.php#34 Error: Required parameter $tagManager follows optional parameter $fileIdentifier at /path/to/cloud/apps/files/lib/Helper.php#220 Error: The method "setFormatter" is deprecated. Use "setOutputStyle" instead. at /path/to/cloud/3rdparty/scssphp/scssphp/src/Compiler.php#5177 Error: Formatters other than Expanded and Compressed are deprecated. at /path/to/cloud/3rdparty/scssphp/scssphp/src/Compiler.php#5175 Error: Ignoring Sass errors is not longer supported. at /path/to/cloud/3rdparty/scssphp/scssphp/src/Compiler.php#5530 Error: ob_end_clean(): Failed to delete buffer. No buffer to delete at /path/to/cloud/lib/private/Files/View.php#449 Error: usort(): Returning bool from comparison function is deprecated, return an integer less than, equal to, or greater than zero at /path/to/cloud/lib/public/AppFramework/Http/Template/PublicTemplateResponse.php#101 ``` ### Server configuration **Operating system:** Ubuntu 20.04 **Web server:** Apache **Database:** MariaDB 10.5.9 **PHP version:** 8.0.2 **Nextcloud version:** (see Nextcloud admin page) 21.0.0 **Updated from an older Nextcloud/ownCloud or fresh install:** Update from 20.0.8 **Where did you install Nextcloud from:** official website **Signing status:** <details> <summary>Signing status</summary> No errors have been found. </details> **List of activated apps:** <details> <summary>App list</summary> Enabled: - accessibility: 1.7.0 - activity: 2.14.3 - admin_audit: 1.11.0 - breezedark: 21.0.1 - camerarawpreviews: 0.7.10 - checksum: 1.0.1 - cloud_federation_api: 1.4.0 - comments: 1.11.0 - contactsinteraction: 1.2.0 - dashboard: 7.1.0 - dav: 1.17.1 - documentserver_community: 0.1.9 - extract: 1.3.1 - federatedfilesharing: 1.11.0 - federation: 1.11.0 - files: 1.16.0 - files_antivirus: 3.1.2 - files_downloadactivity: 1.10.0 - files_external: 1.12.0 - files_pdfviewer: 2.1.0 - files_rightclick: 1.0.0 - files_sharing: 1.13.1 - files_texteditor: 2.14.0 - files_trashbin: 1.11.0 - files_versions: 1.14.0 - files_videoplayer: 1.10.0 - firstrunwizard: 2.10.0 - imageconverter: 1.3.1 - impersonate: 1.8.0 - logreader: 2.6.0 - lookup_server_connector: 1.9.0 - mail: 1.8.3 - maps: 0.1.8 - notifications: 2.9.0 - oauth2: 1.9.0 - onlyoffice: 6.3.0 - password_policy: 1.11.0 - passwords: 2021.2.0 - photos: 1.3.0 - previewgenerator: 3.1.1 - privacy: 1.5.0 - provisioning_api: 1.11.0 - recommendations: 1.0.0 - serverinfo: 1.11.0 - settings: 1.3.0 - sharebymail: 1.11.0 - spreed: 11.0.0 - support: 1.4.0 - survey_client: 1.9.0 - systemtags: 1.11.0 - text: 3.2.0 - theming: 1.12.0 - twofactor_backupcodes: 1.10.0 - updatenotification: 1.11.0 - user_ldap: 1.11.0 - user_status: 1.1.1 - viewer: 1.5.0 - weather_status: 1.1.0 - workflowengine: 2.3.0 Disabled: - bruteforcesettings - encryption - facerecognition - files_fulltextsearch - fulltextsearch - fulltextsearch_elasticsearch - nextcloud_announcements - ransomware_protection </details> **Nextcloud configuration:** <details> <summary>Config report</summary> { "system": { "instanceid": "***REMOVED SENSITIVE VALUE***", "passwordsalt": "***REMOVED SENSITIVE VALUE***", "secret": "***REMOVED SENSITIVE VALUE***", "trusted_domains": [ "cloud.clnp.eu", "cloud.saef-zf.de" ], "datadirectory": "***REMOVED SENSITIVE VALUE***", "dbtype": "mysql", "version": "21.0.0.18", "overwrite.cli.url": "https:\/\/cloud.clnp.eu", "dbname": "***REMOVED SENSITIVE VALUE***", "dbhost": "***REMOVED SENSITIVE VALUE***", "dbport": "", "dbtableprefix": "oc_", "mysql.utf8mb4": true, "dbuser": "***REMOVED SENSITIVE VALUE***", "dbpassword": "***REMOVED SENSITIVE VALUE***", "installed": true, "mail_smtpmode": "sendmail", "mail_from_address": "***REMOVED SENSITIVE VALUE***", "mail_domain": "***REMOVED SENSITIVE VALUE***", "memcache.local": "\\OC\\Memcache\\APCu", "updater.release.channel": "stable", "loglevel": 0, "maintenance": false, "theme": "", "app_install_overwrite": [ "camerarawpreviews", "files_texteditor", "extract", "documentserver_community", "ocdownloader" ], "ldapIgnoreNamingRules": false, "ldapProviderFactory": "OCA\\User_LDAP\\LDAPProviderFactory", "default_language": "de", "default_locale": "de", "default_phone_region": "DE" } } </details> **Are you using external storage, if yes which one:** local/smb/sftp/... local, sftp, nextcloud **Are you using encryption:** yes/no no **Are you using an external user-backend, if yes which one:** LDAP/ActiveDirectory/Webdav/... no

For a bug report, more specific errors from logfiles would be helpful. What is strange that your strace shows an error with the logfile, is this always the same or just by chance?

flotillaropes · May 25, 2021, 8:38pm

Yes, when I connect the running process to strace, the output is always the same set of lines posted above. I did also notice the error with nextcloud.log file. You asked for additional log files. Specifically which ones would be helpful? And I will happily post.

I have created a “hack” workaround for this. It shouldn’t be necessary, but it works for now.

sudo crontab -e

check every 5 mins if cron.php is running for > 5 mins and if so kill it
*/5 * * * * killall -q -u www-data --older-than 5m php

I decided to comment out the above killall workaround and alternatively try another. I installed php 7.4 and set it as default so cron.php will run under php 7.4

Nextlcoud will continue to use php 8 for performance, but cron.php will use php 7.4.

I’m testing whether cron.php will hang if run under php 7.4 and will follow up with the results in a day or so as the hang happens about once every 12 hrs.

flotillaropes · May 26, 2021, 3:26pm

Update: running cron.php under php 7.4 did not resolve the issue. Again this morning after approximately 144 successful runs (12 hrs X 60), cron.php hangs again. I’ve now confirmed it happens under php 7.4 and php 8. This is a serious issue as it will run forever and probably eventually toast my CPU. It requires intervention to manually kill it.

strace shows this output:

strace: Process 11073 attached, infinitely repeats this set of lines:

strace: Process 11073 attached
gettimeofday({tv_sec=1622041051, tv_usec=683497}, NULL) = 0
openat(AT_FDCWD, “/var/nc_data/nextcloud.log”, O_WRONLY|O_CREAT|O_APPEND|O_LARGEFILE, 0666) = 7
fstat64(7, {st_mode=S_IFREG|0644, st_size=766162626, …}) = 0
_llseek(7, 0, [0], SEEK_CUR) = 0
_llseek(7, 0, [0], SEEK_CUR) = 0
write(7, “{“reqId”:“some long string”,”…, 1772) = 1772
close(7) = 0
gettimeofday({tv_sec=1622041051, tv_usec=685381}, NULL) = 0
gettimeofday({tv_sec=1622041051, tv_usec=685592}, NULL) = 0
gettimeofday({tv_sec=1622041051, tv_usec=685941}, NULL) = 0
openat(AT_FDCWD, “/var/nc_data/nextcloud.log”, O_WRONLY|O_CREAT|O_APPEND|O_LARGEFILE, 0666) = 7
fstat64(7, {st_mode=S_IFREG|0644, st_size=766164398, …}) = 0
_llseek(7, 0, [0], SEEK_CUR) = 0
_llseek(7, 0, [0], SEEK_CUR) = 0
write(7, “{“reqId”:“some long string”,”…, 1772) = 1772
close(7)

I’m totally baffled as to why this is happening.

tflidd · May 26, 2021, 5:34pm

Your nextcloud.log is not empty I suppose?

Or it is full and tries to rotate it? You can also start the cron.php from command line, perhaps with -vvv you can make it more verbose and it shows you where it fails…

flotillaropes · May 26, 2021, 5:37pm

The log is not empty, but is set to rotate:

-rw-r----- 1 www-data www-data 70273 May 26 10:35 nextcloud.log
-rw-r–r-- 1 www-data www-data 1531475418 May 26 08:15 nextcloud.log.1

Is there a way to capture the output from the cron job which is running cron.php every 5 minutes?

tflidd · May 26, 2021, 5:40pm

There is a table in the database with all the jobs for cron. If you have ‘exotic’ things from apps that few people are using, I’d disable these apps temporarily.

flotillaropes · May 26, 2021, 5:46pm

My oc_jobs table has 60 rows. I’m not using any “exotic” apps that I know of. Is 60 rows about what is expected?

tflidd · May 26, 2021, 5:53pm

My joblist is at 25 entries (most of them an upload folder cleanup for one specific user…). But you can see which job was run for the last time, so perhaps you can find at which job it usually stops since the jobs behind are not executed any more.

flotillaropes · May 26, 2021, 5:54pm

I see the last run col, but it’s a number. How can they be converted to a date?

flotillaropes · May 26, 2021, 6:27pm

Can I safely delete all rows in the oc_jobs table? Will the apps recreate the necessary rows?

tflidd · May 26, 2021, 8:57pm

https://www.unixtimestamp.com/

Unless there is an obvious problem, I wouldn’t do that. If it is related to an app, I would rather disable it and enable it later. Not sure what happens with other crojobs if you delete them, if you can restore them or if you need to retrieve from a backup.

flotillaropes · May 27, 2021, 6:15am

Well, looks like we are getting somewhere. I cleared out the log file, set logging level to 1 and manually ran the cron.php. As expected it hung, but this time I caught something in the trap. It ran for only a few mins at most, before I did a Ctrl C to kill it.

I checked the nextcloud log and…

The bookmarks app is suspect as the cause of the hang. This error occurred over 531,000 times in the log! Wow!

I then manually ran cron.php again and it hangs. I ran it a third time and no hang. This is still the mystery. Why would it not hang all the time? Why hang, then fine for approx 12 hrs?

When it runs fine, no log errors of course. But the code in cron.php looks like ti should be writing a “core” with “lastcron” to the logfile. I checked the logs and don’t see it.

I will disable bookmarks app for a day and see what happens with cron.php

flotillaropes · May 27, 2021, 3:49pm

Bug report has already been filed with bookmarks

github.com/nextcloud/bookmarks

Bookmarks + PHP8.0 breaks cron jobs

opened 08:23AM - 15 May 21 UTC

flash-me

bug

**Describe the bug** Using PHP 8 breaks cron jobs of nextcloud when bookmarks… is installed, because of its dependency to [andreskrey/readability.php](https://github.com/andreskrey/readability.php). This is due a deprecated implementation of the `usort()` [callback, which returns a bool](https://github.com/andreskrey/readability.php/blob/master/src/Readability.php#L198). There is already an reported issue with [php 7.4](https://github.com/andreskrey/readability.php/issues/99) **To Reproduce** Steps to reproduce the behavior: 1. Use php8.0 2. Install bookmarks 3. Go to admin logging 4. See error **Expected behavior** PHP 8.0 compatibility. **Screenshots** ![image](https://user-images.githubusercontent.com/5240450/118353431-70e0bb80-b566-11eb-9408-dc7983493448.png) **Server (please complete the following information):** - PHP version: [8.0] - Nextcloud version: [21.0.1] - Bookmarks app version: [4.2] **Additional context** ### Workaround changing to line in `nextcloud/apps/bookmarks/vendor/andreskrey/readability.php/src/Readability.php#199` to this solves the issue for now ```php return (int)($a['textLength'] < $b['textLength']); ``` **Nextcloud log (nextcloud/data/nextcloud.log)** ``` { "reqId": "4aGNoFm1iLPZA3G1oxik", "level": 3, "time": "2021-05-15T09:52:30+02:00", "remoteAddr": "", "user": "--", "app": "PHP", "method": "", "url": "--", "message": { "Exception": "Error", "Message": "usort(): Returning bool from comparison function is deprecated, return an integer less than, equal to, or greater than zero at /var/www/nextcloud/apps/bookmarks/vendor/andreskrey/readability.php/src/Readability.php#199", "Code": 0, "Trace": [ { "function": "onError", "class": "OC\\Log\\ErrorHandler", "type": "::" }, { "file": "/var/www/nextcloud/apps/bookmarks/vendor/andreskrey/readability.php/src/Readability.php", "line": 199, "function": "usort" }, { "file": "/var/www/nextcloud/apps/bookmarks/lib/Service/CrawlService.php", "line": 124, "function": "parse", "class": "andreskrey\\Readability\\Readability", "type": "->" }, { "file": "/var/www/nextcloud/apps/bookmarks/lib/Service/CrawlService.php", "line": 105, "function": "archiveContent", "class": "OCA\\Bookmarks\\Service\\CrawlService", "type": "->" }, { "file": "/var/www/nextcloud/apps/bookmarks/lib/BackgroundJobs/CrawlJob.php", "line": 68, "function": "crawl", "class": "OCA\\Bookmarks\\Service\\CrawlService", "type": "->" }, { "file": "/var/www/nextcloud/lib/public/BackgroundJob/Job.php", "line": 80, "function": "run", "class": "OCA\\Bookmarks\\BackgroundJobs\\CrawlJob", "type": "->" }, { "file": "/var/www/nextcloud/lib/public/BackgroundJob/TimedJob.php", "line": 61, "function": "execute", "class": "OCP\\BackgroundJob\\Job", "type": "->" }, { "file": "/var/www/nextcloud/cron.php", "line": 128, "function": "execute", "class": "OCP\\BackgroundJob\\TimedJob", "type": "->" } ], "File": "/var/www/nextcloud/lib/private/Log/ErrorHandler.php", "Line": 92, "CustomMessage": "--" }, "userAgent": "--", "version": "21.0.1.1" } ``` cheers flash ⚡

flotillaropes · May 28, 2021, 8:22pm

This is the fix per bookmarks developer:

As a workaround, this fix works until the issue is fixed.

Temporarily manually remove these 3 jobs from the oc_jobs table:

OCA\Bookmarks\Lib\BackgroundJobs\PreviewsJob
OCA\Bookmarks\BackgroundJobs\PreviewsJob
OCA\Bookmarks\BackgroundJobs\CrawlJob

Whenever you re-enable the app, the jobs will be parsed again from info.xml and added to the database again if they’re not there, yet

marcelklehr · May 31, 2021, 9:33pm

Correction, this is not the fix, this is a workaround. I will release a real fix with the next patch soon.

marcelklehr · June 10, 2021, 12:39pm

v4.2.2 is out now, which should fix this.

famgala · July 24, 2023, 5:15pm

Is it possible this was reintroduced? I’ve been having this very similar problem. I’ve disabled bookmarks app for now, and it appears to be working as expected, though i’ll need a day or two to confirm.