nextcloud / server

☁️ Nextcloud server, a safe home for all your data
https://nextcloud.com
GNU Affero General Public License v3.0
26.64k stars 3.99k forks source link

twice running cron.php / GenerateMetadataJob #43184

Open cypress-hill-car opened 7 months ago

cypress-hill-car commented 7 months ago

Due to problems with the endlessly running cron.php, I identified the issue by finding the "long running job." By obtaining the start time of the PID from ps and searching the logs, I discovered that the issue lies with the "GenerateMetadataJob," which is hanging. This job starts but never receives a "Finished" event:

{"reqId":"T7WSKkyswz0F035LClQ6","level":0,"time":"2024-01-27T10:00:03+00:00","remoteAddr":"","user":"--","app":"cron","method":"","url":"--","message":"Run OC\Core\BackgroundJobs\GenerateMetadataJob job with ID 36764","userAgent":"--","version":"28.0.1.1","data":{"app":"cron"}}

Additionally, the job is running twice or more:

[picard@borgcube ~]$ ps aux | grep -E "^http.*?cron.php$"
http     1944203 97.1  0.0 428316  4072 ?        R    Jan27 2821:33 php -f /srv/http/nextcloud/cron.php
http     1999635 96.8  0.2 428316 23768 ?        R    Jan28 1414:10 php -f /srv/http/nextcloud/cron.php
http     2055241 98.2  0.9 428316 75584 ?        R    11:05  19:55 php -f /srv/http/nextcloud/cron.php

[picard@borgcube ~]$ ps -p 1944203 -o lstart
                 STARTED
 Sat Jan 27 11:00:01 2024
[picard@borgcube ~]$ ps -p 1999635 -o lstart
                 STARTED
 Sun Jan 28 11:05:01 2024
[picard@borgcube ~]$ ps -p 2055241 -o lstart
                 STARTED
 Mon Jan 29 11:05:01 2024

I'm not sure why this is happening, but I have an idea that it might be related to symlinks and/or multiple mounted devices.

Additionally, while investigating this issue, I read some code and would like to recommend changing the "funny if/else construct" for checking "onlyTimeSensitive" at line 122ff in cron.php with this single line:

$onlyTimeSensitive = ($currentHour >= $startHour) == ($currentHour > $endHour);

Thanks a lot!

cypress-hill-car commented 7 months ago

Update

I tried the following:

pjft commented 1 month ago

I agree with this report in that the GenerateMetaData takes too long, but I'm not convinced that that OCC command runs the exact same job.

When the cron job is running, if you start mysql and query the oc_files_metadata table, at least in my case I keep seeing new items being added. Alas, when I run the OCC task, it doesn't seem to create them - or maybe it just does all files, so it starts from the beginning and I just don't let it run to the end.

This is the query I'm running:

select * from oc_files_metadata inner join oc_filecache on file_id = fileid order by id desc limit 10;

and, in fact, just running

select * from oc_files_metadata order by id desc limit 10;

should show you new records.

In my case, I have over 1M entries in filecache, but 700k in metadata, so I imagine that it needs to run to the end. Alas, a regular maintenance reboot on my server stopped the cron job halfway through so I imagine it'll now need to be triggered again at some point.