Cron.php runs forever

henrikw · April 15, 2019, 5:00pm

Steps to reproduce

run cron.php via system cron

Expected behaviour

cron should do the tasks from oc_jobs table and finish them in a resonable time.

Actual behaviour

In my instance once a day a job spawns, which runs forever (at least as I can interpolate )
It takes 100% CPU distributed between cron.php and mysql, and creates no log entries or error messages.
The Queries against the mysql server are always DELETE FROM `oc_properties` WHERE `fileid` IN (0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0)
The amount of rows in oc_properties stays the same meanwhile (~32000).
The only thing to end this is to kill the php processes, but they reappear every day if the cronjob is activated.
The instance is running fine regarding all other aspects.

Content of oc_jobs:

+-------+---------------------------------------------------+-------------------------------------------------------+------------+--------------+-------------+--------------------+
| id    | class                                             | argument                                              | last_run   | last_checked | reserved_at | execution_duration |
+-------+---------------------------------------------------+-------------------------------------------------------+------------+--------------+-------------+--------------------+
|     1 | OC\BackgroundJob\Legacy\RegularJob                | ["\\OC\\Files\\Cache\\BackgroundWatcher","checkNext"] | 1555346702 |   1555346702 |           0 |                  0 |
| 14382 | OCA\Activity\BackgroundJob\EmailNotification      | null                                                  | 1555346702 |   1555346702 |           0 |                  0 |
| 14383 | OC\BackgroundJob\Legacy\RegularJob                | ["OCA\\Music\\Backgroundjob\\CleanUp","run"]          | 1555346702 |   1555346702 |           0 |                  0 |
| 14393 | OCA\Activity\BackgroundJob\ExpireActivities       | null                                                  | 1555338602 |   1555346702 |           0 |                  0 |
| 18389 | OCA\Files_Trashbin\BackgroundJob\ExpireTrash      | null                                                  | 1555346702 |   1555346702 |           0 |                  0 |
| 18390 | OCA\Files_Versions\BackgroundJob\ExpireVersions   | null                                                  | 1555346702 |   1555346702 |           0 |                  0 |
| 18481 | OCA\Files\BackgroundJob\ScanFiles                 | null                                                  | 1555346702 |   1555346702 |           0 |                  0 |
| 18482 | OCA\Files\BackgroundJob\DeleteOrphanedItems       | null                                                  | 1555346702 |   1555346702 |           0 |                  0 |
| 18483 | OCA\Files\BackgroundJob\CleanupFileLocks          | null                                                  | 1555346702 |   1555346702 |           0 |                  0 |
| 18485 | OCA\Federation\SyncJob                            | null                                                  | 1555338602 |   1555346702 |           0 |                  0 |
| 18486 | OCA\DAV\CardDAV\SyncJob                           | null                                                  | 1555338602 |   1555346702 |           0 |                  0 |
| 19250 | \OC\Authentication\Token\DefaultTokenCleanupJob   | null                                                  | 1555346702 |   1555346702 |           0 |                  0 |
| 19251 | OCA\UpdateNotification\Notification\BackgroundJob | null                                                  | 1555338602 |   1555346702 |           0 |                  0 |
| 19253 | OCA\DAV\CardDAV\Sync\SyncJob                      | null                                                  |          0 |   1555335001 |  1555335001 |                 -1 |
| 19254 | OCA\Files_Sharing\DeleteOrphanedSharesJob         | null                                                  | 1555346702 |   1555346702 |           0 |                  0 |
| 19255 | OCA\Files_Sharing\ExpireSharesJob                 | null                                                  | 1555338602 |   1555346702 |           0 |                  0 |
| 19256 | OC\Log\Rotate                                     | "\/srv\/owncloud\/data\/owncloud.log"                 | 1555346702 |   1555346702 |           0 |                  0 |
| 20494 | OCA\Market\CheckUpdateBackgroundJob               | null                                                  | 1555338601 |   1555346702 |           0 |                  1 |
| 20499 | OC\Log\Rotate                                     | "owncloud2.log"                                       | 1555346702 |   1555346702 |           0 |                  0 |
| 20500 | OC\Log\Rotate                                     | "\/srv\/owncloud\/data\/owncloud2.log"                | 1555346702 |   1555346702 |           0 |                  0 |
| 20681 | OCA\DAV\BackgroundJob\CleanProperties             | null                                                  | 1555341302 |   1555341302 |  1555341302 |                 -1 |
| 20682 | OCA\BruteForceProtection\Jobs\ExpireOldAttempts   | null                                                  | 1555338602 |   1555346702 |           0 |                  0 |
+-------+---------------------------------------------------+-------------------------------------------------------+------------+--------------+-------------+--------------------+

Server configuration

Operating system:
Ubuntu 18.04

Web server:
Apache/2.4.29 (Ubuntu)

Database:
mysql Ver 15.1 Distrib 10.1.38-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2

PHP version:
PHP 7.2.15-0ubuntu0.18.04.2

ownCloud version: (see ownCloud admin page)
10.1.1.1

Updated from an older ownCloud or fresh install:
updated

Where did you install ownCloud from:
Official repository

Signing status (ownCloud 9.0 and above):
No errors have been found.

The content of config/config.php:

{                           
    "system": {       
        "instanceid": "***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "datadirectory": "\/srv\/owncloud\/data",
        "dbtype": "mysql",          
        "version": "10.1.1.1",

        "dbname": "owncloud",
        "dbhost": "localhost",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "theme": "",
        "maintenance": false,
        "trusted_domains": [
          "***",
          "***",
          "***",
          "***"
          ],
          "mail_smtpmode": "smtp",
          "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
          "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
          "forcessl": true,
          "mail_from_address": "***REMOVED SENSITIVE VALUE***",
          "mail_domain": "***REMOVED SENSITIVE VALUE***",
          "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
          "mail_smtpport": "25",
          "secret": "***REMOVED SENSITIVE VALUE***",
          "logtimezone": "Europe\/Berlin",
          "log_type": "owncloud",
          "logfile": "\/srv\/owncloud\/data\/owncloud2.log",
          "log_rotate_size": 10485760,
          "log_authfailip": true,
          "loglevel": 2,
          "filelocking.enabled": true,
          "trashbin_retention_obligation": "auto",
          "appstore.experimental.enabled": true,
          "htaccess.RewriteBase": "\/",
          "memcache.local": "\\OC\\Memcache\\Redis",
          "memcache.locking": "\\OC\\Memcache\\Redis",
          "redis": {
            "host": "localhost",
            "port": 6379,
            "timeout": 0
            },
            "updatechecker": false,
            "updater.server.url": "https:\/\/updates.owncloud.com\/server\/",
            "has_internet_connection": true,
            "trusted_proxies": [
              "10.1.1.1"
            ],
            "overwritehost": "***",
            "overwritewebroot": "\/",
            "overwriteprotocol": "https"
}
}

List of activated apps:

Enabled:
  - activity: 2.4.2
  - bookmarks: 0.10.5
  - brute_force_protection: 1.0.1
  - calendar: 1.6.2
  - comments: 0.3.0
  - configreport: 0.1.2
  - contacts: 1.5.5
  - dav: 0.4.0
  - federatedfilesharing: 0.3.1
  - federation: 0.1.0
  - files: 1.5.2
  - files_external: 0.7.1
  - files_pdfviewer: 0.11.0
  - files_sharing: 0.11.0
  - files_texteditor: 2.3.0
  - files_trashbin: 0.9.1
  - files_versions: 1.3.0
  - files_videoplayer: 0.9.9
  - firstrunwizard: 1.1.1
  - gallery: 16.1.1
  - market: 0.4.0
  - notes: 2.0.4
  - notifications: 0.4.1
  - provisioning_api: 0.5.0
  - systemtags: 0.3.0
  - tasks: 0.9.7
  - twofactor_totp: 0.5.3
  - updatenotification: 0.2.1
Disabled:
  - encryption
  - external
  - user_external

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: no

Client configuration

not applicable

Logs

Web server error log

no applicable Webserver Logs

ownCloud log (data/owncloud.log)

No relevant log in owncloud.log

Browser log

not applicable

dmitry · April 15, 2019, 10:03pm

From what version did you update?

henrikw · April 17, 2019, 9:01am

The last update was from 10.1.1 to 10.1.1.1, but the instance is online since some 9.x version.

wrtlprnft · April 25, 2019, 8:27pm

I have the same problem here, also with 10.1.1.1 and updated since forever (last update from 10.1.0).

For me it alternates between the following two queries:

SELECT prop.`fileid` FROM `oc_properties` prop LEFT JOIN `oc_filecache` fc ON prop.`fileid` = fc.`fileid` WHERE fc.`fileid` IS NULL LIMIT 200;
DELETE FROM `oc_properties` WHERE `fileid` IN (0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0);

Contents of oc_properties:

mysql> select * from oc_properties;
+------------------------------------------+---------------+----+--------+
| propertyname                             | propertyvalue | id | fileid |
+------------------------------------------+---------------+----+--------+
| {http://owncloud.org/ns}calendar-enabled | 1             | 12 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 0             | 13 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 14 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 15 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 16 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 17 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 18 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 19 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 20 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 0             | 21 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 22 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 23 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 24 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 25 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 26 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 27 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 28 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 0             | 29 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 30 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 0             | 31 |   NULL |
| {http://owncloud.org/ns}calendar-enabled | 1             | 32 |   NULL |
+------------------------------------------+---------------+----+--------+
21 rows in set (0.00 sec)

Any ideas whether it’s safe to manually delete those? They certainly don’t look very useful to me.

Update: I just tried it after doing a backup, and so far it seems to work. cron.php now finishes quickly and everything still seems to work, including the calendar app. However, I have no idea what I really just did…

henrikw · May 2, 2019, 5:39pm

Thanks for sharing your experience with thw problem - unfortunately my oc_properties table contains a lot entries ( ~32000) with also different type:

select distinct propertyname from oc_properties;
+--------------------------------------------------------------+
| propertyname                                                 |
+--------------------------------------------------------------+
| {urn:ietf:params:xml:ns:caldav}default-alarm-vevent-date     |
| {urn:ietf:params:xml:ns:caldav}default-alarm-vevent-datetime |
| {urn:schemas-microsoft-com:}Win32CreationTime                |
| {urn:schemas-microsoft-com:}Win32LastAccessTime              |
| {urn:schemas-microsoft-com:}Win32LastModifiedTime            |
| {urn:schemas-microsoft-com:}Win32FileAttributes              |
+--------------------------------------------------------------+
6 rows in set (0.04 sec)

Im a bit afraid to simply delete all of them…

wrtlprnft · May 5, 2019, 12:59pm

Hmm. How many of those have NULL in their fileid column? I think that was causing the infinite loop in my case.

henrikw · May 9, 2019, 8:05pm


MariaDB [owncloud]> select distinct propertyname from oc_properties where fileid IS NULL;
+--------------------------------------------------------------+
| propertyname                                                 |
+--------------------------------------------------------------+
| {urn:ietf:params:xml:ns:caldav}default-alarm-vevent-date     |
| {urn:ietf:params:xml:ns:caldav}default-alarm-vevent-datetime |
+--------------------------------------------------------------+
2 rows in set (0.01 sec)
MariaDB [owncloud]> select count() from oc_properties where fileid IS NULL;

±---------+

| count() |

±---------+

|     1068 |

±---------+

1 row in set (0.00 sec)

A couple - I’ll think about deleting them but I’m still unsure as I dont wan’t to mess with my user calendars…

tom42 · May 19, 2019, 6:53am

Hey,

maybe you could open an issue to the ownCloud development team at the github bugtracker if you can’t find a solution or the knowledge in this forums.