System:cron makes many instances and CPU overloaded

Steps to reproduce

  1. Add occ system:cron in a cron
  2. Wait a few hours
  3. You can see a lot of cron instances and a CPU overloaded

Expected behaviour

The same behaviour than I had with cron.php : no CPU overloaded

Actual behaviour

Server configuration

Operating system: CentOS 7.7.1908

Web server: apache 2.4.6

Database: mariadb 5.5.64-1

PHP version: 7.2.25

ownCloud version: (see ownCloud admin page) 10.3.1-2.1

Updated from an older ownCloud or fresh install: Updated from 10.2.1

Where did you install ownCloud from: owncloud rpm

The content of config/config.php:

{
    "system": {
        "instanceid": "ocevydwjehjn",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "***REMOVED SENSITIVE VALUE***"
        ],
        "datadirectory": "\/owncloud\/data",
        "overwrite.cli.url": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "10.3.1.1",
        "dbname": "owncloud",
        "dbhost": "localhost",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "forcessl": true,
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "php",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "logfile": "\/var\/log\/owncloud\/owncloud.log",
        "loglevel": 1,
        "ldapIgnoreNamingRules": false,
        "maintenance": false,
        "app.mail.server-side-cache.enabled": true,
        "logtimezone": "Europe\/Paris",
        "default_language": "fr",
        "preview_libreoffice_path": "\/usr\/bin\/libreoffice",
        "preview_office_cl_parameters": " --headless --nologo --nofirststartwizard --invisible --norestore -convert-to pdf -outdir ",
        "theme": "",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "filelocking.enabled": true,
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "localhost",
            "port": 6379
        },
        "trashbin_retention_obligation": "auto",
        "updatechecker": false,
        "ldapUserCleanupInterval": "240",
        "singleuser": false,
        "activity_expire_days": 300,
        "onlyoffice": {
            "verify_peer_off": true
        },
        "excluded_directories": [
            "AppData"
        ]
    }
}

Are you using external storage, if yes which one: no

Are you using encryption: no

Are you using an external user-backend, if yes which one: LDAP

Before the issue, I had a cron with cron.php and everything was fine
*/15 * * * * php -f /var/www/html/owncloud/cron.php > /dev/null 2>&1

As suggested, I had recently changed my cron with system:cron
*/15 * * * * php -f /var/www/html/owncloud/occ system:cron -q

After one day, I noticed a overloaded CPU, nearly 100%, and I could see many cron instances. The first was not ended, that the other started, and the next again and again :

apache    8462  1.0  1.5 1975892 494228 ?      Ss   12:00   2:16 php -f /var/www/html/owncloud/occ system:cron -q
apache    9732  1.0  1.4 1945172 465740 ?      Ss   12:15   2:08 php -f /var/www/html/owncloud/occ system:cron -q
apache   11087  1.0  1.3 1912404 437296 ?      Ss   12:30   2:05 php -f /var/www/html/owncloud/occ system:cron -q
apache   12374  1.1  1.2 1967176 418756 ?      Ss   12:45   2:00 php -f /var/www/html/owncloud/occ system:cron -q
apache   15479  1.2  1.1 1830484 361220 ?      Ss   13:15   1:51 php -f /var/www/html/owncloud/occ system:cron -q
apache   16897  1.2  1.0 1816452 338364 ?      Ss   13:30   1:46 php -f /var/www/html/owncloud/occ system:cron -q
apache   19772  1.6  0.8 1742420 279716 ?      Ss   14:00   1:44 php -f /var/www/html/owncloud/occ system:cron -q
apache   22552  1.1  0.7 1717924 256440 ?      Ss   14:30   0:53 php -f /var/www/html/owncloud/occ system:cron -q
apache   23926  2.5  0.7 1703656 243428 ?      Ss   14:45   1:33 php -f /var/www/html/owncloud/occ system:cron -q
apache   25300  1.4  2.9 2420308 960892 ?      Ss   15:00   0:39 php -f /var/www/html/owncloud/occ system:cron -q
apache   26670  4.5  0.6 1672788 215932 ?      Ss   15:15   1:27 php -f /var/www/html/owncloud/occ system:cron -q
apache   28035  1.9  0.6 1652452 196116 ?      Ss   15:30   0:19 php -f /var/www/html/owncloud/occ system:cron -q
apache   29453  6.0  0.5 1648212 192164 ?      Ss   15:45   0:07 php -f /var/www/html/owncloud/occ system:cron -q

To solve the issue, I had to kill the processes.
After that, the CPU load decreased.

What should be the time between 2 cron ? 15 minutes was fine with cron.php, but makes an issue with system:cron

Regards

Did you change any of the following parameters recently?

  • file versioning
  • trashbin expiry

Have you had a look in the docs:
https://doc.owncloud.com/server/10.3/admin_manual/configuration/server/background_jobs_configuration.html#available-background-jobs

How many users do you have in your LDAP? And how many can ownCloud see?
Do you have an LDAP user sync job configured in your cron table?

Can you post the content of your oc_jobs table?
Analyze your owncloud log for the following messages:

{"reqId": [...],"message":"Started background job of class : OC\\BackgroundJob\\Legacy\\RegularJob with arguments : Array\n(\n    [0] => OCA\\Music\\Backgroundjob\\CleanUp\n    [1] => run\n)\n"}
{"reqId": [...],"message":"Finished background job, the job took : 0 seconds, this job is an instance of class : OC\\BackgroundJob\\Legacy\\RegularJob with arguments : Array\n(\n    [0] => OCA\\Music\\Backgroundjob\\CleanUp\n    [1] => run\n)\n"}

There should be a specific job that hasn’t finished in a long time, and now takes very long to complete.

With the following config.php you can also write every ownCloud cron log line into a special file:

  'log.conditions' => 
  array (
    0 => 
    array (
      'apps' => 
      array (
        0 => 'cron',
      ),
      'logfile' => '/path/to/your/data/directory/cron.log',
    ),
  ),

Making this analysis a little easier.

Hi eneubauer,

Thanks for your answer

Did you change any of the following parameters recently?
Yes. I changed the “activity_expire_days” from 365 to 300 in config.php.
It was because the size of the database was growing (20 GB) and I wanted to limit its volum.
But i did this change 2 weeks before the owncloud upgrade (owncloud 10.2.1) and I did not met any problems with cron.php

Have you had a look in the docs:
Yes.
I never used occ to make maintenance, just now I’ve moved from cron.php to system:cron, because it was recommended in the changelog.

How many users do you have in your LDAP? And how many can ownCloud see?
It’s quite strange. In web gui, I have this filter:
(&(&(&(objectclass=)(mail=))((employeeType=past*)))(!(jAccountType=generic)))
And no answers when I’m trying to count the users. But I think it was working in owncloud 10.2.1 because I remember that I tested this point. But maybe i’m wrong because with PHP cache, we do not know sometimes.
I changed my filter to a simplier filter:
(&(objectclass=)(mail=)(!(employeeType=past))(!(jAccountType=generic)))
And the result is quick : 262
So, I’m going to keep this second filter.
This result is the same that I have with the ldapsearch command. So it seems good.

(I noticed in the past a bug with users that left, so not in the filter (employeeType = past), but they can continue to log in owncloud. I think it is not normal, but my owncloud is working like this ! Maybe, It will be later an another issue for you :slightly_smiling_face:)

Do you have an LDAP user sync job configured in your cron table?
No

Can you post the content of your oc_jobs table?
No because my dump is too big and I have only the owncloud database with all tables (9 Go)

Analyze your owncloud log for the following messages:
I have one log per day. So if I search “background job” in all my logs; I can only find this pattern the day I met this issue.

{“reqId”:“O2ZhdVYVuzuTmibso4Wa”,“level”:3,“time”:“2019-12-18T14:05:33+01:00”,“remoteAddr”:"",“user”:"–",“app”:“core”,“method”:"–",“url”:"–",“message”:“Error while running background job (class: OC\Command\CommandJob, arguments: O:33:“OCA\Files_Trashbin\Command\Expire”:1:{s:39:”\u0000OCA\Files_Trashbin\Command\Expire\u0000user";s:36:“1b8c0e56-89a6-1037-9fb9-d1cde3f70cff”;}): {“Exception”:“Doctrine\\DBAL\\Exception\\DriverException”,“Message”:“An exception occurred while executing ‘DELETE FROM oc_filecache WHERE fileid = ?’ with params [17786257]:\n\nSQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction”,“Code”:0,“Trace”:"#0 \/var\/www\/html\/owncloud\/lib\/composer\/doctrine\/dbal\/lib\/Doctrine\/DBAL\/DBALException.php(128): Doctrine\\DBAL\\Driver\\AbstractMySQLDriver->convertException(‘An exception oc…’, Object(Doctrine\\DBAL\\Driver\\PDOException))\n#1 \/var\/www\/html\/owncloud\/lib\/composer\/doctrine\/dbal\/lib\/Doctrine\/DBAL\/Connection.php(855): Doctrine\\DBAL\\DBALException::driverExceptionDuringQuery(Object(Doctrine\\DBAL\\Driver\\PDOMySql\\Driver), Object(Doctrine\\DBAL\\Driver\\PDOException), ‘DELETE FROM oc...', Array)\\n#2 \\\/var\\\/www\\\/html\\\/owncloud\\\/lib\\\/private\\\/DB\\\/Connection.php(187): Doctrine\\\\DBAL\\\\Connection->executeQuery('DELETE FROMoc…’, Array, Array, NULL)\n#3 \/var\/www\/html\/owncloud\/lib\/private\/Files\/Cache\/Cache.php(448): OC\\DB\\Connection->executeQuery(‘DELETE FROM `oc…’, Array)\n#4 \/var\/www\/html\/owncloud\/lib\/private\/Files\/Cache\/Updater.php(158): OC\\Files\\Cache\\Cache->remove(‘files_trashbin\/…’)\n#5 \/var\/www\/html\/owncloud\/lib\/private\/Files\/View.php(339): OC\\Files\\Cache\\Updater->remove(‘files_trashbin\/…’)\n#6 \/var\/www\/html\/owncloud\/lib\/private\/Files\/View.php(1218): OC\\Files\\View->removeUpdate(Object(OCA\\Files_Trashbin\\Storage), ‘files_trashbin\/…’)\n#7 \/var\/www\/html\/owncloud\/lib\/private\/Files\/View.php(754): OC\\Files\\View->basicOperation(‘rmdir’, ‘\/files_trashbin…’, Array)\n#8 \/var\/www\/html\/owncloud\/lib\/public\/Events\/EventEmitterTrait.php(50): OC\\Files\\View->OC\\Files\\{closure}(Array)\n#9 \/var\/www\/html\/owncloud\/lib\/private\/Files\/View.php(766): OC\\Files\\View->emittingCall(Object(Closure), Array, ‘file’, ‘delete’)\n#10 \/var\/www\/html\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(711): OC\\Files\\View->unlink(‘files_trashbin\/…’)\n#11 \/var\/www\/html\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(684): OCA\\Files_Trashbin\\Trashbin::deleteVersions(Object(OC\\Files\\View), ‘rpu_flash.d1552…’, ‘rpu_flash’, ‘1552849204’, ‘1b8c0e56-89a6-1…’)\n#12 \/var\/www\/html\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(828): OCA\\Files_Trashbin\\Trashbin::delete(‘rpu_flash’, ‘1b8c0e56-89a6-1…’, ‘1552849204’)\n#13 \/var\/www\/html\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(788): OCA\\Files_Trashbin\\Trashbin::deleteFiles(Array, ‘1b8c0e56-89a6-1…’, -13949190329.5)\n#14 \/var\/www\/html\/owncloud\/apps\/files_trashbin\/lib\/Command\/Expire.php(56): OCA\\Files_Trashbin\\Trashbin::expire(‘1b8c0e56-89a6-1…’)\n#15 \/var\/www\/html\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Trashbin\\Command\\Expire->handle()\n#16 \/var\/www\/html\/owncloud\/lib\/private\/BackgroundJob\/Job.php(66): OC\\Command\\CommandJob->run(‘O:33:\"OCA\\\\Files…’)\n#17 \/var\/www\/html\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#18 \/var\/www\/html\/owncloud\/core\/Command\/System\/Cron.php(119): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#19 \/var\/www\/html\/owncloud\/lib\/composer\/symfony\/console\/Command\/Command.php(255): OC\\Core\\Command\\System\\Cron->execute(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#20 \/var\/www\/html\/owncloud\/lib\/composer\/symfony\/console\/Application.php(963): Symfony\\Component\\Console\\Command\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#21 \/var\/www\/html\/owncloud\/lib\/composer\/symfony\/console\/Application.php(254): Symfony\\Component\\Console\\Application->doRunCommand(Object(OC\\Core\\Command\\System\\Cron), Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#22 \/var\/www\/html\/owncloud\/lib\/composer\/symfony\/console\/Application.php(147): Symfony\\Component\\Console\\Application->doRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#23 \/var\/www\/html\/owncloud\/lib\/private\/Console\/Application.php(165): Symfony\\Component\\Console\\Application->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#24 \/var\/www\/html\/owncloud\/console.php(106): OC\\Console\\Application->run()\n#25 \/var\/www\/html\/owncloud\/occ(11): require_once(’\/var\/www\/html\/o…’)\n#26 {main}",“File”:"\/var\/www\/html\/owncloud\/lib\/composer\/doctrine\/dbal\/lib\/Doctrine\/DBAL\/Driver\/AbstractMySQLDriver.php",“Line”:115}"}

I knew with htop command that mysql did a lot of CPU at this moment

Before adding the system:cron in the crontab, I did a test with the command:

sudo -u apache php occ system:cron

I noticed it took at least 10 minutes the first time.
Then I reexecute immediatly the same command and it took less than 1 minute.
So I decided to add this crontab.

Now, if i execute again the command, I get a long wait at “23”, then it continues, again a long wait at “227”, and it doesn’t go any further. It did again mysql job.

time sudo -u apache php occ system:cron
227 [—>------------------------]
Complété

real 36m25.965s
user 0m58.845s
sys 0m12.729s

After more than 30 minues, I killed the process.
I do not know what thinking of this.But I prefer coming back with cron.php

I wanted to come back to cron.php, but it is impossible now:

sudo -u apache php cron.php
Please use ./occ system:cron
sh: ./occ: Permission non accordée

It’s very annoying, no cron works.
How can I do ?

I can not upload my oc_jobs, I have a message: “sorry new users can not upload attachments”

Here is the link on my owncloud:

occ_jobs

After a server reboot, I did again a system:cron and it is done correctly in 14 minutes

time sudo -u apache php occ system:cron
328 [-------------------->-------]

real 14m2.646s
user 0m50.049s
sys 0m12.140s

In my opinion, the execution time of the system: cron task is extremely variable from one task to another. Maybe it’s related to the size of the database, user activity with owncloud. Many deleted or added files will influence on the result.

It might be relevant that the system: cron task can only be executed one at the same time (not multiple tasks which would have unpredictable side effects)

Hey,

if such issues appears after an upgrade i would personally report these to a bugtracker rather then to a support forum. It seems the bugtracker for ownCloud is available at the following link, maybe it could make sense to notify the ownCloud development team there about a possible issue as i think they could too easily miss it if posting it only in this forums :frowning_face:

It’s done. See: https://github.com/owncloud/core/issues/36703
Thanks for your good idea :slightly_smiling_face:

1 Like