Automations are not running after Zammad upgrade from 6.1 on CentOS to 6.2 on Debian 12

Infos:

  • Used Zammad version: 6.2
  • Used Zammad installation type: package
  • Operating system: Debian 12
  • Browser + version: Firefox 123, Chromium 121

Expected behavior:

  • Automation should run and do the tasks like before in version 6.1 on CentOS 7.9

Actual behavior:

  • Automation is not running and working
  • View shows there are tickets that should be worked on, but nothing happens

Steps to reproduce the behavior:

  • Zammad 6.1 was running on CentOS 7.9
  • Installed new server with Debian 12 and Zammad 6.2
  • Created a backup with zammad_backup.sh and config
BACKUP_DIR='/opt/zammad_backup'
HOLD_DAYS='10'
FULL_FS_DUMP='no'
DEBUG='no'
  • Restored backup with zammad_restore.sh
  • Also changed from HTTP to HTTPS

Rest is working as expected and no further issues. I can not find further information in production.log. Any hint is welcome.

Thank you

Hi @sven-ruess. Could you please provide more information about the automation you are referring to?

Hi @fliebe92, of course I can provide further information about one example automation.

There exists tickets for hardware. Every Tuesday morning ad 8:20 there should be send mails for those tickets, to remind the user, that they can pick up there hardware.
Abstract from log:

I, [2024-02-28T13:42:19.147313#1540986-142000]  INFO -- : ProcessScheduledJobs running...
I, [2024-02-28T13:42:19.148093#1540986-142000]  INFO -- : Running job thread for 'Process ticket escalations.' (Ticket.process_escalation) status is: sleep
I, [2024-02-28T13:42:19.148115#1540986-142000]  INFO -- : Running job thread for 'Check channels.' (Channel.fetch) status is: sleep
I, [2024-02-28T13:42:19.148195#1540986-142000]  INFO -- : Running job thread for 'Generate 'Session' data.' (Sessions.jobs) status is: sleep
I, [2024-02-28T13:42:19.148218#1540986-142000]  INFO -- : Running job thread for 'Check 'Channel' streams.' (Channel.stream) status is: sleep
I, [2024-02-28T13:42:19.238188#555-45971860]  INFO -- : Completed 200 OK in 257ms (Views: 17.0ms | ActiveRecord: 17.9ms | Allocations: 136262)
I, [2024-02-28T13:42:19.332675#555-46472820]  INFO -- : Started GET "/api/v1/tickets/17637?all=true&auto_assign=true&_=1709122325471" for 172.17.90.11 at 2024-02-28 13:42:19 +0100
I, [2024-02-28T13:42:19.335372#555-46472820]  INFO -- : Processing by TicketsController#show as JSON
I, [2024-02-28T13:42:19.335394#555-46472820]  INFO -- :   Parameters: {"all"=>"true", "auto_assign"=>"true", "_"=>"1709122325471", "id"=>"17637"}
I, [2024-02-28T13:42:19.419617#555-46472820]  INFO -- : Completed 200 OK in 84ms (Views: 17.4ms | ActiveRecord: 10.4ms | Allocations: 103612)
I, [2024-02-28T13:42:19.758960#555-46634200]  INFO -- : Started GET "/api/v1/tickets/17885?all=true&auto_assign=true&_=1709122325472" for 172.17.90.11 at 2024-02-28 13:42:19 +0100
I, [2024-02-28T13:42:19.761497#555-46634200]  INFO -- : Processing by TicketsController#show as JSON
I, [2024-02-28T13:42:19.761519#555-46634200]  INFO -- :   Parameters: {"all"=>"true", "auto_assign"=>"true", "_"=>"1709122325472", "id"=>"17885"}
I, [2024-02-28T13:42:19.828896#555-46634200]  INFO -- : Completed 200 OK in 67ms (Views: 6.6ms | ActiveRecord: 10.4ms | Allocations: 94749)
I, [2024-02-28T13:42:22.126204#555-45976560]  INFO -- : Started PUT "/api/v1/jobs/29" for 172.17.90.43 at 2024-02-28 13:42:22 +0100
I, [2024-02-28T13:42:22.128948#555-45976560]  INFO -- : Processing by JobsController#update as JSON
I, [2024-02-28T13:42:22.128996#555-45976560]  INFO -- :   Parameters: {"name"=>"Abholbereite Sachen - Erinnerungen losschicken", "object"=>"Ticket", "timeplan"=>{"days"=>{"Mon"=>false, "Tue"=>true, "Wed"=>false, "Thu"=>false, "Fri"=>false, "Sat"=>false, "Sun"=>false}, "hours"=>{"0"=>false, "1"=>false, "2"=>false, "3"=>false, "4"=>false, "5"=>false, "6"=>false, "7"=>false, "8"=>true, "9"=>false, "10"=>false, "11"=>false, "12"=>false, "13"=>false, "14"=>false, "15"=>false, "16"=>false, "17"=>false, "18"=>false, "19"=>false, "20"=>false, "21"=>false, "22"=>false, "23"=>false}, "minutes"=>{"0"=>false, "10"=>false, "20"=>true, "30"=>false, "40"=>false, "50"=>false}}, "condition"=>{"ticket.state_id"=>{"operator"=>"is not", "value"=>["4"]}, "ticket.title"=>{"operator"=>"contains", "value"=>"--abholbereit"}}, "perform"=>{"notification.email"=>{"body"=>"[FILTERED]", "internal"=>"false", "recipient"=>["ticket_customer"], "subject"=>"[IT-Support] Für dich liegt etwas zur Abholung bereit!", "include_attachments"=>"false"}}, "disable_notification"=>true, "note"=>"", "active"=>true, "id"=>"29"}
I, [2024-02-28T13:42:22.131521#555-46562400]  INFO -- : Started GET "/api/v1/jobs?full=true&page=1&per_page=150&sort_by=name,%20id&order_by=ASC,%20ASC&_=1709101817075" for 172.17.90.43 at 2024-02-28 13:42:22 +0100
I, [2024-02-28T13:42:22.134991#555-46562400]  INFO -- : Processing by JobsController#index as JSON
I, [2024-02-28T13:42:22.135244#555-46562400]  INFO -- :   Parameters: {"full"=>"true", "page"=>"1", "per_page"=>"150", "sort_by"=>"name, id", "order_by"=>"ASC, ASC", "_"=>"1709101817075"}
I, [2024-02-28T13:42:22.160746#555-46472640]  INFO -- : Started GET "/api/v1/tickets/13608?all=true&auto_assign=true&_=1708931509079" for 172.24.100.165 at 2024-02-28 13:42:22 +0100
I, [2024-02-28T13:42:22.304041#555-46472640]  INFO -- : Processing by TicketsController#show as JSON
I, [2024-02-28T13:42:22.304468#555-46472640]  INFO -- :   Parameters: {"all"=>"true", "auto_assign"=>"true", "_"=>"1708931509079", "id"=>"13608"}
I, [2024-02-28T13:42:22.305143#555-46562860]  INFO -- : Started GET "/api/v1/tickets/17719?all=true&auto_assign=true&_=1708931509082" for 172.24.100.165 at 2024-02-28 13:42:22 +0100
I, [2024-02-28T13:42:22.310567#555-46562860]  INFO -- : Processing by TicketsController#show as JSON
I, [2024-02-28T13:42:22.311035#555-46562860]  INFO -- :   Parameters: {"all"=>"true", "auto_assign"=>"true", "_"=>"1708931509082", "id"=>"17719"}
I, [2024-02-28T13:42:22.312736#555-46472780]  INFO -- : Started GET "/api/v1/tickets/14130?all=true&auto_assign=true&_=1708931509081" for 172.24.100.165 at 2024-02-28 13:42:22 +0100
I, [2024-02-28T13:42:22.317009#555-46562360]  INFO -- : Started GET "/api/v1/tickets/14074?all=true&auto_assign=true&_=1708931509080" for 172.24.100.165 at 2024-02-28 13:42:22 +0100
I, [2024-02-28T13:42:22.319645#555-46472780]  INFO -- : Processing by TicketsController#show as JSON
I, [2024-02-28T13:42:22.320240#555-46472780]  INFO -- :   Parameters: {"all"=>"true", "auto_assign"=>"true", "_"=>"1708931509081", "id"=>"14130"}

Other automation will change after two weeks priority from 1 to 2.
Abstract from log:

I, [2024-02-28T13:42:29.151205#1540986-142000]  INFO -- : Running job thread for 'Process ticket escalations.' (Ticket.process_escalation) status is: sleep
I, [2024-02-28T13:42:29.151226#1540986-142000]  INFO -- : Running job thread for 'Check channels.' (Channel.fetch) status is: sleep
I, [2024-02-28T13:42:29.154259#1540986-1666640]  INFO -- : execute Ticket.process_auto_unassign (try_count 0)...
I, [2024-02-28T13:42:29.155499#1540986-1666640]  INFO -- : ended Ticket.process_auto_unassign took: 0.003806716 seconds.
I, [2024-02-28T13:42:30.074108#555-46634200]  INFO -- : Started PUT "/api/v1/jobs/30" for 172.17.90.43 at 2024-02-28 13:42:30 +0100
I, [2024-02-28T13:42:30.076884#555-46634200]  INFO -- : Processing by JobsController#update as JSON
I, [2024-02-28T13:42:30.076937#555-46634200]  INFO -- :   Parameters: {"name"=>"Clone: Prio 1 Tickets nach 3 Wochen auf Prio 2 setzen", "object"=>"Ticket", "timeplan"=>{"days"=>{"Mon"=>true, "Tue"=>true, "Wed"=>true, "Thu"=>true, "Fri"=>true, "Sat"=>true, "Sun"=>true}, "hours"=>{"0"=>false, "1"=>false, "2"=>false, "3"=>false, "4"=>false, "5"=>false, "6"=>false, "7"=>false, "8"=>false, "9"=>false, "10"=>false, "11"=>false, "12"=>false, "13"=>false, "14"=>true, "15"=>false, "16"=>false, "17"=>false, "18"=>false, "19"=>false, "20"=>false, "21"=>false, "22"=>false, "23"=>false}, "minutes"=>{"0"=>false, "10"=>true, "20"=>false, "30"=>false, "40"=>false, "50"=>false}}, "condition"=>{"ticket.state_id"=>{"operator"=>"is", "value"=>["8", "1", "2"]}, "ticket.priority_id"=>{"operator"=>"is", "value"=>["1"]}, "ticket.updated_at"=>{"operator"=>"before (relative)", "value"=>"3", "range"=>"week"}, "ticket.owner_id"=>{"operator"=>"is", "pre_condition"=>"not_set", "value"=>[], "value_completion"=>""}, "ticket.group_id"=>{"operator"=>"is", "value"=>["2", "9"], "value_completion"=>""}}, "perform"=>{"article.note"=>{"body"=>"[FILTERED]", "internal"=>"true", "subject"=>"Priorität 1 -> 2"}, "ticket.priority_id"=>{"value"=>"2"}}, "disable_notification"=>false, "note"=>"Priorität nach 3 Wochen automatisch erhöht.", "active"=>true, "id"=>"30"}
I, [2024-02-28T13:42:30.079745#555-46562400]  INFO -- : Started GET "/api/v1/jobs?full=true&page=1&per_page=150&sort_by=name,%20id&order_by=ASC,%20ASC&_=1709101817079" for 172.17.90.43 at 2024-02-28 13:42:30 +0100
I, [2024-02-28T13:42:30.083733#555-46562400]  INFO -- : Processing by JobsController#index as JSON
I, [2024-02-28T13:42:30.083758#555-46562400]  INFO -- :   Parameters: {"full"=>"true", "page"=>"1", "per_page"=>"150", "sort_by"=>"name, id", "order_by"=>"ASC, ASC", "_"=>"1709101817079"}
I, [2024-02-28T13:42:30.136679#555-46562400]  INFO -- : Completed 200 OK in 53ms (Views: 5.2ms | ActiveRecord: 17.5ms | Allocations: 60757)
I, [2024-02-28T13:42:30.138319#555-46634200]  INFO -- : Completed 200 OK in 61ms (Views: 0.3ms | ActiveRecord: 16.1ms | Allocations: 68479)
I, [2024-02-28T13:42:30.149820#555-46562860]  INFO -- : Started GET "/api/v1/jobs?full=true&page=1&per_page=150&sort_by=name,%20id&order_by=ASC,%20ASC&_=1709101817080" for 172.17.90.43 at 2024-02-28 13:42:30 +0100
I, [2024-02-28T13:42:30.151494#1540986-142000]  INFO -- : Running job thread for 'Generate 'Session' data.' (Sessions.jobs) status is: sleep
I, [2024-02-28T13:42:30.151606#1540986-142000]  INFO -- : Running job thread for 'Check 'Channel' streams.' (Channel.stream) status is: sleep
I, [2024-02-28T13:42:30.152171#555-46562860]  INFO -- : Processing by JobsController#index as JSON
I, [2024-02-28T13:42:30.152194#555-46562860]  INFO -- :   Parameters: {"full"=>"true", "page"=>"1", "per_page"=>"150", "sort_by"=>"name, id", "order_by"=>"ASC, ASC", "_"=>"1709101817080"}
I, [2024-02-28T13:42:30.181651#555-46562860]  INFO -- : Completed 200 OK in 29ms (Views: 5.4ms | ActiveRecord: 4.5ms | Allocations: 45370)
I, [2024-02-28T13:42:30.374403#555-46472640]  INFO -- : Started POST "/api/v1/knowledge_bases/init" for 172.24.101.51 at 2024-02-28 13:42:30 +0100
I, [2024-02-28T13:42:30.377137#555-46472640]  INFO -- : Processing by KnowledgeBasesController#init as JSON
I, [2024-02-28T13:42:30.377163#555-46472640]  INFO -- :   Parameters: {"answer_translation_content_ids"=>[67, 66, 32]}
I, [2024-02-28T13:42:30.544068#555-46472640]  INFO -- : Completed 200 OK in 167ms (Views: 10.6ms | ActiveRecord: 31.4ms | Allocations: 206576)
I, [2024-02-28T13:42:30.567151#555-45976560]  INFO -- : Started GET "/api/v1/jobs/?full=true&_=1709101817081" for 172.17.90.43 at 2024-02-28 13:42:30 +0100
I, [2024-02-28T13:42:30.569170#555-45976560]  INFO -- : Processing by JobsController#index as JSON
I, [2024-02-28T13:42:30.569190#555-45976560]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1709101817081"}
I, [2024-02-28T13:42:30.742195#555-45976560]  INFO -- : Completed 200 OK in 173ms (Views: 5.3ms | ActiveRecord: 5.1ms | Allocations: 45150)
I, [2024-02-28T13:42:30.749675#555-46472780]  INFO -- : Started GET "/api/v1/jobs?full=true&page=1&per_page=150&sort_by=name,%20id&order_by=ASC,%20ASC&_=1709101817082" for 172.17.90.43 at 2024-02-28 13:42:30 +0100
I, [2024-02-28T13:42:30.752068#555-46472780]  INFO -- : Processing by JobsController#index as JSON
I, [2024-02-28T13:42:30.752092#555-46472780]  INFO -- :   Parameters: {"full"=>"true", "page"=>"1", "per_page"=>"150", "sort_by"=>"name, id", "order_by"=>"ASC, ASC", "_"=>"1709101817082"}
I, [2024-02-28T13:42:30.783324#555-46472780]  INFO -- : Completed 200 OK in 31ms (Views: 4.8ms | ActiveRecord: 6.1ms | Allocations: 44960)
I, [2024-02-28T13:42:31.773230#555-46562360]  INFO -- : Started POST "/api/v1/tickets/selector" for 172.17.90.43 at 2024-02-28 13:42:31 +0100
I, [2024-02-28T13:42:31.775809#555-46562360]  INFO -- : Processing by SelectorsController#preview as JSON
I, [2024-02-28T13:42:31.775845#555-46562360]  INFO -- :   Parameters: {"condition"=>{"ticket.state_id"=>{"operator"=>"is", "value"=>["8", "1", "2"]}, "ticket.priority_id"=>{"operator"=>"is", "value"=>["2"]}, "ticket.updated_at"=>{"operator"=>"before (relative)", "value"=>"2", "range"=>"week"}, "ticket.owner_id"=>{"operator"=>"is", "pre_condition"=>"not_set", "value"=>[], "value_completion"=>""}, "ticket.group_id"=>{"operator"=>"is", "value"=>["2", "9"], "value_completion"=>""}}, "object"=>"tickets"}
I, [2024-02-28T13:42:31.803316#555-46562360]  INFO -- : Completed 200 OK in 27ms (Views: 3.5ms | ActiveRecord: 4.8ms | Allocations: 34308)
I, [2024-02-28T13:42:35.055859#555-46472740]  INFO -- : Started PUT "/api/v1/jobs/31" for 172.17.90.43 at 2024-02-28 13:42:35 +0100
I, [2024-02-28T13:42:35.058759#555-46472740]  INFO -- : Processing by JobsController#update as JSON
I, [2024-02-28T13:42:35.058817#555-46472740]  INFO -- :   Parameters: {"name"=>"Clone: Prio 2 Tickets nach 3 Wochen auf Prio 3 setzen", "object"=>"Ticket", "timeplan"=>{"days"=>{"Mon"=>true, "Tue"=>true, "Wed"=>true, "Thu"=>true, "Fri"=>true, "Sat"=>true, "Sun"=>true}, "hours"=>{"0"=>false, "1"=>false, "2"=>false, "3"=>false, "4"=>false, "5"=>false, "6"=>false, "7"=>false, "8"=>false, "9"=>false, "10"=>false, "11"=>false, "12"=>false, "13"=>false, "14"=>true, "15"=>false, "16"=>false, "17"=>false, "18"=>false, "19"=>false, "20"=>false, "21"=>false, "22"=>false, "23"=>false}, "minutes"=>{"0"=>false, "10"=>true, "20"=>false, "30"=>false, "40"=>false, "50"=>false}}, "condition"=>{"ticket.state_id"=>{"operator"=>"is", "value"=>["8", "1", "2"]}, "ticket.priority_id"=>{"operator"=>"is", "value"=>["2"]}, "ticket.updated_at"=>{"operator"=>"before (relative)", "value"=>"2", "range"=>"week"}, "ticket.owner_id"=>{"operator"=>"is", "pre_condition"=>"not_set", "value"=>[], "value_completion"=>""}, "ticket.group_id"=>{"operator"=>"is", "value"=>["2", "9"], "value_completion"=>""}}, "perform"=>{"article.note"=>{"body"=>"[FILTERED]", "internal"=>"true", "subject"=>"Priorität 2 -> 3"}, "ticket.priority_id"=>{"value"=>"3"}}, "disable_notification"=>false, "note"=>"Priorität nach 2 Wochen automatisch erhöht.", "active"=>true, "id"=>"31"}
I, [2024-02-28T13:42:35.061100#555-46251940]  INFO -- : Started GET "/api/v1/jobs?full=true&page=1&per_page=150&sort_by=name,%20id&order_by=ASC,%20ASC&_=1709101817083" for 172.17.90.43 at 2024-02-28 13:42:35 +0100
I, [2024-02-28T13:42:35.063915#555-46251940]  INFO -- : Processing by JobsController#index as JSON
I, [2024-02-28T13:42:35.063962#555-46251940]  INFO -- :   Parameters: {"full"=>"true", "page"=>"1", "per_page"=>"150", "sort_by"=>"name, id", "order_by"=>"ASC, ASC", "_"=>"1709101817083"}
I, [2024-02-28T13:42:35.105369#555-46251940]  INFO -- : Completed 200 OK in 41ms (Views: 4.7ms | ActiveRecord: 11.9ms | Allocations: 59964)
I, [2024-02-28T13:42:35.107843#555-46472740]  INFO -- : Completed 200 OK in 49ms (Views: 0.2ms | ActiveRecord: 9.0ms | Allocations: 68782)
I, [2024-02-28T13:42:35.117321#555-46426380]  INFO -- : Started GET "/api/v1/jobs?full=true&page=1&per_page=150&sort_by=name,%20id&order_by=ASC,%20ASC&_=1709101817084" for 172.17.90.43 at 2024-02-28 13:42:35 +0100
I, [2024-02-28T13:42:35.119917#555-46426380]  INFO -- : Processing by JobsController#index as JSON
I, [2024-02-28T13:42:35.119946#555-46426380]  INFO -- :   Parameters: {"full"=>"true", "page"=>"1", "per_page"=>"150", "sort_by"=>"name, id", "order_by"=>"ASC, ASC", "_"=>"1709101817084"}
I, [2024-02-28T13:42:35.153970#555-46426380]  INFO -- : Completed 200 OK in 34ms (Views: 7.2ms | ActiveRecord: 4.9ms | Allocations: 45362)
I, [2024-02-28T13:42:35.377635#555-46562540]  INFO -- : Started GET "/api/v1/jobs/?full=true&_=1709101817085" for 172.17.90.43 at 2024-02-28 13:42:35 +0100
I, [2024-02-28T13:42:35.380548#555-46562540]  INFO -- : Processing by JobsController#index as JSON
I, [2024-02-28T13:42:35.380572#555-46562540]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1709101817085"}
I, [2024-02-28T13:42:35.411234#555-46562540]  INFO -- : Completed 200 OK in 31ms (Views: 5.6ms | ActiveRecord: 5.5ms | Allocations: 44954)

For both automation exists tickets in the view. But mails nor priority is changed.

Hi @sven-ruess. Do you have another scheduler that is working fine, or are all affected?

Hi @fliebe92 all automations are affected. None is working at the moment.

Hi. What’s the output of systemctl status zammad-worker?

systemctl status zammad-worker
● zammad-worker.service
     Loaded: loaded (/etc/systemd/system/zammad-worker.service; enabled; preset>
     Active: active (running) since Thu 2024-02-22 06:48:02 CET; 2 weeks 0 days>
   Main PID: 562 (sleep)
      Tasks: 1 (limit: 23386)
     Memory: 168.0K
        CPU: 809us
     CGroup: /system.slice/zammad-worker.service
             └─562 /bin/sleep infinity

Feb 22 06:48:02 srvzammad01 systemd[1]: Started zammad-worker.servic>
lines 1-11/11 (END)...skipping...
● zammad-worker.service
     Loaded: loaded (/etc/systemd/system/zammad-worker.service; enabled; preset: enabled)
     Active: active (running) since Thu 2024-02-22 06:48:02 CET; 2 weeks 0 days ago
   Main PID: 562 (sleep)
      Tasks: 1 (limit: 23386)
     Memory: 168.0K
        CPU: 809us
     CGroup: /system.slice/zammad-worker.service
             └─562 /bin/sleep infinity

Feb 22 06:48:02 srvzammad01 systemd[1]: Started zammad-worker.service.

Output is really like this. That is not normal, or?

Could you please use the Railse Console and execute the following statement?

zammad run rails c and when the Rails Console is loaded, please do Scheduler.pluck(:last_run) and post the output here.

zammad run rails c
Loading production environment (Rails 7.0.8)
[1] pry(main)> Scheduler.pluck(:last_run)
=> [Thu, 18 Jan 2024 10:32:51.944000000 UTC +00:00,
 Mon, 12 Feb 2024 17:54:16.397000000 UTC +00:00,
 Thu, 15 Feb 2024 08:53:40.313000000 UTC +00:00,
 Thu, 07 Mar 2024 15:00:31.562000000 UTC +00:00,
 Thu, 07 Mar 2024 15:01:16.307000000 UTC +00:00,
 Wed, 06 Mar 2024 22:00:08.553000000 UTC +00:00,
 Wed, 06 Mar 2024 19:06:17.949000000 UTC +00:00,
 Wed, 06 Mar 2024 19:24:35.475000000 UTC +00:00,
 Wed, 06 Mar 2024 19:34:42.114000000 UTC +00:00,
 Wed, 06 Mar 2024 14:04:38.574000000 UTC +00:00,
 Fri, 01 Mar 2024 00:36:49.947000000 UTC +00:00,
 Thu, 07 Mar 2024 15:02:03.356000000 UTC +00:00,
 Sat, 02 Mar 2024 09:37:13.856000000 UTC +00:00,
 Wed, 06 Mar 2024 14:04:39.574000000 UTC +00:00,
 Thu, 07 Mar 2024 14:03:34.210000000 UTC +00:00,
 Thu, 07 Mar 2024 14:51:26.057000000 UTC +00:00,
 Thu, 07 Mar 2024 00:00:02.904000000 UTC +00:00,
 Fri, 09 Feb 2024 14:51:56.825000000 UTC +00:00,
 Thu, 07 Mar 2024 14:01:21.031000000 UTC +00:00,
 Wed, 06 Mar 2024 19:54:22.657000000 UTC +00:00,
 Wed, 06 Mar 2024 17:19:26.951000000 UTC +00:00,
 Thu, 07 Mar 2024 14:53:17.821000000 UTC +00:00,
 Wed, 06 Mar 2024 19:27:07.765000000 UTC +00:00,
 Thu, 07 Mar 2024 14:53:18.822000000 UTC +00:00,
 Wed, 06 Mar 2024 19:49:58.553000000 UTC +00:00,
 Thu, 07 Mar 2024 14:58:50.469000000 UTC +00:00,
 Wed, 28 Feb 2024 10:49:43.368000000 UTC +00:00,
 Tue, 05 Mar 2024 11:59:53.478000000 UTC +00:00,
 Thu, 07 Mar 2024 13:52:24.943000000 UTC +00:00]

Sorry for the delay. I hope, this information can help you.
Let me know, if you need further information and thank you for supporting me.

Hi @sven-ruess. Well, at least there are jobs that were handled, so it’s not completely broken. I still have no idea why your schedulers/triggers are not working. Maybe you could try to open them in the GUI, check them and save them again. Or create another one as a test one, affecting only 1–2 tickets, and play around with it.

Hi @fliebe92,

thank you for your response. That was my first idea. I have edited all automations and saved them. Nothing happend. I have edited them and added an additional execution. Nothing happend.

I have created a now automation to check, if that is working. No success.

My suggestion is now:

  • Can we increase log level for automations?
  • Can we get further information, which automations are executed?
  • Can we manually execute an automation and check, what will happen?
  • Does database provide further information about automations?

Otherwise:

  • Should I delete all automations and recreate them?
  • Should I make a new backup and restore it?
  • Could it be related to the change from HTTP to HTTPS?
  • Can it be related to OS change from CentOS to Debian?

At the moment there are 68 tickets, that should be processed by automations. If needed, you can get direct access to system and payment. The result should be, that it is working again.

Please let me know, what I can do for you, that you can find the reason, why automations stopped to work.

Thank you very much

Hi @sven-ruess. If you would like to have support by Zammad GmbH for your Zammad instance, please head over to The Best Helpdesk at the Best Prices | Zammad.

Right now, I need to think about your issue, it’s not that easy to figure out what’s going on there.

Hi @fliebe92,

Thank you very much for this information about paid services. At the moment we are looking only for one time support. All other issues could be solved by ourselves.

I had done a further debugging session and want to inform about those details:

  • I have upgrade to 6.2.0-1709902372.e5509ee8.bookworm
  • Zammad worker was running two times. Now it is running only once
  • postgresql 15 and 16 were installed. postgresql 16 was removed and 15 is used as before

Created a completely new automation. Automation is shown, that it will be triggered in 18 minutes.
With zammad run rails c and Scheduler.pluck(:last_run) I checked execution. There was an entry for this time. So I guess, that it was executed. I could not find an entry in production.log. After supposed execution, new trigger is not calculated. It should be executed after 10 minutes again.

Existing automations were all shown with an outdated trigger. This means for example, it should be startet 26.2.2024 at 10:30. But it was not executed or the trigger did not get updated.

Edited existing automations and added a new execution time point. In GUI all were show, that they should be executed in some minutes and the amount of affected tickets is updated. Waited and got some new entries in scheduler. No entries in production.log. Trigger is not updated to next planed schedule. Tickets are not worked on.

I hope with this information you can provide further steps for resolving it or I can dig you to the right way :wink:

I created a new backup and will play localy with it.

Best regards and thank you very much.

Hi @sven-ruess. I’m sorry, but I still have no clue to support you right now. Still thinking about it…

Hi @sven-ruess

Let me chime in quickly with two things here:

First of all, as per our documentation, our recommendation is to restore Zammad into the same version as the source installation. In your case, this means restoring your 6.1 backup from CentOS 7 into a freshly installed 6.1 on Debian 12. Only after this is done, upgrade Zammad to its latest stable (currently 6.2).
https://docs.zammad.org/en/latest/appendix/backup-and-restore/migrate-hosts.html

Secondly, Zammad’s naming scheme can be a bit confusing when it comes to schedulers. What is called “Scheduler” on the frontend (“Automatisierung” in German, which I’m assuming you’re using), is called Job on the rails backend.

So, whenever you’re entering commands like the one above (Scheduler.pluck(:last_run)), you’re querying a different part of Zammad’s code base than the one you’re actually interested in.

Try this command instead and post its output here. Maybe it will give us some more information on what is actually happening here:

Job.pluck(:id, :name, :active, :last_run_at)

There is however one (backend) Scheduler that could give us some information. Please post it in its entirety by pasting the output of the following command in here:

Scheduler.find_by(name: "Execute planned jobs.")

Hi @t-shehab,

thank you for for interrupting and putting me to the right direction.

I have verify with the old backup and the same version, that I run into the same issue.
So there is no difference if I restore the backup in the same version 6.1 or 6.2.
I have used the same backups. With the new backup I have the same situation locally in my VM.

I run the command you told:

Job.pluck(:id, :name, :active, :last_run_at)
[1] pry(main)> Job.pluck(:id, :name, :active, :last_run_at)
=> [[29, "Abholbereite Sachen - Erinnerungen losschicken", true, nil],
 [30, "Clone: Prio 1 Tickets nach 3 Wochen auf Prio 2 setzen", true, nil],
 [32, "Clone: Tickets mit Titelinhalt \"[zur Löschung markiert]\" löschen", true, nil],
 [34, "Test Automation", true, nil],
 [31, "Clone: Prio 2 Tickets nach 3 Wochen auf Prio 3 setzen", true, nil]]
Scheduler.find_by(name: "Execute planned jobs.")
[2] pry(main)> Scheduler.find_by(name: "Execute planned jobs.")
=> #<Scheduler:0x00007f47e8c7d378
id: 8,
name: "Execute planned jobs.",
method: "Job.run",
period: 300,
running: 0,
last_run: Fri, 09 Feb 2024 14:51:56.825000000 UTC +00:00,
prio: 2,
pid: "183180",
note: nil,
error_message: "Failed to run Job.run after 11 tries.",
status: "error",
active: false,
updated_by_id: 59,
created_by_id: 1,
created_at: Mon, 06 Apr 2020 08:16:30.015000000 UTC +00:00,
updated_at: Fri, 09 Feb 2024 14:51:56.842000000 UTC +00:00,
timeplan: {}>

With this information it is clear, that this has an error and is not working. I executed following commands to repair the situation:

zammad run rake db:migrate
zammad run rails r 'Scheduler.update_all(active: true)'
systemctl restart zammad

For verification:

[1] pry(main)> Scheduler.find_by(name: "Execute planned jobs.")
=> #<Scheduler:0x00007fd2fbb33a50
 id: 8,
 name: "Execute planned jobs.",
 method: "Job.run",
 period: 300,
 running: 0,
 last_run: Thu, 28 Mar 2024 11:17:25.284000000 UTC +00:00,
 prio: 2,
 pid: "599420",
 note: nil,
 error_message: "",
 status: "ok",
 active: true,
 updated_by_id: 59,
 created_by_id: 1,
 created_at: Mon, 06 Apr 2020 08:16:30.015000000 UTC +00:00,
 updated_at: Thu, 28 Mar 2024 11:17:25.285000000 UTC +00:00,
 timeplan: {}>

Now it is running regularly again and all tickets were successfully processed.

Thank you very much for your great support and this wonderful ticket system.

Best regards and special thanks from my customer
Sven

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