Backgroundjob error messages: SyncJob does not exist

[mmattel]

Steps to reproduce

1. Automatically run occ via cron

Note: I once installed the LDAP App and enabled it, but never configured it. It was just to see the screen how it looks like. Then I disabled the app but did not remove it.

Note: Grepping eg for LDAP in the log only shows entried past 2019.05.21 which was as far I remember the day I did the upgrade to 10.2

Expected behaviour

No error message for backgroundjobs

Actual behaviour

Getting error messages for backgroundjobs: Could not resolve OCA SyncJob does not exist CleanUp! Class OCA\\\\OAuth2 SyncJob! Class OCA\\\\DAV UpdateGroups! Class OCA\\\\User_LDAP

Server configuration

Operating system: Ubuntu 16.04

Web server: nginx

Database: mysql

PHP version: 7.0

ownCloud version: 10.2.0.5

Updated from an older ownCloud or fresh install: updated

Where did you install ownCloud from: tar

Signing status (ownCloud 9.0 and above):

No errors have been found.

The content of config/config.php:

{
    "system": {
        "instanceid": "oct7bkicorxf",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "xxx"
        ],
        "datadirectory": "\/var\/www\/owncloud\/data",
        "overwrite.cli.url": "https:\/\/xxxx",
        "htaccess.RewriteBase": "\/",
        "dbtype": "mysql",
        "version": "10.2.0.5",
        "dbname": "owncloud",
        "dbhost": "localhost",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "logtimezone": "Europe\/Vienna",
        "installed": true,
        "filelocking.enabled": "true",
        "memcache.local": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "localhost",
            "port": 6379,
            "timeout": 0,
            "dbindex": 0
        },
        "filesystem_check_changes": 1,
        "loglevel": 2,
        "mail_smtpmode": "smtp",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpsecure": "tls",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpauthtype": "LOGIN",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "587",
        "maintenance": false,
        "theme": "",
        "preview_max_scale_factor": 1,
        "excluded_directories": [
            ".snapshot",
            "~snapshot"
        ],
        "upgrade.automatic-app-update": true,
        "quota_include_external_storage": false,
        "singleuser": false,
        "apps_paths": [
            {
                "path": "\/var\/www\/owncloud\/apps",
                "url": "\/apps",
                "writable": false
            },
            {
                "path": "\/var\/www\/owncloud\/apps-external",
                "url": "\/apps-external",
                "writable": true
            }
        ],
        "show_server_hostname": false,
        "ldapIgnoreNamingRules": false
    }
}

List of activated apps:

Enabled:
  - activity: 2.4.2
  - audioplayer: 2.7.1
  - comments: 0.3.0
  - configreport: 0.2.0
  - dav: 0.4.0
  - federatedfilesharing: 0.4.0
  - federation: 0.1.0
  - files: 1.5.2
  - files_external: 0.7.1
  - files_external_dropbox: 1.1.0
  - files_external_ftp: 0.2.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.10.1
  - firstrunwizard: 1.2.0
  - gallery: 16.1.1
  - guests: 0.8.1
  - market: 0.4.0
  - notifications: 0.5.0
  - provisioning_api: 0.5.0
  - systemtags: 0.3.0
  - templateeditor: 0.4.0
  - updatenotification: 0.2.1
Disabled:
  - encryption
  - external
  - files_clipboard
  - user_external
  - user_ldap

Are you using external storage, if yes which one: local/smb/sftp/google drive, dropbox

Are you using encryption: no

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

Client configuration

Browser: Opera

Operating system: W10x64

Logs

Web server error log

Not relevant

ownCloud log (data/owncloud.log)

{"reqId":"HAtiD0LKHgy0Bh44vG0o","level":3,"time":"2019-06-18T23:45:02+02:00","remoteAddr":"","user":"--","app":"core","method":"--","url":"--","message":"Exception: {\"Exception\":\"OCP\\\\AppFramework\\\\QueryException\",\"Message\":\"Could not resolve OCA\\\\OAuth2\\\\BackgroundJob\\\\CleanUp! Class OCA\\\\OAuth2\\\\BackgroundJob\\\\CleanUp does not exist\",\"Code\":0,\"Trace\":\"
#0 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Utility\\\/SimpleContainer.php(110): OC\\\\AppFramework\\\\Utility\\\\SimpleContainer->resolve('OCA\\\\\\\\OAuth2\\\\\\\\Back...')\\
n#1 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/ServerContainer.php(86): OC\\\\AppFramework\\\\Utility\\\\SimpleContainer->query('OCA\\\\\\\\OAuth2\\\\\\\\Back...')\\
n#2 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/JobList.php(253): OC\\\\ServerContainer->query('OCA\\\\\\\\OAuth2\\\\\\\\Back...')\\
n#3 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/JobList.php(209): OC\\\\BackgroundJob\\\\JobList->buildJob(Array)\\
n#4 \\\/var\\\/www\\\/owncloud\\\/cron.php(114): OC\\\\BackgroundJob\\\\JobList->getNext()\\
n#5 {main}\",\"File\":\"\\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Utility\\\/SimpleContainer.php\",\"Line\":96}"}

{"reqId":"tEZiKB0VZhumIdDiX8Ec","level":3,"time":"2019-06-18T23:00:03+02:00","remoteAddr":"","user":"--","app":"core","method":"--","url":"--","message":"Exception: {\"Exception\":\"OCP\\\\AppFramework\\\\QueryException\",\"Message\":\"Could not resolve OCA\\\\DAV\\\\CardDAV\\\\Sync\\\\SyncJob! Class OCA\\\\DAV\\\\CardDAV\\\\Sync\\\\SyncJob does not exist\",\"Code\":0,\"Trace\":\"
#0 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Utility\\\/SimpleContainer.php(110): OC\\\\AppFramework\\\\Utility\\\\SimpleContainer->resolve('OCA\\\\\\\\DAV\\\\\\\\CardDAV...')\\
n#1 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/ServerContainer.php(86): OC\\\\AppFramework\\\\Utility\\\\SimpleContainer->query('OCA\\\\\\\\DAV\\\\\\\\CardDAV...')\\
n#2 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/JobList.php(253): OC\\\\ServerContainer->query('OCA\\\\\\\\DAV\\\\\\\\CardDAV...')\\
n#3 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/JobList.php(209): OC\\\\BackgroundJob\\\\JobList->buildJob(Array)\\
n#4 \\\/var\\\/www\\\/owncloud\\\/cron.php(114): OC\\\\BackgroundJob\\\\JobList->getNext()\\
n#5 {main}\",\"File\":\"\\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Utility\\\/SimpleContainer.php\",\"Line\":96}"}

{"reqId":"IxZlSS20TS8Gz8AoPtvV","level":3,"time":"2019-06-19T02:45:03+02:00","remoteAddr":"","user":"--","app":"core","method":"--","url":"--","message":"Exception: {\"Exception\":\"OCP\\\\AppFramework\\\\QueryException\",\"Message\":\"Could not resolve OCA\\\\User_LDAP\\\\Jobs\\\\UpdateGroups! Class OCA\\\\User_LDAP\\\\Jobs\\\\UpdateGroups does not exist\",\"Code\":0,\"Trace\":\"
#0 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Utility\\\/SimpleContainer.php(110): OC\\\\AppFramework\\\\Utility\\\\SimpleContainer->resolve('OCA\\\\\\\\User_LDAP\\\\\\\\J...')\\
n#1 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/ServerContainer.php(86): OC\\\\AppFramework\\\\Utility\\\\SimpleContainer->query('OCA\\\\\\\\User_LDAP\\\\\\\\J...')\\
n#2 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/JobList.php(253): OC\\\\ServerContainer->query('OCA\\\\\\\\User_LDAP\\\\\\\\J...')\\
n#3 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/JobList.php(209): OC\\\\BackgroundJob\\\\JobList->buildJob(Array)\\
n#4 \\\/var\\\/www\\\/owncloud\\\/cron.php(114): OC\\\\BackgroundJob\\\\JobList->getNext()\\
n#5 {main}\",\"File\":\"\\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Utility\\\/SimpleContainer.php\",\"Line\":96}"}

@DeepDiver1975 mind to take a look on respectively point to someone who could cover that?

[VicDeo]

@mmattel please post

select * from oc_jobs where class like '%LDAP%';

[VicDeo]

Looks like the logging was added intentionally :unsure: https://github.com/owncloud/core/pull/32623

[mmattel]

id	class	argument	last_run	last_checked	reserved_at	execution_duration
325	OCA\User_LDAP\Jobs\UpdateGroups	null	0	1561185002	1561185002	1

[mmattel]

Any update on this as this fills up the log triggerd by cron every 15min... 👎

[VicDeo]

@mmattel you can delete OCA\User_LDAP\Jobs\UpdateGroups job from DB, as it is unneeded and has been removed from the app recently

[mmattel]

I am not convinced deleting a job manually. There is more than one job in question as you can see above, exact they are three. It is necessary to check and solve, eg during an upgrade, if there are bgj leftovers from former/disabled apps or had issues. TIP: do not run a bgj for a disabled app... (which is at least true for the LDAP app above). That would make one problem gone and let two problems left to cover.

[VicDeo]

do not run a bgj for a disabled app...

@mmattel it is not run. https://github.com/owncloud/core/pull/32623 adds a log entry why the job was skipped, before this PR the job was skipped silently.

[mmattel]

Anyhow, this is not an excuse. The app is disabled (or the BGJ does not exist anymore), so it must not try to run and therefore must not create a log entry. For the other two, investigations and fixes are needed. I get daily 96 sensless log entries filling up the log file. BTW: by your refrence from above pls see comment of the PR: https://github.com/owncloud/core/blob/334bae3bb7a5f575b335d97adb706e9c71fa21ae/lib/private/legacy/app.php#L1052

[Linda-chan]

Just upgraded to 10.2.1.4 and got same issue. I think you should add autoremove for these jobs on upgrade process.

[cortho]

Are there any news on this topic? Even with a recent 10.7, when I disable e.g. the market app manual intervention is still required,.

I took efforts to collect the relevant information in my Ticket https://github.com/owncloud/core/issues/36908 over a year ago which had not been considered in this ticket.

This happens because exceptions are thrown in any case, even when the app is disabled,

So it should be a junior job to at least not to throw the exception when the app is not enabled at all.

[UnitedMarsupials]

So, how do we deal with this for the time being?

[zubanst]

Same issue here even in version 10.10. For me is with CleanupExpiredWopiTokens: Could not resolve OCA\Richdocuments\BackgroundJob\CleanupExpiredWopiTokens; Class OCA\Richdocuments\BackgroundJob\CleanupExpiredWopiTokens does not exist.

[hknet]

well, 10.11 throws this on me every cron job: "message":"Exception: {"Exception":"OCP\\AppFramework\\QueryException","Message":"Could not resolve OCA\\Federation\\SyncJob! Class OCA\\Federation\\SyncJob does not exist"

while the job is in oc_jobs like this: | 5 | OCA\Federation\SyncJob | null | 1518448502 | 1675660502 | 1675660502 | 0 |

[mmattel]

@jvillafanez @DeepDiver1975 can you have a look?

[jvillafanez]

We need to decide what to do. So far, while annoying, this is the intended behavior.

Note that even if the common cause of the problem is the target app being disabled, there could be other causes. Removing the log isn't a good idea.

The simplest solution would be to reduce the logging level, but if the problem isn't caused by a disabled app, we'll likely miss the error and it will be difficult to pinpoint the actual location of the issue.

Another more complex option could be to include an "state" column so we could mark the job as disabled / invalid etc. By marking the job as disabled, ownCloud shouldn't even try to run it. This will imply some additional development (we'll need a way to manipulate the state of the job from the command line), so it won't be a one-line change.

Furthermore, removing the job isn't a valid option. I've only checked with the activity app, but I guess it could happen with more. If the app is disabled and you manually remove the job (I don't think ownCloud is removing it), the jobs won't come back when the app is re-enabled, so it will cause problems in the long run.

[DeepDiver1975]

We need to decide what to do. So far, while annoying, this is the intended behavior.

Note that even if the common cause of the problem is the target app being disabled, there could be other causes. Removing the log isn't a good idea.

Exactly this is why it is good to have this log entry. And finally it is a log entry - nothing is broken :shrug:

Furthermore, removing the job isn't a valid option. I've only checked with the activity app, but I guess it could happen with more. If the app is disabled and you manually remove the job (I don't think ownCloud is removing it), the jobs won't come back when the app is re-enabled, so it will cause problems in the long run.

And this speaks again removing the job.

I agree this is no nice - but also not really an issue

[UnitedMarsupials]

We need to decide what to do. So far, while annoying, this is the intended behavior. ... Exactly this is why it is good to have this log entry. And finally it is a log entry - nothing is broken shrug

An error is printed -- and, in many cases, e-mailed -- which is not a sign of there being any actual error. That is, what's broken.

Software (multiple times a day): hey, owner, there is this trouble... Owner: oops, what trouble, I don't understand... Software Authors: you can ignore it. Owner: why is your software notifying me of things, which you're telling me to ignore? Software Authors: it builds character...

If the target app is disabled, any maintenance related to it should not be attempted either.

[mmattel]

If the target app is disabled, any maintenance related to it should not be attempted either.

This is the key sentence and I fully agree on that. A log entry should not pop up if the app is not enabled as it is not accessed. IMHO it is not a big deal before writing the log entry to check if the app related is enabled or not. I am therfore reopen it to keep it on the radar.

[DeepDiver1975]

I am therfore reopen it to keep it on the radar.

Cool - let's keep one issue open for each log entry somebody on this planet is not interested in :+1:

[mmattel]

A traveller that has made a trip to France in the past but is now back in Germany, does not want to get highway congestion jam reports on his radio from France, just he was there in the past- he is just not interested in. When he once will go there again, the interest ist back.

[d7oc]

Furthermore, removing the job isn't a valid option. I've only checked with the activity app, but I guess it could happen with more. If the app is disabled and you manually remove the job (I don't think ownCloud is removing it), the jobs won't come back when the app is re-enabled, so it will cause problems in the long run.

Just for confirmation: So an app doesn't re-install its needed jobs? What's the reason? The job is also added when initially installing the app. I would assume this procedure to be idempotent.

I'm curious as we have a documentation article about removing the jobs: https://doc.owncloud.com/server/next/admin_manual/troubleshooting/remove_non_existent_bg_jobs.html

If they are not added back again if the customer installs an app again later on we might have an issue.

[mmattel]

I would like to summarize the behaviour related with disabled/deleted apps that added a BG-job when first time enabled. Starting with item 1 and 2, it turns out that there are more issues related underneath:

1. If the app got disabled, BG-jobs stay active and force a log entry about a non existant app/job. Not only one time, but continuosly each time BG jobs start, filling up the log.
2. The app gets finally deleted, you end up in item 1.
3. You delete the BG job via occ to silence logging, it is unclear (see comment above) if the BG-job gets readded when the app gets re-enabled. Even worse the same if the app was deleted before. This has negative impacts on the system as necessary jobs dont run anymore.
4. There is no occ command to readd a formerly deleted BG job.

This results in two major issues:

• Log silencing (do not add a BG-job log entry if the app is disabled)
• How to readd a formerly deleted BG-job if the app is re-enabled/reinstalled