server icon indicating copy to clipboard operation
server copied to clipboard

[Bug]: "Error while running background job" -> "Recurring events are only allowed to generate 3500"

Open rybaha opened this issue 2 years ago • 14 comments

⚠️ This issue respects the following points: ⚠️

  • [X] This is a bug, not a question or a configuration/webserver/proxy issue.
  • [X] This issue is not already reported on Github (I've searched it).
  • [X] Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
  • [X] Nextcloud Server is running on 64bit capable CPU, PHP and OS.
  • [X] I agree to follow Nextcloud's Code of Conduct.

Bug description

Using Nextcloud from the beginning, migrated from OwnCloud long time ago on dedicated server and up to 100 users primary for file sharing and calendar services. Recently (after recent Nextcloud update) I started to notice unusual messages at regualr (5 and 10 minutes) basis: `[core] Error: Sabre\VObject\Recur\MaxInstancesExceededException: Recurring events are only allowed to generate 3500 at <>

  1. /var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php line 639 Sabre\VObject\Recur\EventIterator->valid()
  2. /var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php line 139 OCA\DAV\CalDAV\Reminder\ReminderService->getVEventByRecurrenceId()
  3. /var/www/html/nextcloud/apps/dav/lib/BackgroundJob/EventReminderJob.php line 69 OCA\DAV\CalDAV\Reminder\ReminderService->processReminders()
  4. /var/www/html/nextcloud/lib/public/BackgroundJob/Job.php line 79 OCA\DAV\BackgroundJob\EventReminderJob->run()
  5. /var/www/html/nextcloud/lib/public/BackgroundJob/TimedJob.php line 95 OCP\BackgroundJob\Job->execute()
  6. /var/www/html/nextcloud/cron.php line 151 OCP\BackgroundJob\TimedJob->execute()

at 2022-10-05T18:00:03+03:00`

At first I thought its related to recurring events in calendar, so I started to check in database for events in oc_calendar_reminders with is_recurring = 1 for further investigation. I did checks down to inspecting object_id contents and calendar_id but no luck. I delete "old" events but that didn't help.

Error appear in log each 5 and 10 minutes, cron is set to run at */5.

Steps to reproduce

I have no way to reproduce it, as this messages started relatively recently, same error with stable recurrence of 10 minutes. But in general it looks like:

  1. Install Nextcloud 24.0.5.1
  2. Use it normally as file storage/calendar server
  3. check logs regularly

Expected behavior

No messages with Error severity.

Installation method

Community Manual installation with Archive

Operating system

Debian/Ubuntu

PHP engine version

PHP 7.4

Web server

Nginx

Database engine version

MariaDB

Is this bug present after an update or on a fresh install?

Updated from a minor version (ex. 22.2.3 to 22.2.4)

Are you using the Nextcloud Server Encryption module?

Encryption is Disabled

What user-backends are you using?

  • [ ] Default user-backend (database)
  • [X] LDAP/ Active Directory
  • [ ] SSO - SAML
  • [ ] Other

Configuration report

{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "installed": true,
        "ldapIgnoreNamingRules": false,
        "ldapUserCleanupInterval": 51,
        "forcessl": true,
        "loglevel": 2,
        "log_type": "file",
        "logfile": "\/var\/log\/nextcloud\/nextcloud.log",
        "log_rotate_size": 5242880,
        "logtimezone": "Europe\/Athens",
        "log_query": false,
        "defaultapp": "files",
        "maintenance": false,
        "theme": "",
        "mail_smtpmode": "smtp",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "587",
        "mail_smtpdebug": false,
        "memcache.local": "\\OC\\Memcache\\APCu",
        "filelocking.enabled": true,
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 0,
            "timeout": 0,
            "password": "***REMOVED SENSITIVE VALUE***",
            "dbindex": 0
        },
        "trusted_domains": [
            "nc.example.com"
        ],
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "version": "24.0.5.1",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "appstore.experimental.enabled": true,
        "trashbin_retention_obligation": "auto",
        "ldapProviderFactory": "\\OCA\\User_LDAP\\LDAPProviderFactory",
        "updater.release.channel": "stable",
        "overwrite.cli.url": "https:\/\/nc.example.com",
        "htaccess.RewriteBase": "\/",
        "mysql.utf8mb4": true,
        "app_install_overwrite": [
            "keeweb"
        ],
        "config_is_read_only": false,
        "data-fingerprint": "cfab618149e5103031a21607a2309ca7",
        "mail_sendmailmode": "smtp",
        "auth.bruteforce.protection.enabled": true,
        "enable_previews": false,
        "hashingThreads": 1,
        "hashingMemoryCost": 2048,
        "hashingTimeCost": 1,
        "hashingCost": 6,
        "mail_smtpsecure": "tls",
        "default_phone_region": "UA",
        "skeletondirectory": ""
    }
}

List of activated Apps

Enabled:
  - activity: 2.16.0
  - admin_audit: 1.14.0
  - breezedark: 24.0.2
  - bruteforcesettings: 2.4.0
  - calendar: 3.5.0
  - circles: 24.0.1
  - cloud_federation_api: 1.7.0
  - comments: 1.14.0
  - contacts: 4.2.2
  - contactsinteraction: 1.5.0
  - dav: 1.22.0
  - extract: 1.3.5
  - federatedfilesharing: 1.14.0
  - files: 1.19.0
  - files_downloadactivity: 1.13.0
  - files_external: 1.16.1
  - files_pdfviewer: 2.5.0
  - files_rightclick: 1.3.0
  - files_sharing: 1.16.2
  - files_trashbin: 1.14.0
  - files_versions: 1.17.0
  - files_videoplayer: 1.13.0
  - firstrunwizard: 2.13.0
  - groupfolders: 12.0.1
  - guests: 2.3.0
  - impersonate: 1.11.0
  - keeweb: 0.6.9
  - logreader: 2.9.0
  - lookup_server_connector: 1.12.0
  - nextcloud_announcements: 1.13.0
  - notes: 4.5.1
  - notifications: 2.12.1
  - oauth2: 1.12.0
  - password_policy: 1.14.0
  - photos: 1.6.0
  - privacy: 1.8.0
  - provisioning_api: 1.14.0
  - quota_warning: 1.14.0
  - recommendations: 1.3.0
  - serverinfo: 1.14.0
  - settings: 1.6.0
  - sharebymail: 1.14.0
  - support: 1.7.0
  - systemtags: 1.14.0
  - tasks: 0.14.4
  - text: 3.5.1
  - theming: 1.15.0
  - twofactor_backupcodes: 1.13.0
  - twofactor_email: 2.7.0
  - updatenotification: 1.14.0
  - user_ldap: 1.14.1
  - viewer: 1.8.0
  - weather_status: 1.4.0
  - workflowengine: 2.6.0
Disabled:
  - accessibility: 1.6.0
  - dashboard: 7.0.0
  - encryption: 1.0.0
  - event_update_notification: 1.5.0
  - federation: 0.0.4
  - survey_client: 1.6.0
  - user_status: 1.0.1

Nextcloud Signing status

No errors have been found.

Nextcloud Logs

{"reqId":"wWD7XKLVaSXKAPsCdpdl","level":3,"time":"2022-10-05T18:35:03+03:00","remoteAddr":"","user":"--","app":"core","method":"","url":"--","message":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )","userAgent":"--","version":"24.0.5.1","exception":{"Exception":"Sabre\\VObject\\Recur\\MaxInstancesExceededException","Message":"Recurring events are only allowed to generate 3500","Code":0,"Trace":[{"file":"/var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php","line":639,"function":"valid","class":"Sabre\\VObject\\Recur\\EventIterator","type":"->"},{"file":"/var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php","line":139,"function":"getVEventByRecurrenceId","class":"OCA\\DAV\\CalDAV\\Reminder\\ReminderService","type":"->"},{"file":"/var/www/html/nextcloud/apps/dav/lib/BackgroundJob/EventReminderJob.php","line":69,"function":"processReminders","class":"OCA\\DAV\\CalDAV\\Reminder\\ReminderService","type":"->"},{"file":"/var/www/html/nextcloud/lib/public/BackgroundJob/Job.php","line":79,"function":"run","class":"OCA\\DAV\\BackgroundJob\\EventReminderJob","type":"->"},{"file":"/var/www/html/nextcloud/lib/public/BackgroundJob/TimedJob.php","line":95,"function":"execute","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/var/www/html/nextcloud/cron.php","line":151,"function":"execute","class":"OCP\\BackgroundJob\\TimedJob","type":"->"}],"File":"/var/www/html/nextcloud/3rdparty/sabre/vobject/lib/Recur/EventIterator.php","Line":306,"message":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )","CustomMessage":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )"},"id":"633da551899ba"}
{"reqId":"tQUKuuUZViplWlo5sRv2","level":3,"time":"2022-10-05T18:25:03+03:00","remoteAddr":"","user":"--","app":"core","method":"","url":"--","message":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )","userAgent":"--","version":"24.0.5.1","exception":{"Exception":"Sabre\\VObject\\Recur\\MaxInstancesExceededException","Message":"Recurring events are only allowed to generate 3500","Code":0,"Trace":[{"file":"/var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php","line":639,"function":"valid","class":"Sabre\\VObject\\Recur\\EventIterator","type":"->"},{"file":"/var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php","line":139,"function":"getVEventByRecurrenceId","class":"OCA\\DAV\\CalDAV\\Reminder\\ReminderService","type":"->"},{"file":"/var/www/html/nextcloud/apps/dav/lib/BackgroundJob/EventReminderJob.php","line":69,"function":"processReminders","class":"OCA\\DAV\\CalDAV\\Reminder\\ReminderService","type":"->"},{"file":"/var/www/html/nextcloud/lib/public/BackgroundJob/Job.php","line":79,"function":"run","class":"OCA\\DAV\\BackgroundJob\\EventReminderJob","type":"->"},{"file":"/var/www/html/nextcloud/lib/public/BackgroundJob/TimedJob.php","line":95,"function":"execute","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/var/www/html/nextcloud/cron.php","line":151,"function":"execute","class":"OCP\\BackgroundJob\\TimedJob","type":"->"}],"File":"/var/www/html/nextcloud/3rdparty/sabre/vobject/lib/Recur/EventIterator.php","Line":306,"message":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )","CustomMessage":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )"},"id":"633da55189b43"}
{"reqId":"2yxbX2hoSyEFVGKmtA7s","level":3,"time":"2022-10-05T18:15:02+03:00","remoteAddr":"","user":"--","app":"core","method":"","url":"--","message":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )","userAgent":"--","version":"24.0.5.1","exception":{"Exception":"Sabre\\VObject\\Recur\\MaxInstancesExceededException","Message":"Recurring events are only allowed to generate 3500","Code":0,"Trace":[{"file":"/var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php","line":639,"function":"valid","class":"Sabre\\VObject\\Recur\\EventIterator","type":"->"},{"file":"/var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php","line":139,"function":"getVEventByRecurrenceId","class":"OCA\\DAV\\CalDAV\\Reminder\\ReminderService","type":"->"},{"file":"/var/www/html/nextcloud/apps/dav/lib/BackgroundJob/EventReminderJob.php","line":69,"function":"processReminders","class":"OCA\\DAV\\CalDAV\\Reminder\\ReminderService","type":"->"},{"file":"/var/www/html/nextcloud/lib/public/BackgroundJob/Job.php","line":79,"function":"run","class":"OCA\\DAV\\BackgroundJob\\EventReminderJob","type":"->"},{"file":"/var/www/html/nextcloud/lib/public/BackgroundJob/TimedJob.php","line":95,"function":"execute","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/var/www/html/nextcloud/cron.php","line":151,"function":"execute","class":"OCP\\BackgroundJob\\TimedJob","type":"->"}],"File":"/var/www/html/nextcloud/3rdparty/sabre/vobject/lib/Recur/EventIterator.php","Line":306,"message":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )","CustomMessage":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )"},"id":"633da55189c17"}
{"reqId":"WxBhXZVAOpQsyxQnaLTv","level":3,"time":"2022-10-05T18:10:02+03:00","remoteAddr":"","user":"--","app":"core","method":"","url":"--","message":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )","userAgent":"--","version":"24.0.5.1","exception":{"Exception":"Sabre\\VObject\\Recur\\MaxInstancesExceededException","Message":"Recurring events are only allowed to generate 3500","Code":0,"Trace":[{"file":"/var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php","line":639,"function":"valid","class":"Sabre\\VObject\\Recur\\EventIterator","type":"->"},{"file":"/var/www/html/nextcloud/apps/dav/lib/CalDAV/Reminder/ReminderService.php","line":139,"function":"getVEventByRecurrenceId","class":"OCA\\DAV\\CalDAV\\Reminder\\ReminderService","type":"->"},{"file":"/var/www/html/nextcloud/apps/dav/lib/BackgroundJob/EventReminderJob.php","line":69,"function":"processReminders","class":"OCA\\DAV\\CalDAV\\Reminder\\ReminderService","type":"->"},{"file":"/var/www/html/nextcloud/lib/public/BackgroundJob/Job.php","line":79,"function":"run","class":"OCA\\DAV\\BackgroundJob\\EventReminderJob","type":"->"},{"file":"/var/www/html/nextcloud/lib/public/BackgroundJob/TimedJob.php","line":95,"function":"execute","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/var/www/html/nextcloud/cron.php","line":151,"function":"execute","class":"OCP\\BackgroundJob\\TimedJob","type":"->"}],"File":"/var/www/html/nextcloud/3rdparty/sabre/vobject/lib/Recur/EventIterator.php","Line":306,"message":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )","CustomMessage":"Error while running background job (class: OCA\\DAV\\BackgroundJob\\EventReminderJob, arguments: )"},"id":"633da55189c55"}

Additional info

No response

rybaha avatar Oct 05 '22 15:10 rybaha

May be its something related to #29896

rybaha avatar Oct 11 '22 14:10 rybaha

Looks like v25.0.3 will have that PR. I hope, we'll see it soon. I've a bunch of events which trigger this error message.

oktayacikalin avatar Jan 13 '23 23:01 oktayacikalin

Hi, please update to 24.0.9 or better 25.0.3 and report back if it fixes the issue. Thank you!

My goal is to add a label like e.g. 25-feedback to this ticket of an up-to-date major Nextcloud version where the bug could be reproduced. However this is not going to work without your help. So thanks for all your effort!

If you don't manage to reproduce the issue in time and the issue gets closed but you can reproduce the issue afterwards, feel free to create a new bug report with up-to-date information by following this link: https://github.com/nextcloud/server/issues/new?assignees=&labels=bug%2C0.+Needs+triage&template=BUG_REPORT.yml&title=%5BBug%5D%3A+

szaimen avatar Jan 23 '23 15:01 szaimen

Hi, please update to 24.0.9 or better 25.0.3 and report back if it fixes the issue. Thank you!

Hi! Updated to 25.0.3 week ago, but same errors present. Any suggestions how I can track it down to the issue?

rybaha avatar Jan 23 '23 17:01 rybaha

Hi, please update to 24.0.9 or better 25.0.3 and report back if it fixes the issue. Thank you!

Have running 24/7 instance of NC 24.0.9.

Two active users have recurring events with an indefinite end date. Error "Recurring events are only allowed to generate 3500" not fixed, and reminder emails are not sent.

Sending emails from NC is configured and works fine, and for one-time events, emails are sent.

Let us know what kind of debug info you need.

Snousmoumryk avatar Jan 23 '23 18:01 Snousmoumryk

I'm now on 25.0.3 and the code change seems to work as indented. At least I'm not seeing this error anymore.

oktayacikalin avatar Jan 23 '23 21:01 oktayacikalin

Comment. Our NC setup have 50+ users with shared calendars for everyone. Its a big number of calendars to check even via guessing SQL queries I've tried some time ago. So any suggestions on that would be helpful since its a Error level of message.

rybaha avatar Jan 25 '23 10:01 rybaha

My mistake click on "close with comment", sorry.

rybaha avatar Jan 25 '23 10:01 rybaha

Also I have calcardbackup configued, and I can browse exported files for anomalies if any. That helped me once to check wrong timezone configured for some users. May be there are some obvious points for calendar files I can check. Thank you in advance!

rybaha avatar Jan 25 '23 10:01 rybaha

Issue still present, I see a lot of this messages in the log. Nextcloud 25.0.3..

rybaha avatar Feb 10 '23 10:02 rybaha

Hi, please update to 24.0.9 or better 25.0.3 and report back if it fixes the issue. Thank you!

My goal is to add a label like e.g. 25-feedback to this ticket of an up-to-date major Nextcloud version where the bug could be reproduced. However this is not going to work without your help. So thanks for all your effort!

If you don't manage to reproduce the issue in time and the issue gets closed but you can reproduce the issue afterwards, feel free to create a new bug report with up-to-date information by following this link: https://github.com/nextcloud/server/issues/new?assignees=&labels=bug%2C0.+Needs+triage&template=BUG_REPORT.yml&title=%5BBug%5D%3A+

Filed as new bug as suggested. https://github.com/nextcloud/server/issues/36659

rybaha avatar Feb 10 '23 10:02 rybaha

Is anything I can do on my side to help track this issue? I can proceed via SQL queries inspection or evaluate calendar dump to find that caused that behavior. It might be the case that some users misuse calendar events that caused such errors. Thank you in advance!

rybaha avatar Feb 10 '23 12:02 rybaha

I found that some users set "End repeat" as "never" instead of some date or number of occurences. For their side its look like normal to not predict end date for such events, I can understand that. That is why theorepically this can lead to 3500+ events..

rybaha avatar Feb 10 '23 13:02 rybaha

With 25.0.4 I can't see those messages anymore.

rybaha avatar Mar 01 '23 12:03 rybaha

Hi @rybaha - Just wanted to send one last check in to make sure you haven't seen this return? We'll close out this issue if it seems fixed. Thanks!

joshtrichards avatar Aug 28 '23 21:08 joshtrichards

Hi @rybaha - Just wanted to send one last check in to make sure you haven't seen this return? We'll close out this issue if it seems fixed. Thanks!

No new messages in logs. Please close this ticket. Thank you!

rybaha avatar Aug 29 '23 09:08 rybaha