After upgrading from version 6.2 to version 6.4, tickets are sometimes not created via the “email” channel

Lex · January 29, 2025, 2:41pm

Infos:

Zammad 6.4.1-1737822837.0110da4a.jammy
Used Zammad installation type: package
Operating system: Ubunut 22.04.3 LTS
Browser + version: Firefox 122

Expected behavior:

when the mail is received, the ticket should be created

Actual behavior:

the ticket is not created every time, sometimes yes, sometimes no.

Steps to reproduce the behavior:

mail settings were not changed after the update, no settings were made at all. Before the update, requests were created adequately

at the bottom of the log, in this example the ticket was not created

Production.log

I [2025-01-29T23:33:49.470148#781-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:33:49.470682#781-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:33:59.470813#781-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:33:59.471609#781-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:33:59.471653#781-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:33:59.471667#781-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:33:59.471677#781-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:33:59.473054#781-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:34:01.319694#781-153600] INFO – : execute Ticket.process_escalation (try_count 0)…
I, [2025-01-29T23:34:01.648703#781-153600] INFO – : ended Ticket.process_escalation took: 0.336527295 seconds.
I, [2025-01-29T23:34:07.010217#781-142360] INFO – : execute Channel.fetch (try_count 0)…
I, [2025-01-29T23:34:07.010945#781-142360] INFO – : fetching imap (mail.1221.by/vs@1221.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:34:07.181413#781-142360] INFO – : - no message
I, [2025-01-29T23:34:07.186710#781-142360] INFO – : fetching imap (mail.1221.by/help@nalogirb.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:34:07.520355#781-142360] INFO – : - no message
I, [2025-01-29T23:34:07.525677#781-142360] INFO – : fetching imap (mail.1221.by/help@1221.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:34:07.599054#781-142360] INFO – : - no message
I, [2025-01-29T23:34:07.604531#781-142360] INFO – : ended Channel.fetch took: 0.601240643 seconds.
I, [2025-01-29T23:34:09.473203#781-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:34:09.474071#781-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:34:09.474103#781-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:34:09.474147#781-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:34:09.474194#781-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:34:09.481700#781-4235340] INFO – : execute SessionTimeoutJob.perform_now (try_count 0)…
I, [2025-01-29T23:34:09.490388#781-4235340] INFO – : SessionTimeoutJob removed session ‘534562’ for user id ‘’ (last ping: ‘2025-01-29T20:08:43Z’, timeout: ‘-1’)
I, [2025-01-29T23:34:09.492976#781-4235340] INFO – : SessionTimeoutJob removed session ‘534561’ for user id ‘’ (last ping: ‘2025-01-29T20:07:46Z’, timeout: ‘-1’)
I, [2025-01-29T23:34:09.516478#781-4235340] INFO – : ended SessionTimeoutJob.perform_now took: 0.04160424 seconds.
I, [2025-01-29T23:34:10.474932#781-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:34:20.475119#781-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:34:20.477372#781-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:34:20.477416#781-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:34:20.477462#781-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:34:20.477506#781-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:34:20.478989#781-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:34:30.479152#781-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:34:30.480031#781-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:34:30.484236#781-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:34:30.484299#781-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:34:30.484349#781-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:34:30.485062#781-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:34:37.612669#781-142360] INFO – : execute Channel.fetch (try_count 0)…
I, [2025-01-29T23:34:37.613439#781-142360] INFO – : fetching imap (mail.1221.by/vs@1221.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:34:37.705340#781-142360] INFO – : - no message
I, [2025-01-29T23:34:37.711514#781-142360] INFO – : fetching imap (mail.1221.by/help@nalogirb.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:34:37.781073#781-142360] INFO – : - message 1/1
I, [2025-01-29T23:34:37.815013#781-142360] INFO – : Process email with msgid ‘E1tdElH-003mq9-Eu@mail.1221.by’
I, [2025-01-29T23:34:37.826004#781-142360] INFO – : set_attributes_by_x_headers header x-zammad-ticket-customer_id found. Assign customer_id=15
I, [2025-01-29T23:34:37.839381#781-142360] INFO – : set_attributes_by_x_headers header x-zammad-article-preferences found. Assign preferences={“send-auto-response”=>true, “is-auto-response”=>false}
I, [2025-01-29T23:34:37.876240#781-142360] INFO – : Execute trigger (TICKET-AUTOOWNER/5) for this object (Ticket:11164/Loop:1)
I, [2025-01-29T23:34:37.886227#781-142360] INFO – : Do not execute recursive triggers per default until Zammad 3.0. With Zammad 3.0 and higher the following trigger is executed ‘TICKET-AUTOOWNER’ on Ticket:11164. Please review your current triggers and change them if needed.
I, [2025-01-29T23:34:37.971583#781-142360] INFO – : fetching imap (mail.1221.by/help@1221.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:34:38.045820#781-142360] INFO – : - no message
I, [2025-01-29T23:34:38.052067#781-142360] INFO – : ended Channel.fetch took: 0.447131515 seconds.
I, [2025-01-29T23:34:40.266515#781-142080] INFO – : 2025-01-29T23:34:40+0300: [Worker(host:helpdesk pid:781)] Job TransactionJob [e3ce94a0-a0e3-49d4-8362-d52ea5c8e76b] from DelayedJob(default) with arguments: [{“object”=>“Ticket”, “object_id”=>11164, “user_id”=>1, “created_at”=>{“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:34:37.879726429Z”}, “type”=>“update”, “changes”=>{“updated_by_id”=>[15, 1], “_aj_symbol_keys”=>}, “_aj_symbol_keys”=>[“object”, “object_id”, “user_id”, “created_at”, “type”, “changes”]}, {“interface_handle”=>“scheduler”, “disable”=>[“Transaction::Notification”], “type”=>“create”, “reset_user_id”=>true, “trigger_ids”=>{“11164”=>[5], “_aj_symbol_keys”=>}, “loop_count”=>1, “_aj_symbol_keys”=>[“interface_handle”, “disable”, “type”, “reset_user_id”, “trigger_ids”, “loop_count”]}] (id=1007665) (queue=default) RUNNING
I, [2025-01-29T23:34:40.278874#781-142080] INFO – : 2025-01-29T23:34:40+0300: [Worker(host:helpdesk pid:781)] Job TransactionJob [e3ce94a0-a0e3-49d4-8362-d52ea5c8e76b] from DelayedJob(default) with arguments: [{“object”=>“Ticket”, “object_id”=>11164, “user_id”=>1, “created_at”=>{“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:34:37.879726429Z”}, “type”=>“update”, “changes”=>{“updated_by_id”=>[15, 1], “_aj_symbol_keys”=>}, “_aj_symbol_keys”=>[“object”, “object_id”, “user_id”, “created_at”, “type”, “changes”]}, {“interface_handle”=>“scheduler”, “disable”=>[“Transaction::Notification”], “type”=>“create”, “reset_user_id”=>true, “trigger_ids”=>{“11164”=>[5], “_aj_symbol_keys”=>}, “loop_count”=>1, “_aj_symbol_keys”=>[“interface_handle”, “disable”, “type”, “reset_user_id”, “trigger_ids”, “loop_count”]}] (id=1007665) (queue=default) COMPLETED after 0.0123
I, [2025-01-29T23:34:40.283256#781-142080] INFO – : 2025-01-29T23:34:40+0300: [Worker(host:helpdesk pid:781)] Job TransactionJob [8ca9632f-b46a-47cd-bd3f-4285e20457f9] from DelayedJob(default) with arguments: [{“object”=>“Ticket”, “object_id”=>11164, “user_id”=>15, “created_at”=>{“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:34:37.852113501Z”}, “type”=>“create”, “changes”=>{“last_contact_at”=>[nil, {“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:34:37.840000000Z”}], “last_contact_customer_at”=>[nil, {“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:34:37.840000000Z”}], “_aj_symbol_keys”=>}, “article_id”=>32761, “article”=>{“_aj_globalid”=>“gid://zammad/Ticket::Article/32761”}, “_aj_symbol_keys”=>[“object”, “object_id”, “user_id”, “created_at”, “type”, “changes”, “article_id”, “article”]}, {“interface_handle”=>“scheduler”, “disable”=>, “_aj_symbol_keys”=>[“interface_handle”, “disable”]}] (id=1007666) (queue=default) RUNNING
I, [2025-01-29T23:34:40.485215#781-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:34:40.486032#781-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:34:40.486703#781-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:34:40.486750#781-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:34:40.486795#781-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:34:40.487292#781-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:34:41.094563#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job TransactionJob [8ca9632f-b46a-47cd-bd3f-4285e20457f9] from DelayedJob(default) with arguments: [{“object”=>“Ticket”, “object_id”=>11164, “user_id”=>15, “created_at”=>{“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:34:37.852113501Z”}, “type”=>“create”, “changes”=>{“last_contact_at”=>[nil, {“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:34:37.840000000Z”}], “last_contact_customer_at”=>[nil, {“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:34:37.840000000Z”}], “_aj_symbol_keys”=>}, “article_id”=>32761, “article”=>{“_aj_globalid”=>“gid://zammad/Ticket::Article/32761”}, “_aj_symbol_keys”=>[“object”, “object_id”, “user_id”, “created_at”, “type”, “changes”, “article_id”, “article”]}, {“interface_handle”=>“scheduler”, “disable”=>, “_aj_symbol_keys”=>[“interface_handle”, “disable”]}] (id=1007666) (queue=default) COMPLETED after 0.8113
I, [2025-01-29T23:34:41.096424#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job TicketUserTicketCounterJob [673b724f-079c-440a-b37f-7830784b8808] from DelayedJob(default) with arguments: [15, 15] (id=1007667) (queue=default) RUNNING
I, [2025-01-29T23:34:41.121545#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job TicketUserTicketCounterJob [673b724f-079c-440a-b37f-7830784b8808] from DelayedJob(default) with arguments: [15, 15] (id=1007667) (queue=default) COMPLETED after 0.0251
I, [2025-01-29T23:34:41.123351#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexJob [8a4c7bd7-e275-418e-8568-f254f6bd9401] from DelayedJob(default) with arguments: [“Ticket”, 11164] (id=1007668) (queue=default) RUNNING
I, [2025-01-29T23:34:41.167457#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexJob [8a4c7bd7-e275-418e-8568-f254f6bd9401] from DelayedJob(default) with arguments: [“Ticket”, 11164] (id=1007668) (queue=default) COMPLETED after 0.0441
I, [2025-01-29T23:34:41.170016#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexAssociationsJob [974456ae-8501-4842-8ac6-43a393ec64f8] from DelayedJob(default) with arguments: [“Ticket”, 11164] (id=1007669) (queue=default) RUNNING
I, [2025-01-29T23:34:41.220750#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexAssociationsJob [974456ae-8501-4842-8ac6-43a393ec64f8] from DelayedJob(default) with arguments: [“Ticket”, 11164] (id=1007669) (queue=default) COMPLETED after 0.0507
I, [2025-01-29T23:34:41.223269#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexJob [c11b992e-3285-4ba4-b774-4218656160f3] from DelayedJob(default) with arguments: [“User”, 15] (id=1007670) (queue=default) RUNNING
I, [2025-01-29T23:34:41.251969#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexJob [c11b992e-3285-4ba4-b774-4218656160f3] from DelayedJob(default) with arguments: [“User”, 15] (id=1007670) (queue=default) COMPLETED after 0.0287
I, [2025-01-29T23:34:41.253719#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexAssociationsJob [7d2439be-b154-491c-b937-ef62b9c16754] from DelayedJob(default) with arguments: [“User”, 15] (id=1007671) (queue=default) RUNNING
I, [2025-01-29T23:34:41.397837#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexAssociationsJob [7d2439be-b154-491c-b937-ef62b9c16754] from DelayedJob(default) with arguments: [“User”, 15] (id=1007671) (queue=default) COMPLETED after 0.1441
I, [2025-01-29T23:34:41.399585#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexJob [f0016c91-2253-4158-9446-72eb6828fe72] from DelayedJob(default) with arguments: [“Organization”, 5] (id=1007672) (queue=default) RUNNING
I, [2025-01-29T23:34:41.427050#781-142080] INFO – : 2025-01-29T23:34:41+0300: [Worker(host:helpdesk pid:781)] Job SearchIndexJob [f0016c91-2253-4158-9446-72eb6828fe72] from DelayedJob(default) with arguments: [“Organization”, 5] (id=1007672) (queue=default) COMPLETED after 0.0274
I, [2025-01-29T23:34:41.429133#781-142080] INFO – : 2025-01-29T23:34:41+0

rolfschmidt · January 29, 2025, 5:02pm

What does Admin → Monitoring say, are there maybe some unprocessable emails? I am not aware of any active mail handling issues atm.

Lex · January 29, 2025, 8:16pm

Zero problem.

also zero in
/opt/zammad/var/spool/unprocessable_mail

and i do

zammad run rails r ‘Channel::EmailParser.process_unprocessable_mails’

nothing …

Lex · January 29, 2025, 8:46pm

after deleting all incoming mails in the settings, the server still accesses the mail and deletes mails from it without creating a ticket.

Production

I, [2025-01-29T23:41:58.632063#772-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:41:58.632083#772-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:42:08.632806#772-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:42:08.641912#772-164080] INFO – : execute Ticket.process_pending (try_count 0)…
I, [2025-01-29T23:42:08.650294#772-164080] INFO – : ended Ticket.process_pending took: 0.016361067 seconds.
I, [2025-01-29T23:42:09.633820#772-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:42:09.633864#772-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:42:09.633917#772-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:42:09.633967#772-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:42:09.633981#772-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:42:19.636134#772-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:42:19.636927#772-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:42:19.637152#772-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:42:19.637181#772-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:42:19.637236#772-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:42:19.637273#772-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:42:20.251624#772-142360] INFO – : execute Channel.fetch (try_count 0)…
I, [2025-01-29T23:42:20.252264#772-142360] INFO – : fetching imap (mail.1221.by/vs@1221.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:42:20.420684#772-142360] INFO – : - no message
I, [2025-01-29T23:42:20.426207#772-142360] INFO – : fetching imap (mail.1221.by/help@nalogirb.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:42:20.555687#772-142360] INFO – : - no message
I, [2025-01-29T23:42:20.561334#772-142360] INFO – : fetching imap (mail.1221.by/help@1221.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:42:20.688058#772-142360] INFO – : - no message
I, [2025-01-29T23:42:20.693537#772-142360] INFO – : ended Channel.fetch took: 0.448860193 seconds.
I, [2025-01-29T23:42:29.637904#772-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:42:29.638829#772-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:42:29.638859#772-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: sleep
I, [2025-01-29T23:42:29.638899#772-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:42:29.638926#772-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:42:29.638967#772-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:42:39.640985#772-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:42:39.641864#772-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:42:39.641929#772-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: run
I, [2025-01-29T23:42:39.641986#772-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:42:39.642047#772-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:42:39.642111#772-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:42:49.642795#772-142100] INFO – : ProcessScheduledJobs running…
I, [2025-01-29T23:42:49.643672#772-142100] INFO – : Running job thread for ‘Check ‘Channel’ streams.’ (Channel.stream) status is: sleep
I, [2025-01-29T23:42:49.643735#772-142100] INFO – : Running job thread for ‘Generate ‘Session’ data.’ (Sessions.jobs) status is: run
I, [2025-01-29T23:42:49.643828#772-142100] INFO – : Running job thread for ‘Process ticket escalations.’ (Ticket.process_escalation) status is: sleep
I, [2025-01-29T23:42:49.643850#772-142100] INFO – : Running job thread for ‘Check channels.’ (Channel.fetch) status is: sleep
I, [2025-01-29T23:42:49.643885#772-142100] INFO – : Running job thread for ‘Execute planned jobs.’ (Job.run) status is: sleep
I, [2025-01-29T23:42:50.701711#772-142360] INFO – : execute Channel.fetch (try_count 0)…
I, [2025-01-29T23:42:50.702369#772-142360] INFO – : fetching imap (mail.1221.by/vs@1221.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:42:50.773790#772-142360] INFO – : - no message
I, [2025-01-29T23:42:50.779976#772-142360] INFO – : fetching imap (mail.1221.by/help@nalogirb.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:42:50.847732#772-142360] INFO – : - message 1/1
I, [2025-01-29T23:42:50.880856#772-142360] INFO – : Process email with msgid ‘E1tdEtB-003n9f-4R@mail.1221.by’
I, [2025-01-29T23:42:50.908053#772-142360] INFO – : set_attributes_by_x_headers header x-zammad-ticket-customer_id found. Assign customer_id=15
I, [2025-01-29T23:42:50.958174#772-142360] INFO – : set_attributes_by_x_headers header x-zammad-article-preferences found. Assign preferences={“send-auto-response”=>true, “is-auto-response”=>false}
I, [2025-01-29T23:42:51.041102#772-142360] INFO – : Execute trigger (TICKET-AUTOOWNER/5) for this object (Ticket:11165/Loop:1)
I, [2025-01-29T23:42:51.051807#772-142360] INFO – : Do not execute recursive triggers per default until Zammad 3.0. With Zammad 3.0 and higher the following trigger is executed ‘TICKET-AUTOOWNER’ on Ticket:11165. Please review your current triggers and change them if needed.
I, [2025-01-29T23:42:51.257930#772-142360] INFO – : fetching imap (mail.1221.by/help@1221.by port=993,ssl=true,starttls=false,folder=INBOX,keep_on_server=false,auth_type=LOGIN)
I, [2025-01-29T23:42:51.334804#772-142360] INFO – : - no message
I, [2025-01-29T23:42:51.340848#772-142360] INFO – : ended Channel.fetch took: 0.646917042 seconds.
I, [2025-01-29T23:42:53.657170#772-142080] INFO – : 2025-01-29T23:42:53+0300: [Worker(host:helpdesk pid:772)] Job TransactionJob [2d8610b7-6b79-4701-8abe-5ad26713383e] from DelayedJob(default) with arguments: [{“object”=>“Ticket”, “object_id”=>11165, “user_id”=>1, “created_at”=>{“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:42:51.044953419Z”}, “type”=>“update”, “changes”=>{“updated_by_id”=>[15, 1], “_aj_symbol_keys”=>}, “_aj_symbol_keys”=>[“object”, “object_id”, “user_id”, “created_at”, “type”, “changes”]}, {“interface_handle”=>“scheduler”, “disable”=>[“Transaction::Notification”], “type”=>“create”, “reset_user_id”=>true, “trigger_ids”=>{“11165”=>[5], “_aj_symbol_keys”=>}, “loop_count”=>1, “_aj_symbol_keys”=>[“interface_handle”, “disable”, “type”, “reset_user_id”, “trigger_ids”, “loop_count”]}] (id=1007710) (queue=default) RUNNING
I, [2025-01-29T23:42:53.667266#772-142080] INFO – : 2025-01-29T23:42:53+0300: [Worker(host:helpdesk pid:772)] Job TransactionJob [2d8610b7-6b79-4701-8abe-5ad26713383e] from DelayedJob(default) with arguments: [{“object”=>“Ticket”, “object_id”=>11165, “user_id”=>1, “created_at”=>{“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:42:51.044953419Z”}, “type”=>“update”, “changes”=>{“updated_by_id”=>[15, 1], “_aj_symbol_keys”=>}, “_aj_symbol_keys”=>[“object”, “object_id”, “user_id”, “created_at”, “type”, “changes”]}, {“interface_handle”=>“scheduler”, “disable”=>[“Transaction::Notification”], “type”=>“create”, “reset_user_id”=>true, “trigger_ids”=>{“11165”=>[5], “_aj_symbol_keys”=>}, “loop_count”=>1, “_aj_symbol_keys”=>[“interface_handle”, “disable”, “type”, “reset_user_id”, “trigger_ids”, “loop_count”]}] (id=1007710) (queue=default) COMPLETED after 0.0100
I, [2025-01-29T23:42:53.669182#772-142080] INFO – : 2025-01-29T23:42:53+0300: [Worker(host:helpdesk pid:772)] Job TransactionJob [50b4f3b9-acbc-44ff-9026-397285f42766] from DelayedJob(default) with arguments: [{“object”=>“Ticket”, “object_id”=>11165, “user_id”=>15, “created_at”=>{“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:42:50.985511310Z”}, “type”=>“create”, “changes”=>{“last_contact_at”=>[nil, {“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:42:50.959000000Z”}], “last_contact_customer_at”=>[nil, {“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:42:50.959000000Z”}], “_aj_symbol_keys”=>}, “article_id”=>32762, “article”=>{“_aj_globalid”=>“gid://zammad/Ticket::Article/32762”}, “_aj_symbol_keys”=>[“object”, “object_id”, “user_id”, “created_at”, “type”, “changes”, “article_id”, “article”]}, {“interface_handle”=>“scheduler”, “disable”=>, “_aj_symbol_keys”=>[“interface_handle”, “disable”]}] (id=1007711) (queue=default) RUNNING
I, [2025-01-29T23:42:54.507392#772-142080] INFO – : 2025-01-29T23:42:54+0300: [Worker(host:helpdesk pid:772)] Job TransactionJob [50b4f3b9-acbc-44ff-9026-397285f42766] from DelayedJob(default) with arguments: [{“object”=>“Ticket”, “object_id”=>11165, “user_id”=>15, “created_at”=>{“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:42:50.985511310Z”}, “type”=>“create”, “changes”=>{“last_contact_at”=>[nil, {“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:42:50.959000000Z”}], “last_contact_customer_at”=>[nil, {“_aj_serialized”=>“ActiveJob::Serializers::TimeWithZoneSerializer”, “value”=>“2025-01-29T20:42:50.959000000Z”}], “_aj_symbol_keys”=>}, “article_id”=>32762, “article”=>{“_aj_globalid”=>“gid://zammad/Ticket::Article/32762”}, “_aj_symbol_keys”=>[“object”, “object_id”, “user_id”, “created_at”, “type”, “changes”, “article_id”, “article”]}, {“interface_handle”=>“scheduler”, “disable”=>, “_aj_symbol_keys”=>[“interface_handle”, “disable”]}] (id=1007711) (queue=default) COMPLETED after 0.8382
I, [2025-01-29T23:42:54.509700#772-142080] INFO – : 2025-01-29T23:42:54+0300: [Worker(host:helpdesk pid:772)] Job TicketUserTicketCounterJob [84bda1f1-29ca-4962-8139-75ae6ca2ff7c] from DelayedJob(default) with arguments: [15, 15] (id=1007712) (queue=default) RUNNING
I, [2025-01-29T23:42:54.556378#772-142080] INFO – : 2025-01-29T23:42:54+0300: [Worker(host:helpdesk pid:772)] Job TicketUserTicketCounterJob [84bda1f1-29ca-4962-8139-75ae6ca2ff7c] from DelayedJob(default) with arguments: [15, 15] (id=1007712) (queue=default) COMPLETED after 0.0466
I, [2025-01-29T23:42:54.558523#772-142080] INFO – : 2025-01-29T23:42:54+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexJob [f8b915c1-ca12-417c-976a-233437653823] from DelayedJob(default) with arguments: [“Ticket”, 11165] (id=1007713) (queue=default) RUNNING
I, [2025-01-29T23:42:55.093530#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexJob [f8b915c1-ca12-417c-976a-233437653823] from DelayedJob(default) with arguments: [“Ticket”, 11165] (id=1007713) (queue=default) COMPLETED after 0.5348
I, [2025-01-29T23:42:55.095406#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexAssociationsJob [3129ed6e-2eed-4493-97aa-6ced077b21d9] from DelayedJob(default) with arguments: [“Ticket”, 11165] (id=1007714) (queue=default) RUNNING
I, [2025-01-29T23:42:55.264581#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexAssociationsJob [3129ed6e-2eed-4493-97aa-6ced077b21d9] from DelayedJob(default) with arguments: [“Ticket”, 11165] (id=1007714) (queue=default) COMPLETED after 0.1691
I, [2025-01-29T23:42:55.266874#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexJob [08aee921-49d3-4971-b84a-eb431af26aee] from DelayedJob(default) with arguments: [“User”, 15] (id=1007715) (queue=default) RUNNING
I, [2025-01-29T23:42:55.303626#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexJob [08aee921-49d3-4971-b84a-eb431af26aee] from DelayedJob(default) with arguments: [“User”, 15] (id=1007715) (queue=default) COMPLETED after 0.0367
I, [2025-01-29T23:42:55.305863#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexAssociationsJob [4dcc8f65-c4d2-40a0-a414-34cc1d16d25b] from DelayedJob(default) with arguments: [“User”, 15] (id=1007716) (queue=default) RUNNING
I, [2025-01-29T23:42:55.436132#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexAssociationsJob [4dcc8f65-c4d2-40a0-a414-34cc1d16d25b] from DelayedJob(default) with arguments: [“User”, 15] (id=1007716) (queue=default) COMPLETED after 0.1302
I, [2025-01-29T23:42:55.439105#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexJob [8f54bb04-d389-468a-a010-e6abcb78d107] from DelayedJob(default) with arguments: [“Organization”, 5] (id=1007717) (queue=default) RUNNING
I, [2025-01-29T23:42:55.492144#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexJob [8f54bb04-d389-468a-a010-e6abcb78d107] from DelayedJob(default) with arguments: [“Organization”, 5] (id=1007717) (queue=default) COMPLETED after 0.0530
I, [2025-01-29T23:42:55.494609#772-142080] INFO – : 2025-01-29T23:42:55+0300: [Worker(host:helpdesk pid:772)] Job SearchIndexAssociationsJob [7945c311-047c-473d-a859-dd3b991dd7ca] from DelayedJob(default) with arguments: [“Organization”, 5] (id=1007718) (queue=default) RUNNING

Lex · January 29, 2025, 8:49pm

Found the cause.

Possibly restarting the Zammad service is good enough already.
Your logfile and description do not fit.

Your production log shows a running scheduler and functioning fetch process.
If mails are vanshing from your mailbox but not appearing on your Zammad instance ensure the following:

!!!* no other Zammad instance fetching mail from the same mailbox!!!

you having enough permissions to see the group the ticket may be directed to

MrGeneration Thank you

MrGeneration · January 29, 2025, 9:26pm

Just for reference. The two commands you posted regarding unprocessable mails are outdated since a year or so.

See Other Useful Commands — Zammad System Documentation documentation

system · February 5, 2025, 9:27pm

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