cron failure after update to 18.0.x

[andrewdunndev]

Steps to reproduce

1. working instance of 17.0.x
2. cron being run by systemd service and timer units
3. update to 18.0.0 via web updater
4. cron appears to be broken but no meaningful logs Last background job execution ran...

Expected behaviour

cron continues to run after update.

Actual behaviour

cron failing, but silent, no logs

Server configuration

Operating system: debian 10

Web server: nginx 1.14.2-2+deb10u1

Database: postgres 11.6-0+deb10u1

PHP version: php 7.3.11-1~deb10u1

Nextcloud version: (see Nextcloud admin page) 18.0.1

Updated from an older Nextcloud/ownCloud or fresh install: fresh install of 17.0.x

Where did you install Nextcloud from: curl from github, install in container

Login as admin user into your Nextcloud and access 
http://example.com/index.php/settings/integrity/failed 
paste the results here.

No errors have been found.

List of activated apps:

Enabled:
  - accessibility: 1.4.0
  - activity: 2.11.0
  - bruteforcesettings: 1.5.0
  - cloud_federation_api: 1.1.0
  - comments: 1.8.0
  - contacts: 3.1.8
  - dav: 1.14.0
  - federatedfilesharing: 1.8.0
  - federation: 1.8.0
  - files: 1.13.1
  - files_external: 1.9.0
  - files_pdfviewer: 1.7.0
  - files_rightclick: 0.15.2
  - files_sharing: 1.10.1
  - files_trashbin: 1.8.0
  - files_versions: 1.11.0
  - files_videoplayer: 1.7.0
  - firstrunwizard: 2.7.0
  - logreader: 2.3.0
  - lookup_server_connector: 1.6.0
  - nextcloud_announcements: 1.7.0
  - notifications: 2.6.0
  - oauth2: 1.6.0
  - password_policy: 1.8.0
  - photos: 1.0.0
  - privacy: 1.2.0
  - provisioning_api: 1.8.0
  - serverinfo: 1.8.0
  - settings: 1.0.0
  - sharebymail: 1.8.0
  - spreed: 8.0.4
  - support: 1.1.0
  - survey_client: 1.6.0
  - systemtags: 1.8.0
  - text: 2.0.0
  - theming: 1.9.0
  - twofactor_backupcodes: 1.7.0
  - twofactor_totp: 4.1.2
  - twofactor_u2f: 5.0.2
  - updatenotification: 1.8.0
  - viewer: 1.2.0
  - workflowengine: 2.0.0
Disabled:
  - admin_audit
  - encryption
  - recommendations
  - user_ldap

Nextcloud configuration:

{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "vault.dunn.dev"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "pgsql",
        "version": "18.0.1.3",
        "overwrite.cli.url": "https:\/\/vault.dunn.dev",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "memcache.local": "\\OC\\Memcache\\APCu",
        "maintenance": false,
        "mail_smtpmode": "smtp",
        "mail_smtpsecure": "tls",
        "mail_sendmailmode": "smtp",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpauthtype": "LOGIN",
        "mail_smtpauth": 1,
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "587",
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "theme": "",
        "loglevel": 2,
        "updater.release.channel": "stable",
        "updater.secret": "***REMOVED SENSITIVE VALUE***"
    },
    "apps": {
        "accessibility": {
            "types": "",
            "enabled": "yes",
            "installed_version": "1.4.0"
        },
        "activity": {
            "types": "filesystem",
            "enabled": "yes",
            "installed_version": "2.11.0"
        },
        "backgroundjob": {
            "lastjob": "42"
        },
        "bruteforcesettings": {
            "installed_version": "1.5.0",
            "types": "",
            "enabled": "yes"
        },
        "cloud_federation_api": {
            "types": "filesystem",
            "enabled": "yes",
            "installed_version": "1.1.0"
        },
        "comments": {
            "types": "logging",
            "enabled": "yes",
            "installed_version": "1.8.0"
        },
        "contacts": {
            "installed_version": "3.1.8",
            "types": "",
            "enabled": "yes"
        },
        "core": {
            "installedat": "1568556219.0675",
            "vendor": "nextcloud",
            "public_webdav": "dav\/appinfo\/v1\/publicwebdav.php",
            "public_files": "files_sharing\/public.php",
            "installed.bundles": "[\"CoreBundle\"]",
            "backgroundjobs_mode": "cron",
            "shareapi_enable_link_password_by_default": "yes",
            "shareapi_enforce_links_password": "yes",
            "shareapi_default_expire_date": "yes",
            "enterpriseLogoChecked": "yes",
            "theming.variables": "9dc4383bc4a5117f3b0b0b0340d56cea",
            "lastcron": "1581279342",
            "updater.secret.created": "1581684213",
            "oc.integritycheck.checker": "[]",
            "lastupdateResult": "[]",
            "lastupdatedat": "1581686672"
        },
        "dav": {
            "types": "filesystem",
            "enabled": "yes",
            "installed_version": "1.14.0",
            "regeneratedBirthdayCalendarsForYearFix": "yes",
            "buildCalendarSearchIndex": "yes",
            "buildCalendarReminderIndex": "yes",
            "chunks_migrated": "1"
        },
        "federatedfilesharing": {
            "types": "",
            "enabled": "yes",
            "installed_version": "1.8.0"
        },
        "federation": {
            "types": "authentication",
            "enabled": "yes",
            "installed_version": "1.8.0"
        },
        "files": {
            "types": "filesystem",
            "enabled": "yes",
            "cronjob_scan_files": "500",
            "installed_version": "1.13.1"
        },
        "files_external": {
            "types": "filesystem",
            "enabled": "yes",
            "installed_version": "1.9.0"
        },
        "files_pdfviewer": {
            "types": "",
            "enabled": "yes",
            "installed_version": "1.7.0"
        },
        "files_rightclick": {
            "types": "",
            "enabled": "yes",
            "installed_version": "0.15.2"
        },
        "files_sharing": {
            "types": "filesystem",
            "enabled": "yes",
            "installed_version": "1.10.1"
        },
        "files_texteditor": {
            "installed_version": "2.8.0",
            "types": "",
            "enabled": "no"
        },
        "files_trashbin": {
            "types": "filesystem,dav",
            "enabled": "yes",
            "installed_version": "1.8.0"
        },
        "files_versions": {
            "types": "filesystem,dav",
            "enabled": "yes",
            "installed_version": "1.11.0"
        },
        "files_videoplayer": {
            "types": "",
            "enabled": "yes",
            "installed_version": "1.7.0"
        },
        "firstrunwizard": {
            "types": "logging",
            "enabled": "yes",
            "installed_version": "2.7.0"
        },
        "gallery": {
            "types": "",
            "installed_version": "18.4.0",
            "enabled": "no"
        },
        "logreader": {
            "types": "",
            "enabled": "yes",
            "installed_version": "2.3.0"
        },
        "lookup_server_connector": {
            "types": "authentication",
            "enabled": "yes",
            "installed_version": "1.6.0"
        },
        "maps": {
            "enabled": "no",
            "installed_version": "0.1.4",
            "types": "filesystem"
        },
        "nextcloud_announcements": {
            "pub_date": "Thu, 24 Oct 2019 00:00:00 +0200",
            "types": "logging",
            "enabled": "yes",
            "installed_version": "1.7.0"
        },
        "notifications": {
            "types": "logging",
            "enabled": "yes",
            "installed_version": "2.6.0"
        },
        "oauth2": {
            "types": "authentication",
            "enabled": "yes",
            "installed_version": "1.6.0"
        },
        "password_policy": {
            "types": "",
            "enabled": "yes",
            "minLength": "64",
            "installed_version": "1.8.0"
        },
        "photos": {
            "installed_version": "1.0.0",
            "types": "",
            "enabled": "yes"
        },
        "privacy": {
            "types": "",
            "enabled": "yes",
            "readableLocation": "us",
            "installed_version": "1.2.0"
        },
        "provisioning_api": {
            "types": "prevent_group_restriction",
            "enabled": "yes",
            "installed_version": "1.8.0"
        },
        "recommendations": {
            "installed_version": "0.4.0",
            "types": "",
            "enabled": "no"
        },
        "serverinfo": {
            "types": "",
            "enabled": "yes",
            "installed_version": "1.8.0"
        },
        "settings": {
            "installed_version": "1.0.0",
            "types": "",
            "enabled": "yes"
        },
        "sharebymail": {
            "types": "filesystem",
            "enabled": "yes",
            "installed_version": "1.8.0",
            "enforcePasswordProtection": "yes"
        },
        "spreed": {
            "types": "prevent_group_restriction",
            "enabled": "yes",
            "project_access_invalidated": "1",
            "installed_version": "8.0.4",
            "stun_servers": "***REMOVED SENSITIVE VALUE***"
        },
        "support": {
            "enabled": "yes",
            "types": "session",
            "installed_version": "1.1.0"
        },
        "survey_client": {
            "types": "",
            "enabled": "yes",
            "installed_version": "1.6.0"
        },
        "systemtags": {
            "types": "logging",
            "enabled": "yes",
            "installed_version": "1.8.0"
        },
        "text": {
            "enabled": "yes",
            "types": "dav",
            "installed_version": "2.0.0"
        },
        "theming": {
            "types": "logging",
            "enabled": "yes",
            "installed_version": "1.9.0",
            "name": "vault.dunn.dev",
            "url": "***REMOVED SENSITIVE VALUE***",
            "slogan": "***REMOVED SENSITIVE VALUE***",
            "imprintUrl": "***REMOVED SENSITIVE VALUE***",
            "privacyUrl": "***REMOVED SENSITIVE VALUE***",
            "color": "#4A4A4A",
            "cachebuster": "8"
        },
        "twofactor_backupcodes": {
            "types": "",
            "enabled": "yes",
            "installed_version": "1.7.0"
        },
        "twofactor_totp": {
            "types": "",
            "enabled": "yes",
            "installed_version": "4.1.2"
        },
        "twofactor_u2f": {
            "types": "",
            "enabled": "yes",
            "installed_version": "5.0.2"
        },
        "updatenotification": {
            "twofactor_totp": "4.1.2",
            "types": "",
            "enabled": "yes",
            "files_rightclick": "0.15.1",
            "update_check_errors": "0",
            "core": "17.0.1.1",
            "installed_version": "1.8.0",
            "twofactor_u2f": "5.0.2",
            "spreed": "8.0.2",
            "bruteforcesettings": "1.5.0"
        },
        "viewer": {
            "types": "",
            "enabled": "yes",
            "installed_version": "1.2.0"
        },
        "workflowengine": {
            "types": "filesystem",
            "enabled": "yes",
            "installed_version": "2.0.0"
        }
    }
}

Are you using external storage, if yes which one: local/smb/sftp/...

local

Are you using encryption: yes/no

no

[andrewdunndev]

after updating to 18.0.0 I'd installed maps as it was "featured", I removed it after a couple minutes. Could be duplicate of #19032 but maps was removed.

[kesselb]

This report is incomplete and looks more like a configuration issue.

1. What exact error message do you see?
2. Logs

This is the issue tracker of Nextcloud, please do NOT use this to get answers to your questions or get help for fixing your installation. This is a place to report bugs to developers, after your server has been debugged. You can find help debugging your system on our home user forums: https://help.nextcloud.com or, if you use Nextcloud in a large organization, ask our engineers on https://portal.nextcloud.com. See also https://nextcloud.com/support for support options.

[andrewdunndev]

error: Last job execution ran 5 days ago. Something seems wrong.

I've made no configuration changes between 17.0.x and 18.0.0/18.0.1.

How would you like logs to be collected, is the only location in the nextcloud gui?

[andrewdunndev]

sudo -u www-data php cron.php within the nextcloud install folder seems to hang, provides no text output.

[kesselb]

How would you like logs to be collected, is the only location in the nextcloud gui?

There is some advice about logs with the issue template. $datadirectory/nextcloud.log is usually a good place to start.

[andrewdunndev]

cat $datadirectory/nextcloud.log | grep cron, not sure if I should be grepping for anything else. tail on the file doesn't provide any sort of errors that have anything to do with cron.

{"file":"/opt/nextcloud/lib/private/BackgroundJob/JobList.php","line":227,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]},{"file":"/opt/nextcloud/lib/private/BackgroundJob/JobList.php","line":227,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]},{"file":"/opt/nextcloud/lib/private/BackgroundJob/JobList.php","line":227,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]},{"file":"/opt/nextcloud/lib/private/BackgroundJob/JobList.php","line":227,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]},{"file":"/opt/nextcloud/lib/private/BackgroundJob/JobList.php","line":227,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]},{"file":"/opt/nextcloud/lib/private/BackgroundJob/JobList.php","line":227,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]},{"file":"/opt/nextcloud/lib/private/BackgroundJob/JobList.php","line":227,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]},{"file":"/opt/nextcloud/lib/private/BackgroundJob/JobList.php","line":227,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]},{"file":"/opt/nextcloud/cron.php","line":119,"function":"getNext","class":"OC\BackgroundJob\JobList","type":"->","args":[]}],"File":"/opt/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php","Line":117}},"CustomMessage":"--"},"userAgent":"--","version":"18.0.0.10"}

[andrewdunndev]

moving the log file and rebooting the metal so we're on a fresh file, running sudo -u www-data php -f /opt/nextcloud/cron.php just runs forever and there is no entries in the log. I'm not sure how to debug this any further as I don't see any arguments for verbose output of the cron script.

So I'm in a state where I don't know how to debug this further, the instance (after updating to 18.0.0 stopped being able to do the cron.php and I'm not sure how to provide enough meaningful information to debug it).

[andrewdunndev]

Entirely possible that I'm hit by #19032. I believe that installing maps created a significant amount of jobs (I have 2T of photos on this instance). Is there a way to examine/clear jobs?

[kesselb]

1. 'loglevel' => 2, decrease the log level to 0.
2. Add 'debug' => true, to `config.php' for more output.
3. If there is still nothing in your logs:

server/cron.php

Line 120 in 5bf3d1b

if (isset($executedJobs[$job->getId()])) {

\OC::$server->getLogger()->debug('Going to execute: ' . get_class($job), ['app' => 'cron']); should write the job going to be executed to the log. So the last Going to execute line in the log is the hanging job. Also jobs table is probably interesting.

[kesselb]

Entirely possible that I'm hit by #19032.

Do you see the same error message in the logs? If you uninstalled the app it's actually not possible to execute the job anymore (because it's not there). It might be still in jobs database table but cron.php will skip it. I don't know the maps app but this UpdatePhotoByFileJob indeed seems heavy. If they scan all images of a user and you have 2T that's probably not going to work. But the background job should have some kind of limitation / offsets.

cc @nextcloud/server-triage actually a interesting question. We recommend to run cron.php every 5 minutes now. I see there is code to lock/unlock jobs so it should be possible to have long and short running jobs.

[kesselb]

Hey @eneiluj @tacruc, thanks for your great work with the maps app. Do you have other reports like that (a lot of images and long running jobs)?