Error "Scheduler may not run" after a few hours

jacotec · July 27, 2020, 3:48pm

Infos:

Used Zammad version: 3.4.0
Used Zammad installation source: (source, package, …) Package
Operating system: Centos 7
Browser + version: Firefox, Safari, Chrome … (independent from Browser)

I have an issue with my Zammad installation (it was moved from another Server via Backup/Restore which ran the same OS and same Zammad version). After a few hours of running I see tickets not arriving in time from mailboxes. In Monitoring I see messages like:

scheduler may not run (last execution of OnlineNotification.cleanup about 4 hours over) - please contact your system administrator

I don’t see what’s causing this. Some threads in this forum point to Elasticsearch, but ES 6 is configured properly with 2GB of Java Memory and installed Ingest-Attachment. I also have manually recreated the search index which did not help.

In the Zammad log I periodically see these bunches of entries where the search index is added to Delayed Job multiple times within a few ms - I don’t understand why:

I, [2020-07-27T17:24:20.138792 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 177bdd94-a55c-48d3-8bd9-dcf38961c421) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:20.139024 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 177bdd94-a55c-48d3-8bd9-dcf38961c421) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:20.140129 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 30849082-c996-463c-b6d5-efcf49b904b1) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:20.140366 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 30849082-c996-463c-b6d5-efcf49b904b1) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:20.369214 #764-47264394136980]  INFO -- : Fetchd image 'https://graph.facebook.com/178412842236677/picture?type=large', http code: 200
    I, [2020-07-27T17:24:20.395511 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: d227a524-0731-43de-a553-2eea90afc0e4) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:20.395693 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: d227a524-0731-43de-a553-2eea90afc0e4) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.396633 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 062ae7aa-d576-41a2-84ba-0efda90766d7) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:20.396762 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 062ae7aa-d576-41a2-84ba-0efda90766d7) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.813007 #764-47264394136980]  INFO -- : Fetchd image 'https://graph.facebook.com/10214367723720569/picture?type=large', http code: 200
    I, [2020-07-27T17:24:20.836772 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 99364553-a942-43ee-8f30-fdd33af16ca2) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:20.836953 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 99364553-a942-43ee-8f30-fdd33af16ca2) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.837881 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 3c435c42-9a00-4ea4-ad1c-11ffab0c6e05) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:20.838017 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 3c435c42-9a00-4ea4-ad1c-11ffab0c6e05) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.862473 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: a99e10c5-010c-449b-bc65-4709e505d3e3) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:20.862706 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: a99e10c5-010c-449b-bc65-4709e505d3e3) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.863623 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: baf0305c-e9f6-44b5-8f7f-c306619d94d0) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:20.863736 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: baf0305c-e9f6-44b5-8f7f-c306619d94d0) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.892825 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: cfbd813e-a285-4371-993a-8138b7cc7abc) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:20.892989 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: cfbd813e-a285-4371-993a-8138b7cc7abc) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.893909 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 48594326-c09e-4db1-8301-9781c33bb65f) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:20.894053 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 48594326-c09e-4db1-8301-9781c33bb65f) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.917611 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 610759aa-1b07-4530-9a31-09890b8f2d23) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:20.917769 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 610759aa-1b07-4530-9a31-09890b8f2d23) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.918670 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 5e32afa2-1ccc-4c20-b569-a179952f010a) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:20.918783 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 5e32afa2-1ccc-4c20-b569-a179952f010a) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:20.957737 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 4696b967-73ea-4ca7-929d-5d7d45a1bdaf) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:20.957899 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 4696b967-73ea-4ca7-929d-5d7d45a1bdaf) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:20.959024 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: d6d3bc9c-8532-4a74-a5b5-c2d8aae6f1cc) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:20.959217 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: d6d3bc9c-8532-4a74-a5b5-c2d8aae6f1cc) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:20.982775 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: b96ccbad-a4b0-41cc-af70-bcfaca87afa4) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:20.982950 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: b96ccbad-a4b0-41cc-af70-bcfaca87afa4) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:20.984410 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 3cb01670-0cbb-463a-b8a9-cb3232acd7cb) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:20.984684 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 3cb01670-0cbb-463a-b8a9-cb3232acd7cb) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:21.001341 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 496e1e79-f5b2-4884-ae70-572442c9e8a1) because of already existing job with lock key 'SearchIndexJob/User/2044'.
    I, [2020-07-27T17:24:21.001479 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 496e1e79-f5b2-4884-ae70-572442c9e8a1) to DelayedJob(default) with arguments: "User", 2044
    I, [2020-07-27T17:24:21.002565 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 7511207e-6331-4b19-bfa4-b7dc78ad3536) because of already existing job with lock key 'SearchIndexAssociationsJob/User/2044'.
    I, [2020-07-27T17:24:21.002778 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 7511207e-6331-4b19-bfa4-b7dc78ad3536) to DelayedJob(default) with arguments: "User", 2044
    I, [2020-07-27T17:24:21.235025 #764-47264394136980]  INFO -- : Fetchd image 'https://graph.facebook.com/683463911790824/picture?type=large', http code: 200
    I, [2020-07-27T17:24:21.449868 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: d10c9f63-72cb-4c70-a541-47fb0f46ceaa) because of already existing job with lock key 'SearchIndexJob/User/787'.
    I, [2020-07-27T17:24:21.450051 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: d10c9f63-72cb-4c70-a541-47fb0f46ceaa) to DelayedJob(default) with arguments: "User", 787
    I, [2020-07-27T17:24:21.451129 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 0305b015-df9f-4542-bbd4-d0780776b69b) because of already existing job with lock key 'SearchIndexAssociationsJob/User/787'.
    I, [2020-07-27T17:24:21.451366 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 0305b015-df9f-4542-bbd4-d0780776b69b) to DelayedJob(default) with arguments: "User", 787
    I, [2020-07-27T17:24:21.676003 #764-47264394136980]  INFO -- : Fetchd image 'https://graph.facebook.com/10202064145148204/picture?type=large', http code: 200
    I, [2020-07-27T17:24:21.925937 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 302f7e84-2fe6-4346-8892-1cbbf903bc78) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:21.926110 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 302f7e84-2fe6-4346-8892-1cbbf903bc78) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:21.927038 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 5c22a9a2-d27e-4693-8f93-b6a39890e9cc) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:21.927156 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 5c22a9a2-d27e-4693-8f93-b6a39890e9cc) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:21.955263 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 2b1862fa-786a-45a8-a143-b0f46e30be0e) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:21.955439 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 2b1862fa-786a-45a8-a143-b0f46e30be0e) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:21.956345 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: a1f8ef34-d446-4f42-bea4-73aca804f669) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:21.956462 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: a1f8ef34-d446-4f42-bea4-73aca804f669) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:21.983048 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 8c85f5c3-b4b2-4193-851a-6f62589adf99) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:21.983203 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 8c85f5c3-b4b2-4193-851a-6f62589adf99) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:21.984095 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 3b375e4a-a533-42c6-8c0f-1d2cb20e5dfc) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:21.984252 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 3b375e4a-a533-42c6-8c0f-1d2cb20e5dfc) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:22.016202 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: fb2be202-7bb0-4384-b5e1-7e96755edb7f) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:22.016524 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: fb2be202-7bb0-4384-b5e1-7e96755edb7f) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.018048 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 601f2513-5b46-4ed1-ab81-a6503d74874c) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:22.018331 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 601f2513-5b46-4ed1-ab81-a6503d74874c) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.044991 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: d9874738-e623-4c58-8e69-dd688a285266) because of already existing job with lock key 'SearchIndexJob/User/1395'.
    I, [2020-07-27T17:24:22.045179 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: d9874738-e623-4c58-8e69-dd688a285266) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:22.046456 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 263c16da-59ba-49da-a305-e35585760f54) because of already existing job with lock key 'SearchIndexAssociationsJob/User/1395'.
    I, [2020-07-27T17:24:22.046578 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 263c16da-59ba-49da-a305-e35585760f54) to DelayedJob(default) with arguments: "User", 1395
    I, [2020-07-27T17:24:22.082270 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 662750f6-fc5c-48c4-90bf-c891761fb329) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:22.082512 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 662750f6-fc5c-48c4-90bf-c891761fb329) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.083440 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 4958d8ee-f52d-49fe-81b1-6131015ba862) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:22.083553 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 4958d8ee-f52d-49fe-81b1-6131015ba862) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.108896 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 4f1e3d1c-c26d-4bc5-8e40-df35a6b20565) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:22.109072 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 4f1e3d1c-c26d-4bc5-8e40-df35a6b20565) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.110000 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 434b36e7-83bb-43ac-bdf3-cf57360d790b) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:22.110126 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 434b36e7-83bb-43ac-bdf3-cf57360d790b) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.133614 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 42360726-3613-4af9-bfa6-1188b5f1f8c2) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:22.133798 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 42360726-3613-4af9-bfa6-1188b5f1f8c2) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.134703 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 5b5bf1d7-151b-40d7-9c37-41f3587dc6f4) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:22.134819 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 5b5bf1d7-151b-40d7-9c37-41f3587dc6f4) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.157378 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 880eb5ac-d800-4513-8f3a-d680afecce16) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:22.157554 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 880eb5ac-d800-4513-8f3a-d680afecce16) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.158493 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 40d23cdd-f194-4404-a1c8-5807506c56e8) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:22.158609 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 40d23cdd-f194-4404-a1c8-5807506c56e8) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.182117 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: a8e16a3e-6e6a-420c-8420-df33f09f81a2) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:22.182360 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: a8e16a3e-6e6a-420c-8420-df33f09f81a2) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.183273 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: dc1dc9fb-f1da-493d-889f-6877a0cae787) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:22.183385 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: dc1dc9fb-f1da-493d-889f-6877a0cae787) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.222728 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 826934cc-0d26-49e0-8615-1518c6a2076b) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:22.222911 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 826934cc-0d26-49e0-8615-1518c6a2076b) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.223887 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 3643a751-b152-4d28-9060-31dcb3dc7afa) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:22.224023 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 3643a751-b152-4d28-9060-31dcb3dc7afa) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.251789 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 3d813711-f339-4fd0-8ddc-9330ef0326f8) because of already existing job with lock key 'SearchIndexJob/User/25'.
    I, [2020-07-27T17:24:22.252143 #764-47264394136980]  INFO -- : Enqueued SearchIndexJob (Job ID: 3d813711-f339-4fd0-8ddc-9330ef0326f8) to DelayedJob(default) with arguments: "User", 25
    I, [2020-07-27T17:24:22.254081 #764-47264394136980]  INFO -- : Won't enqueue SearchIndexAssociationsJob (Job ID: 727495de-2783-4188-9314-b5aaedde6657) because of already existing job with lock key 'SearchIndexAssociationsJob/User/25'.
    I, [2020-07-27T17:24:22.254386 #764-47264394136980]  INFO -- : Enqueued SearchIndexAssociationsJob (Job ID: 727495de-2783-4188-9314-b5aaedde6657) to DelayedJob(default) with arguments: "User", 25

More info:

[root@fblhelpdesk ~]# zammad run rails r 'p Delayed::Job.count'
34
[root@fblhelpdesk ~]# zammad run rails r 'p Delayed::Job.first'
#<Delayed::Backend::ActiveRecord::Job id: 11914080, priority: 300, attempts: 0, handler: "--- !ruby/object:ActiveJob::QueueAdapters::Delayed...", last_error: nil, run_at: "2020-07-27 11:16:18", locked_at: "2020-07-27 11:16:20", failed_at: nil, locked_by: "host:fblhelpdesk pid:764", queue: "default", created_at: "2020-07-27 11:16:18", updated_at: "2020-07-27 11:16:18">
[root@fblhelpdesk ~]# zammad run rails r 'p Delayed::Job.last'
#<Delayed::Backend::ActiveRecord::Job id: 11914117, priority: 200, attempts: 0, handler: "--- !ruby/object:ActiveJob::QueueAdapters::Delayed...", last_error: nil, run_at: "2020-07-27 15:56:45", locked_at: nil, failed_at: nil, locked_by: nil, queue: "default", created_at: "2020-07-27 15:56:45", updated_at: "2020-07-27 15:56:45">

Any ideas how to fix this is highly appreciated.

BR,
Marco

MrGeneration · August 3, 2020, 2:11pm

Heya,

let me pick you up really quick to clear a miss understanding before hand:
The “Won’t enqueue (…)” messages in the log file are an information, not an error or some faulty behavior.

Zammad does this to only have one update job per ticket/user/article/organization. We do this because in busy systems when you update the same ticket more often, this other wise would lead to you having dozens of update jobs for the same e.g. ticket. This will consume more time and eventually degrade your systems performance even more. Beside it doesn’t provide any benefit if your system updates the index for the same ticket 20 times in a row when technically one job would have been enough.

Thus we only enqueue one searchindex update job - this is what above message does want to tell you.

Looks like essential things did change?
With essential I do mean CPU type (so GHz per core) and number of cores.
Also change of virtualization plattform may be a relevantg change.

Anyway, please check your process list. Is scheduler.rb stuck at 100% on one core?
Does this warning appear permanently or eventually disappear?

Ensure that zammad-worker is running. You may want to try to restart Zammad and check your logfile for actual errors.

After this time that went by now, did the delayed jobs increase or decrease?

jacotec · August 4, 2020, 6:09pm

I’ve rechecked everything and found that one of my email addresses had wrong credentials configured (so the email polling did not work on this single email account).

Nevertheless this should not lead to the queue issue and that the polling of other, properly configured boxes, do not work.

MrGeneration · August 14, 2020, 8:28am

I do agree.
Up to now I’ve never seen any Zammad instances which scheduler completely strikes its work if one email account is not working.

Maybe there was another side effecting reason to that which silently vanished as soon as you fixed the credentials. Maybe also carefully monitor your systems performance, may be a performance issue under the hood.

system · December 12, 2020, 8:28am

This topic was automatically closed 120 days after the last reply. New replies are no longer allowed.