So I am thinking I may have come across some sort of bug while preparing to update existing tickets with the new custom object and a default value.
I am using the Scheduler to set a default value for my new custom object in existing tickets, but nothing seems to be updated even though the Scheduler says it will process the relevant tickets. As I am not totally sure if this is a bug or just me doing something stupid, I’ll post my issue and findings here:
Some possibly noteworthy facts:
- I have not messed with the custom object in the database on this particular instance
- After spotting this possible issue and prior to re-testing and submitting this report, I have updated the Zammad package on our Ubuntu 20.04 testing system to the latest available version, which is 5.1.1-1655712708.d1d67c32.focal at the time of writing. The issue stayed the same
- This instance doesn’t have Core Workflows
- I’ve added some test tickets to this instance via the Rails console (awesome!)
The Scheduler:
The Schedule config:
The Zammad Production log at the time of running the Schedule (I have replaced the actual system hostname with the helpdesk.example.com
value):
I, [2022-06-20T14:44:46.245361 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [e6c5ed15-12cd-4be2-a522-9caa27a66320] from DelayedJob(default) with arguments: [521, 1] (id=346590) (queue=default) RUNNING
I, [2022-06-20T14:44:46.270386 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [e6c5ed15-12cd-4be2-a522-9caa27a66320] from DelayedJob(default) with arguments: [521, 1] (id=346590) (queue=default) COMPLETED after 0.0249
I, [2022-06-20T14:44:46.272226 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [1b60a184-f543-46b7-b0f3-a31662fe8baa] from DelayedJob(default) with arguments: [711, 1] (id=346591) (queue=default) RUNNING
I, [2022-06-20T14:44:46.302967 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [1b60a184-f543-46b7-b0f3-a31662fe8baa] from DelayedJob(default) with arguments: [711, 1] (id=346591) (queue=default) COMPLETED after 0.0306
I, [2022-06-20T14:44:46.304776 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [874091a3-df82-4a8e-a485-7d63368b81d1] from DelayedJob(default) with arguments: [817, 1] (id=346592) (queue=default) RUNNING
I, [2022-06-20T14:44:46.332900 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [874091a3-df82-4a8e-a485-7d63368b81d1] from DelayedJob(default) with arguments: [817, 1] (id=346592) (queue=default) COMPLETED after 0.0280
I, [2022-06-20T14:44:46.334843 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [83080306-3720-4c13-ab0d-3671a264ddb7] from DelayedJob(default) with arguments: [1031, 1] (id=346593) (queue=default) RUNNING
I, [2022-06-20T14:44:46.358943 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [83080306-3720-4c13-ab0d-3671a264ddb7] from DelayedJob(default) with arguments: [1031, 1] (id=346593) (queue=default) COMPLETED after 0.0240
I, [2022-06-20T14:44:46.360593 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [90eda935-bcc1-4dca-a746-8804e216c891] from DelayedJob(default) with arguments: [910, 1] (id=346594) (queue=default) RUNNING
I, [2022-06-20T14:44:46.382985 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [90eda935-bcc1-4dca-a746-8804e216c891] from DelayedJob(default) with arguments: [910, 1] (id=346594) (queue=default) COMPLETED after 0.0223
I, [2022-06-20T14:44:46.384721 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [e17f64b1-49a0-4f07-9f03-ffae6d90371b] from DelayedJob(default) with arguments: [664, 1] (id=346595) (queue=default) RUNNING
I, [2022-06-20T14:44:46.406960 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [e17f64b1-49a0-4f07-9f03-ffae6d90371b] from DelayedJob(default) with arguments: [664, 1] (id=346595) (queue=default) COMPLETED after 0.0221
I, [2022-06-20T14:44:46.408773 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [35ecb12f-630c-4d28-9ea9-7a7fa955b633] from DelayedJob(default) with arguments: [731, 1] (id=346596) (queue=default) RUNNING
I, [2022-06-20T14:44:46.431155 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [35ecb12f-630c-4d28-9ea9-7a7fa955b633] from DelayedJob(default) with arguments: [731, 1] (id=346596) (queue=default) COMPLETED after 0.0223
I, [2022-06-20T14:44:46.432960 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [25997481-2314-4089-8b1b-25d4fd4a64ea] from DelayedJob(default) with arguments: [587, 1] (id=346597) (queue=default) RUNNING
I, [2022-06-20T14:44:46.454841 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job TicketUserTicketCounterJob [25997481-2314-4089-8b1b-25d4fd4a64ea] from DelayedJob(default) with arguments: [587, 1] (id=346597) (queue=default) COMPLETED after 0.0218
I, [2022-06-20T14:44:46.456692 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [3cea66b6-29d9-491f-89dd-b355f8664ac4] from DelayedJob(default) with arguments: ["Ticket", 236] (id=346572) (queue=default) RUNNING
I, [2022-06-20T14:44:46.515176 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [3cea66b6-29d9-491f-89dd-b355f8664ac4] from DelayedJob(default) with arguments: ["Ticket", 236] (id=346572) (queue=default) COMPLETED after 0.0583
I, [2022-06-20T14:44:46.517270 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [959f66c1-4a93-46ab-b5a7-07b38288d219] from DelayedJob(default) with arguments: ["User", 521] (id=346573) (queue=default) RUNNING
I, [2022-06-20T14:44:46.565884 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [959f66c1-4a93-46ab-b5a7-07b38288d219] from DelayedJob(default) with arguments: ["User", 521] (id=346573) (queue=default) COMPLETED after 0.0484
I, [2022-06-20T14:44:46.568112 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [2ee65228-7d4e-4774-a439-bbafa750bd16] from DelayedJob(default) with arguments: ["Ticket", 237] (id=346574) (queue=default) RUNNING
I, [2022-06-20T14:44:46.624142 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [2ee65228-7d4e-4774-a439-bbafa750bd16] from DelayedJob(default) with arguments: ["Ticket", 237] (id=346574) (queue=default) COMPLETED after 0.0558
I, [2022-06-20T14:44:46.626297 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [0e42af17-47bb-4fa4-913b-acbc1870c6ee] from DelayedJob(default) with arguments: ["User", 711] (id=346575) (queue=default) RUNNING
I, [2022-06-20T14:44:46.658990 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [0e42af17-47bb-4fa4-913b-acbc1870c6ee] from DelayedJob(default) with arguments: ["User", 711] (id=346575) (queue=default) COMPLETED after 0.0326
I, [2022-06-20T14:44:46.661102 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [9c11d004-d24d-4477-8614-d5e7d41c49b0] from DelayedJob(default) with arguments: ["Ticket", 238] (id=346576) (queue=default) RUNNING
I, [2022-06-20T14:44:46.711223 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [9c11d004-d24d-4477-8614-d5e7d41c49b0] from DelayedJob(default) with arguments: ["Ticket", 238] (id=346576) (queue=default) COMPLETED after 0.0500
I, [2022-06-20T14:44:46.713345 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [4aa7369a-e9da-4db2-b39d-cbf1f9b2cd53] from DelayedJob(default) with arguments: ["User", 817] (id=346577) (queue=default) RUNNING
I, [2022-06-20T14:44:46.748685 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [4aa7369a-e9da-4db2-b39d-cbf1f9b2cd53] from DelayedJob(default) with arguments: ["User", 817] (id=346577) (queue=default) COMPLETED after 0.0352
I, [2022-06-20T14:44:46.750659 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [8ed385bc-7579-432d-ac05-942cc4bb75ca] from DelayedJob(default) with arguments: ["Ticket", 240] (id=346578) (queue=default) RUNNING
I, [2022-06-20T14:44:46.804691 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [8ed385bc-7579-432d-ac05-942cc4bb75ca] from DelayedJob(default) with arguments: ["Ticket", 240] (id=346578) (queue=default) COMPLETED after 0.0539
I, [2022-06-20T14:44:46.806645 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [dc7ac1aa-5129-49ef-ba18-1ab9125133ba] from DelayedJob(default) with arguments: ["User", 1031] (id=346579) (queue=default) RUNNING
I, [2022-06-20T14:44:46.838259 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [dc7ac1aa-5129-49ef-ba18-1ab9125133ba] from DelayedJob(default) with arguments: ["User", 1031] (id=346579) (queue=default) COMPLETED after 0.0315
I, [2022-06-20T14:44:46.840071 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [f1193db9-2b84-4b39-a61e-c6c7346333a7] from DelayedJob(default) with arguments: ["Ticket", 242] (id=346580) (queue=default) RUNNING
I, [2022-06-20T14:44:46.910325 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [f1193db9-2b84-4b39-a61e-c6c7346333a7] from DelayedJob(default) with arguments: ["Ticket", 242] (id=346580) (queue=default) COMPLETED after 0.0702
I, [2022-06-20T14:44:46.912979 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [25262027-8fca-4ee7-a9a0-c3bc6bf044ce] from DelayedJob(default) with arguments: ["User", 910] (id=346581) (queue=default) RUNNING
I, [2022-06-20T14:44:46.966495 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [25262027-8fca-4ee7-a9a0-c3bc6bf044ce] from DelayedJob(default) with arguments: ["User", 910] (id=346581) (queue=default) COMPLETED after 0.0534
I, [2022-06-20T14:44:46.968842 #3166168-182940] INFO -- : 2022-06-20T14:44:46+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [3792a26b-2fc8-4a6f-b1be-460ca0a68a72] from DelayedJob(default) with arguments: ["Organization", 36] (id=346582) (queue=default) RUNNING
I, [2022-06-20T14:44:47.115152 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [3792a26b-2fc8-4a6f-b1be-460ca0a68a72] from DelayedJob(default) with arguments: ["Organization", 36] (id=346582) (queue=default) COMPLETED after 0.1462
I, [2022-06-20T14:44:47.117369 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [a07eae43-d0db-4192-a4a4-5ae82b5cca7d] from DelayedJob(default) with arguments: ["Ticket", 243] (id=346583) (queue=default) RUNNING
I, [2022-06-20T14:44:47.171578 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [a07eae43-d0db-4192-a4a4-5ae82b5cca7d] from DelayedJob(default) with arguments: ["Ticket", 243] (id=346583) (queue=default) COMPLETED after 0.0541
I, [2022-06-20T14:44:47.173655 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [0d6e01b3-e74e-4227-a585-602be86633d7] from DelayedJob(default) with arguments: ["User", 664] (id=346584) (queue=default) RUNNING
I, [2022-06-20T14:44:47.202373 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [0d6e01b3-e74e-4227-a585-602be86633d7] from DelayedJob(default) with arguments: ["User", 664] (id=346584) (queue=default) COMPLETED after 0.0286
I, [2022-06-20T14:44:47.204270 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [d9c09c4a-32fb-404c-bdad-57e36f6144c4] from DelayedJob(default) with arguments: ["Ticket", 244] (id=346585) (queue=default) RUNNING
I, [2022-06-20T14:44:47.381377 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [d9c09c4a-32fb-404c-bdad-57e36f6144c4] from DelayedJob(default) with arguments: ["Ticket", 244] (id=346585) (queue=default) COMPLETED after 0.1770
I, [2022-06-20T14:44:47.383537 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [1783d564-ce65-4433-9587-6e34c36f4c48] from DelayedJob(default) with arguments: ["User", 731] (id=346586) (queue=default) RUNNING
I, [2022-06-20T14:44:47.412236 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [1783d564-ce65-4433-9587-6e34c36f4c48] from DelayedJob(default) with arguments: ["User", 731] (id=346586) (queue=default) COMPLETED after 0.0286
I, [2022-06-20T14:44:47.414027 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [d9cb28a7-2b25-4580-87d3-e3863219e980] from DelayedJob(default) with arguments: ["Ticket", 245] (id=346587) (queue=default) RUNNING
I, [2022-06-20T14:44:47.463593 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexAssociationsJob [d9cb28a7-2b25-4580-87d3-e3863219e980] from DelayedJob(default) with arguments: ["Ticket", 245] (id=346587) (queue=default) COMPLETED after 0.0495
I, [2022-06-20T14:44:47.465261 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [5a36bb28-be62-48d7-bfe9-8f4fbbdb7a54] from DelayedJob(default) with arguments: ["User", 587] (id=346588) (queue=default) RUNNING
I, [2022-06-20T14:44:47.502316 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [5a36bb28-be62-48d7-bfe9-8f4fbbdb7a54] from DelayedJob(default) with arguments: ["User", 587] (id=346588) (queue=default) COMPLETED after 0.0369
I, [2022-06-20T14:44:47.504186 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [0aeda8fe-3b8b-45fa-ac76-80f5accadb0c] from DelayedJob(default) with arguments: ["Organization", 12] (id=346589) (queue=default) RUNNING
I, [2022-06-20T14:44:47.546506 #3166168-182940] INFO -- : 2022-06-20T14:44:47+0200: [Worker(host:helpdesk.example.com pid:3166168)] Job SearchIndexJob [0aeda8fe-3b8b-45fa-ac76-80f5accadb0c] from DelayedJob(default) with arguments: ["Organization", 12] (id=346589) (queue=default) COMPLETED after 0.0422
One of the tickets in the database which should have been affected by the Schedule:
zammad=# SELECT * FROM tickets WHERE id = 236;
-[ RECORD 1 ]----------------+------------------------
id | 236
group_id | 13
priority_id | 1
state_id | 3
organization_id |
number | 59236
title | some title äöüß625156
owner_id | 41
customer_id | 521
note |
first_response_at |
first_response_escalation_at |
first_response_in_min |
first_response_diff_in_min |
close_at |
close_escalation_at |
close_in_min |
close_diff_in_min |
update_escalation_at |
update_in_min |
update_diff_in_min |
last_contact_at | 2022-06-20 11:17:09.156
last_contact_agent_at |
last_contact_customer_at | 2022-06-20 11:17:09.156
last_owner_update_at |
create_article_type_id | 5
create_article_sender_id | 2
article_count | 1
escalation_at |
pending_time |
type |
time_unit |
preferences |
updated_by_id | 1
created_by_id | 1
created_at | 2022-06-20 11:17:09.104
updated_at | 2022-06-20 11:17:09.18
content_class | {}
Please let me know if I should submit a GitHub issue if this is actually a bug, and if I can provide any further info to help in troubleshooting or diagnosing the issue.