"Visibility is public" trigger condition not working

niddu85 · December 20, 2019, 11:17am

Used Zammad version: 3.2
Used Zammad installation source: package
Operating system: debian 9
Browser + version: Chrome 79.0.3945.88

Expected behavior:

When using condition “Visibility is public” and agent publishes an internal note, trigger should not start.

this is the trigger configuration:

Actual behavior:

trigger starts and send email to customer with the text of the internal note

Steps to reproduce the behavior:

create a trigger as shown
add a private note to an existing ticket

MrGeneration · December 20, 2019, 5:54pm

Sorry your trigger looks totally fine, I cannot reproduce this.
I guess your agent is just posting a public note and then changing it to internal.

niddu85 · December 20, 2019, 8:53pm

Absolutely sure, I am doing it in behalf of the agent

MrGeneration · December 21, 2019, 6:00pm

Please also provide both affected triggers.

niddu85 · December 22, 2019, 4:00pm

thanks for your reply.
That’s the trigger for private notes:

And that’s the trigger for the public posts (i removed the text from the email body from the previous version in order to avoid customer receive the private note text):

MrGeneration · December 24, 2019, 11:21am

Sorry but I can’t reproduce your issue.
Both triggers behave as expected (and configured).

You may want to take a look into the tickets history, you might find the following entries (one of them).

If not, sometihng else is wrong with your Zammad.
Ensure that you’re using a vanilla installation without any custom changes to the code.

If you changes any settings that are not default please state so as well.

niddu85 · December 28, 2019, 7:09pm

Glad to see it was not easy as expected
Here is the history of a just published private note. Nothing like the one you mentioned.

I’m not sure on what kind of install is it unfortunatelly, but i’m pretty sure no code was changed.
What could i try? make a clean install and restore a backup?

MrGeneration · December 31, 2019, 7:19am

Personally I think that’s a bit overkill.
You could try to reproduce this issue on a hosted setup (that brings the benifit you don’t have to handle backups or handle reinstallation(s)). (see: Free 30-Days Trial | Get Zammad )

If the exact same trigger combination brings the same issue, then we’re a step further to the issue. If not, it has to be about your local environment. In this case we need to know all manual changes if any have been made.

As you implied that you don’t have any manual changes on source code and are running a normal package installation, usually updating your installation would be enough. (in case an update is available).

Updates to overwrite all manual code changes. I currently suspect that your issue won’t be gone, but it might be worth a try.

niddu85 · January 7, 2020, 8:32am

Thanks for your reply.
Currently i updated Zammad to the latest version just before opening this ticket in order to try if the update was able to fix it, but with no luck. Currently I’m at the latest version (Zammad version 3.2.x)

The only part which is quite old on my install is ElasticSearch but i don’t think this would be a problem.
I’m running version 5.6.16

I’m trying on the hosted setup and let you know. In the meantime i restored on a VM a backup on a fresh install of Zammad with the latest elasticsearch but i got issue logging in with error “CSRF token verification failed”. Could you help me with this?

niddu85 · January 7, 2020, 10:42am

I’ve set up the environment on the hosted solution, but it works good

niddu85 · January 8, 2020, 8:38am

I was also able to restore a backup copy on a fresh install with latest zammad and elasticsearch and solved the “CSRF” problem but the behavior is the same: private notes triggers also “public” triggers.

Maybe my backup could help you understand the problem?

niddu85 · January 8, 2020, 3:52pm

if this may help you somehow, this is the production.log when i push “update” on a private note added. see the 2 triggers are executed

I, [2020-01-08T16:38:42.151325 #505-47203788704140]  INFO -- : # curl -X post "http://127.0.0.1:9200/zammad_production_user/_doc/32?pipeline=zammad766575370641"
I, [2020-01-08T16:38:42.184284 #505-47203788704140]  INFO -- : # 200
I, [2020-01-08T16:38:42.195612 #505-47203788704140]  INFO -- : Performed SearchIndexJob (Job ID: 51310c12-b7ac-4770-830c-7f758d18617c) from DelayedJob(default) in 205.21ms
I, [2020-01-08T16:38:42.199985 #505-47203788704140]  INFO -- : 2020-01-08T16:38:42+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [51310c12-b7ac-4770-830c-7f758d18617c] from DelayedJob(default) with arguments: ["User", 32] (id=5312064) (queue=default) COMPLETED after 0.2711
I, [2020-01-08T16:38:42.204057 #505-47203788704140]  INFO -- : 2020-01-08T16:38:42+0100: [Worker(host:zammad2 pid:505)] Job UserDeviceLogJob [e91ee087-5035-4fd9-9ecc-090b154ec6f7] from DelayedJob(default) with arguments: ["Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.88 Safari/537.36", "10.0.0.50", 46, "-286852297", "session"] (id=5312065) (queue=default) RUNNING
I, [2020-01-08T16:38:42.230801 #505-47203788704140]  INFO -- : Performing UserDeviceLogJob (Job ID: e91ee087-5035-4fd9-9ecc-090b154ec6f7) from DelayedJob(default) with arguments: "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.88 Safari/537.36", "10.0.0.50", 46, "-286852297", "session"
I, [2020-01-08T16:38:42.287646 #505-47203788704140]  INFO -- : Performed UserDeviceLogJob (Job ID: e91ee087-5035-4fd9-9ecc-090b154ec6f7) from DelayedJob(default) in 56.39ms
I, [2020-01-08T16:38:42.291350 #505-47203788704140]  INFO -- : 2020-01-08T16:38:42+0100: [Worker(host:zammad2 pid:505)] Job UserDeviceLogJob [e91ee087-5035-4fd9-9ecc-090b154ec6f7] from DelayedJob(default) with arguments: ["Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.88 Safari/537.36", "10.0.0.50", 46, "-286852297", "session"] (id=5312065) (queue=default) COMPLETED after 0.0872
I, [2020-01-08T16:38:42.300138 #505-47203788704140]  INFO -- : 2020-01-08T16:38:42+0100: [Worker(host:zammad2 pid:505)] Job Transaction::BackgroundJob (id=5312066) RUNNING
I, [2020-01-08T16:38:42.520259 #505-47203788704140]  INFO -- : 2020-01-08T16:38:42+0100: [Worker(host:zammad2 pid:505)] Job Transaction::BackgroundJob (id=5312066) COMPLETED after 0.2200
I, [2020-01-08T16:38:53.110792 #501-47351719558660]  INFO -- : Started PUT "/api/v1/tickets/566?all=true" for 10.0.0.50 at 2020-01-08 16:38:53 +0100
I, [2020-01-08T16:38:54.096791 #501-47351719558660]  INFO -- : Processing by TicketsController#update as JSON
I, [2020-01-08T16:38:54.106915 #501-47351719558660]  INFO -- :   Parameters: {"number"=>"64566", "title"=>"devo aprire un ticket", "group_id"=>"1", "owner_id"=>1, "customer_id"=>163, "state_id"=>"4", "priority_id"=>"2", "article"=>{"from"=>"niddu", "to"=>"", "cc"=>"", "subject"=>"", "body"=>"[FILTERED]", "content_type"=>"text/html", "ticket_id"=>566, "type_id"=>10, "sender_id"=>1, "internal"=>true, "in_reply_to"=>"", "form_id"=>"495768724", "subtype"=>""}, "updated_at"=>"2020-01-08T15:02:27.981Z", "preferences"=>{}, "pending_time"=>nil, "product"=>"Generic", "type"=>nil, "unitcode"=>"", "id"=>"566", "all"=>"true"}
I, [2020-01-08T16:38:54.933103 #505-47203774099560]  INFO -- : execute Channel.fetch (try_count 0)...
I, [2020-01-08T16:38:54.952866 #505-47203774099560]  INFO -- : fetching imap (domain.com/support@domain.com port=143,ssl=false,starttls=false,folder=INBOX,keep_on_server=true)
I, [2020-01-08T16:38:55.180471 #505-47203774099560]  INFO -- :  - no message
I, [2020-01-08T16:38:55.180586 #505-47203774099560]  INFO -- : done
I, [2020-01-08T16:38:55.202642 #505-47203774099560]  INFO -- : ended Channel.fetch took: 0.340191224 seconds.
I, [2020-01-08T16:38:55.505931 #501-47351719558660]  INFO -- : Enqueued SearchIndexJob (Job ID: 19f09ca5-6d2b-444f-bbb9-031480e4e395) to DelayedJob(default) with arguments: "Ticket", 566
I, [2020-01-08T16:38:55.591012 #501-47351719558660]  INFO -- : Enqueued SearchIndexJob (Job ID: 68d6e981-9e0a-4fd0-a385-18053950bfbe) to DelayedJob(default) with arguments: "User", 163
I, [2020-01-08T16:38:55.642992 #501-47351719558660]  INFO -- : Enqueued SearchIndexJob (Job ID: 80ec1528-2f24-4a67-8292-f4d5619d446f) to DelayedJob(default) with arguments: "Organization", 16
I, [2020-01-08T16:38:56.784463 #501-47351719558660]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 6fff31c2-4337-401f-bdec-d12940618b71) because of already existing job with lock key 'SearchIndexJob/Ticket/566'.
I, [2020-01-08T16:38:56.784813 #501-47351719558660]  INFO -- : Enqueued SearchIndexJob (Job ID: 6fff31c2-4337-401f-bdec-d12940618b71) to DelayedJob(default) with arguments: "Ticket", 566
I, [2020-01-08T16:38:56.837554 #501-47351719558660]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 9976b810-f1c3-4abc-8069-b9e3b6c3687e) because of already existing job with lock key 'SearchIndexJob/User/163'.
I, [2020-01-08T16:38:56.837790 #501-47351719558660]  INFO -- : Enqueued SearchIndexJob (Job ID: 9976b810-f1c3-4abc-8069-b9e3b6c3687e) to DelayedJob(default) with arguments: "User", 163
I, [2020-01-08T16:38:56.867976 #501-47351719558660]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 1872ed10-abb5-4364-8f36-593f4e4c1a55) because of already existing job with lock key 'SearchIndexJob/Organization/16'.
I, [2020-01-08T16:38:56.868170 #501-47351719558660]  INFO -- : Enqueued SearchIndexJob (Job ID: 1872ed10-abb5-4364-8f36-593f4e4c1a55) to DelayedJob(default) with arguments: "Organization", 16
I, [2020-01-08T16:38:57.642978 #501-47351719558660]  INFO -- : Enqueued TicketUserTicketCounterJob (Job ID: c6d81b45-ea3e-4e5c-9ac9-c3c0419f9e0f) to DelayedJob(default) with arguments: 163, 46
I, [2020-01-08T16:38:58.593510 #505-47203788704140]  INFO -- : 2020-01-08T16:38:58+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [19f09ca5-6d2b-444f-bbb9-031480e4e395] from DelayedJob(default) with arguments: ["Ticket", 566] (id=5312067) (queue=default) RUNNING
I, [2020-01-08T16:38:58.733622 #505-47203788704140]  INFO -- : Performing SearchIndexJob (Job ID: 19f09ca5-6d2b-444f-bbb9-031480e4e395) from DelayedJob(default) with arguments: "Ticket", 566
I, [2020-01-08T16:38:59.571306 #505-47203706930620]  INFO -- : Scheduler running...
I, [2020-01-08T16:38:59.774657 #505-47203706930620]  INFO -- : Running job thread for 'Import OTRS diff load' (Import::OTRS.diff_worker) status is: sleep
I, [2020-01-08T16:38:59.776115 #505-47203706930620]  INFO -- : Running job thread for 'Process escalation tickets' (Ticket.process_escalation) status is: sleep
I, [2020-01-08T16:38:59.784580 #505-47203706930620]  INFO -- : Running job thread for 'Check Channels' (Channel.fetch) status is: sleep
I, [2020-01-08T16:38:59.785002 #505-47203706930620]  INFO -- : Running job thread for 'Check streams for Channel' (Channel.stream) status is: sleep
I, [2020-01-08T16:38:59.786959 #505-47203706930620]  INFO -- : Running job thread for 'Generate Session data' (Sessions.jobs) status is: sleep
I, [2020-01-08T16:38:59.788935 #505-47203706930620]  INFO -- : Running job thread for 'Execute jobs' (Job.run) status is: sleep
I, [2020-01-08T16:38:59.846671 #505-47203788704140]  INFO -- : # curl -X post "http://127.0.0.1:9200/zammad_production_ticket/_doc/566?pipeline=zammad766575370641"
I, [2020-01-08T16:39:02.334234 #505-47203788704140]  INFO -- : # 200
I, [2020-01-08T16:39:02.363533 #505-47203788704140]  INFO -- : Performed SearchIndexJob (Job ID: 19f09ca5-6d2b-444f-bbb9-031480e4e395) from DelayedJob(default) in 3627.95ms
I, [2020-01-08T16:39:02.367918 #505-47203788704140]  INFO -- : 2020-01-08T16:39:02+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [19f09ca5-6d2b-444f-bbb9-031480e4e395] from DelayedJob(default) with arguments: ["Ticket", 566] (id=5312067) (queue=default) COMPLETED after 3.7736
I, [2020-01-08T16:39:02.375140 #505-47203788704140]  INFO -- : 2020-01-08T16:39:02+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [68d6e981-9e0a-4fd0-a385-18053950bfbe] from DelayedJob(default) with arguments: ["User", 163] (id=5312068) (queue=default) RUNNING
I, [2020-01-08T16:39:02.428367 #505-47203788704140]  INFO -- : Performing SearchIndexJob (Job ID: 68d6e981-9e0a-4fd0-a385-18053950bfbe) from DelayedJob(default) with arguments: "User", 163
I, [2020-01-08T16:39:02.482471 #505-47203788704140]  INFO -- : # curl -X post "http://127.0.0.1:9200/zammad_production_user/_doc/163?pipeline=zammad766575370641"
I, [2020-01-08T16:39:02.627803 #505-47203788704140]  INFO -- : # 200
I, [2020-01-08T16:39:02.637967 #505-47203788704140]  INFO -- : Performed SearchIndexJob (Job ID: 68d6e981-9e0a-4fd0-a385-18053950bfbe) from DelayedJob(default) in 209.43ms
I, [2020-01-08T16:39:02.641979 #505-47203788704140]  INFO -- : 2020-01-08T16:39:02+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [68d6e981-9e0a-4fd0-a385-18053950bfbe] from DelayedJob(default) with arguments: ["User", 163] (id=5312068) (queue=default) COMPLETED after 0.2667
I, [2020-01-08T16:39:02.646383 #505-47203788704140]  INFO -- : 2020-01-08T16:39:02+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [80ec1528-2f24-4a67-8292-f4d5619d446f] from DelayedJob(default) with arguments: ["Organization", 16] (id=5312069) (queue=default) RUNNING
I, [2020-01-08T16:39:02.677942 #501-47351719558660]  INFO -- : Execute trigger (Send notifications to agents on private update/9) for this object (Ticket:566/Loop:1)
I, [2020-01-08T16:39:02.719648 #505-47203788704140]  INFO -- : Performing SearchIndexJob (Job ID: 80ec1528-2f24-4a67-8292-f4d5619d446f) from DelayedJob(default) with arguments: "Organization", 16
I, [2020-01-08T16:39:02.745950 #505-47203788704140]  INFO -- : # curl -X post "http://127.0.0.1:9200/zammad_production_organization/_doc/16?pipeline=zammad766575370641"
I, [2020-01-08T16:39:02.887973 #505-47203788704140]  INFO -- : # 200
I, [2020-01-08T16:39:02.897232 #505-47203788704140]  INFO -- : Performed SearchIndexJob (Job ID: 80ec1528-2f24-4a67-8292-f4d5619d446f) from DelayedJob(default) in 177.41ms
I, [2020-01-08T16:39:02.900887 #505-47203788704140]  INFO -- : 2020-01-08T16:39:02+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [80ec1528-2f24-4a67-8292-f4d5619d446f] from DelayedJob(default) with arguments: ["Organization", 16] (id=5312069) (queue=default) COMPLETED after 0.2543
I, [2020-01-08T16:39:02.905216 #505-47203788704140]  INFO -- : 2020-01-08T16:39:02+0100: [Worker(host:zammad2 pid:505)] Job TicketUserTicketCounterJob [c6d81b45-ea3e-4e5c-9ac9-c3c0419f9e0f] from DelayedJob(default) with arguments: [163, 46] (id=5312070) (queue=default) RUNNING
I, [2020-01-08T16:39:02.999733 #505-47203788704140]  INFO -- : Performing TicketUserTicketCounterJob (Job ID: c6d81b45-ea3e-4e5c-9ac9-c3c0419f9e0f) from DelayedJob(default) with arguments: 163, 46
I, [2020-01-08T16:39:03.056288 #505-47203788704140]  INFO -- : Performed TicketUserTicketCounterJob (Job ID: c6d81b45-ea3e-4e5c-9ac9-c3c0419f9e0f) from DelayedJob(default) in 56.39ms
I, [2020-01-08T16:39:03.060305 #505-47203788704140]  INFO -- : 2020-01-08T16:39:03+0100: [Worker(host:zammad2 pid:505)] Job TicketUserTicketCounterJob [c6d81b45-ea3e-4e5c-9ac9-c3c0419f9e0f] from DelayedJob(default) with arguments: [163, 46] (id=5312070) (queue=default) COMPLETED after 0.1549
I, [2020-01-08T16:39:04.445892 #501-47351719558660]  INFO -- : Enqueued SearchIndexJob (Job ID: 871ac29e-f68b-4b46-b4c8-5365da5dc638) to DelayedJob(default) with arguments: "Ticket", 566
I, [2020-01-08T16:39:09.282347 #501-47351719558660]  INFO -- : Enqueued TicketArticleCommunicateEmailJob (Job ID: 118e8e44-cd12-4133-8e71-9aebc909664c) to DelayedJob(default) with arguments: 3462
I, [2020-01-08T16:39:09.307771 #501-47351719558660]  INFO -- : Execute trigger (Send notification to ticket owner on public update/7) for this object (Ticket:566/Loop:2)
I, [2020-01-08T16:39:09.655234 #501-47351719558660]  INFO -- : Won't enqueue SearchIndexJob (Job ID: 0dfee2b0-1c8c-4360-854c-20557f00d8c1) because of already existing job with lock key 'SearchIndexJob/Ticket/566'.
I, [2020-01-08T16:39:09.656197 #501-47351719558660]  INFO -- : Enqueued SearchIndexJob (Job ID: 0dfee2b0-1c8c-4360-854c-20557f00d8c1) to DelayedJob(default) with arguments: "Ticket", 566
I, [2020-01-08T16:39:09.661455 #501-47351719558660]  INFO -- : Enqueued TicketArticleCommunicateEmailJob (Job ID: cff0091f-e8fb-49f2-8a0b-8efc56928eac) to DelayedJob(default) with arguments: 3463
I, [2020-01-08T16:39:09.677859 #501-47351719558660]  INFO -- : Skip trigger (Send notification to ticket owner on public update/7) because was already executed for this object (Ticket:566/Loop:3)
I, [2020-01-08T16:39:09.722071 #501-47351719558660]  INFO -- : Enqueued TicketUserTicketCounterJob (Job ID: 7e1719f4-4a47-4e14-8864-18302c3d6165) to DelayedJob(default) with arguments: 163, 46
I, [2020-01-08T16:39:09.741257 #501-47351719558660]  INFO -- : Completed 200 OK in 15632ms (Views: 155.0ms | ActiveRecord: 1122.6ms)
I, [2020-01-08T16:39:09.837854 #501-47351719517300]  INFO -- : Started GET "/api/v1/ticket_customer?customer_id=163&_=1578497833351" for 10.0.0.50 at 2020-01-08 16:39:09 +0100
I, [2020-01-08T16:39:09.855382 #501-47351719517300]  INFO -- : Processing by TicketsController#ticket_customer as JSON
I, [2020-01-08T16:39:09.855489 #501-47351719517300]  INFO -- :   Parameters: {"customer_id"=>"163", "_"=>"1578497833351"}
I, [2020-01-08T16:39:09.895442 #501-47351702636440]  INFO -- : Started DELETE "/api/v1/upload_caches/498044318" for 10.0.0.50 at 2020-01-08 16:39:09 +0100
I, [2020-01-08T16:39:09.961502 #501-47351719517300]  INFO -- : Completed 200 OK in 106ms (Views: 20.5ms | ActiveRecord: 6.4ms)
I, [2020-01-08T16:39:10.016994 #501-47351702636440]  INFO -- : Processing by UploadCachesController#destroy as JSON
I, [2020-01-08T16:39:10.017113 #501-47351702636440]  INFO -- :   Parameters: {"id"=>"498044318"}
I, [2020-01-08T16:39:10.078032 #501-47351702636440]  INFO -- : Completed 200 OK in 61ms (Views: 0.6ms | ActiveRecord: 50.6ms)
I, [2020-01-08T16:39:11.064152 #501-47351719517900]  INFO -- : Started GET "/api/v1/tickets/566?all=true&_=1578497833352" for 10.0.0.50 at 2020-01-08 16:39:11 +0100
I, [2020-01-08T16:39:11.074163 #501-47351719517900]  INFO -- : Processing by TicketsController#show as JSON
I, [2020-01-08T16:39:11.074259 #501-47351719517900]  INFO -- :   Parameters: {"all"=>"true", "_"=>"1578497833352", "id"=>"566"}
I, [2020-01-08T16:39:11.082221 #505-47203788704140]  INFO -- : 2020-01-08T16:39:11+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [871ac29e-f68b-4b46-b4c8-5365da5dc638] from DelayedJob(default) with arguments: ["Ticket", 566] (id=5312071) (queue=default) RUNNING
I, [2020-01-08T16:39:11.291563 #505-47203788704140]  INFO -- : Performing SearchIndexJob (Job ID: 871ac29e-f68b-4b46-b4c8-5365da5dc638) from DelayedJob(default) with arguments: "Ticket", 566
I, [2020-01-08T16:39:11.509107 #501-47351719517900]  INFO -- : Completed 200 OK in 435ms (Views: 28.0ms | ActiveRecord: 129.4ms)
I, [2020-01-08T16:39:11.955198 #501-47351719517020]  INFO -- : Started PUT "/api/v1/taskbar/1922" for 10.0.0.50 at 2020-01-08 16:39:11 +0100
I, [2020-01-08T16:39:11.969912 #501-47351719517020]  INFO -- : Processing by TaskbarController#update as JSON
I, [2020-01-08T16:39:11.970219 #501-47351719517020]  INFO -- :   Parameters: {"key"=>"Ticket-566", "client_id"=>"123", "callback"=>"TicketZoom", "state"=>{"ticket"=>{}, "article"=>{"form_id"=>"498044318"}}, "params"=>{"ticket_id"=>566, "overview_id"=>10, "init"=>true}, "prio"=>3, "notify"=>false, "active"=>true, "attachments"=>[], "updated_at"=>"2020-01-08T15:02:30.445Z", "id"=>"1922"}
I, [2020-01-08T16:39:12.132171 #501-47351719517020]  INFO -- : Completed 200 OK in 162ms (Views: 0.6ms | ActiveRecord: 55.4ms)
I, [2020-01-08T16:39:12.557357 #505-47203788704140]  INFO -- : # curl -X post "http://127.0.0.1:9200/zammad_production_ticket/_doc/566?pipeline=zammad766575370641"
I, [2020-01-08T16:39:13.156433 #505-47203788704140]  INFO -- : # 200
I, [2020-01-08T16:39:13.169448 #505-47203788704140]  INFO -- : Performed SearchIndexJob (Job ID: 871ac29e-f68b-4b46-b4c8-5365da5dc638) from DelayedJob(default) in 1877.44ms
I, [2020-01-08T16:39:13.172854 #505-47203788704140]  INFO -- : 2020-01-08T16:39:13+0100: [Worker(host:zammad2 pid:505)] Job SearchIndexJob [871ac29e-f68b-4b46-b4c8-5365da5dc638] from DelayedJob(default) with arguments: ["Ticket", 566] (id=5312071) (queue=default) COMPLETED after 2.0885
I, [2020-01-08T16:39:13.176612 #505-47203788704140]  INFO -- : 2020-01-08T16:39:13+0100: [Worker(host:zammad2 pid:505)] Job TicketArticleCommunicateEmailJob [118e8e44-cd12-4133-8e71-9aebc909664c] from DelayedJob(default) with arguments: [3462] (id=5312072) (queue=default) RUNNING
I, [2020-01-08T16:39:13.223423 #505-47203788704140]  INFO -- : Performing TicketArticleCommunicateEmailJob (Job ID: 118e8e44-cd12-4133-8e71-9aebc909664c) from DelayedJob(default) with arguments: 3462
I, [2020-01-08T16:39:14.848718 #505-47203788704140]  INFO -- : Send email to: 'mail_1@domain.com, mail_2@domain.com, mail_3@domain.com, mail_4@domain.com' (from "Users - mail_5@domain.com" <mail_5@domain.com>)
I, [2020-01-08T16:39:14.867621 #505-47203788704140]  INFO -- : Performed TicketArticleCommunicateEmailJob (Job ID: 118e8e44-cd12-4133-8e71-9aebc909664c) from DelayedJob(default) in 1644.02ms
I, [2020-01-08T16:39:14.871713 #505-47203788704140]  INFO -- : 2020-01-08T16:39:14+0100: [Worker(host:zammad2 pid:505)] Job TicketArticleCommunicateEmailJob [118e8e44-cd12-4133-8e71-9aebc909664c] from DelayedJob(default) with arguments: [3462] (id=5312072) (queue=default) COMPLETED after 1.6950
I, [2020-01-08T16:39:14.879113 #505-47203788704140]  INFO -- : 2020-01-08T16:39:14+0100: [Worker(host:zammad2 pid:505)] Job TicketArticleCommunicateEmailJob [cff0091f-e8fb-49f2-8a0b-8efc56928eac] from DelayedJob(default) with arguments: [3463] (id=5312073) (queue=default) RUNNING
I, [2020-01-08T16:39:14.918506 #505-47203788704140]  INFO -- : Performing TicketArticleCommunicateEmailJob (Job ID: cff0091f-e8fb-49f2-8a0b-8efc56928eac) from DelayedJob(default) with arguments: 3463
I, [2020-01-08T16:39:15.501112 #501-47351719558660]  INFO -- : Started GET "/api/v1/ticket_articles/3462?full=true&_=1578497833353" for 10.0.0.50 at 2020-01-08 16:39:15 +0100
I, [2020-01-08T16:39:15.508379 #501-47351719558660]  INFO -- : Processing by TicketArticlesController#show as JSON
I, [2020-01-08T16:39:15.508489 #501-47351719558660]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1578497833353", "id"=>"3462"}
I, [2020-01-08T16:39:15.624182 #501-47351719558660]  INFO -- : Completed 200 OK in 116ms (Views: 17.6ms | ActiveRecord: 11.2ms)
I, [2020-01-08T16:39:16.664895 #505-47203788704140]  INFO -- : Send email to: 'mail_5@domain.com, mail@anotherdomain.com, mail_1@domain.com, mail_2@domain.com, mail_3@domain.com, mail_4@domain.com' (from "Users - mail_5@domain.com" <mail_5@domain.com>)
I, [2020-01-08T16:39:16.679852 #505-47203788704140]  INFO -- : Performed TicketArticleCommunicateEmailJob (Job ID: cff0091f-e8fb-49f2-8a0b-8efc56928eac) from DelayedJob(default) in 1761.18ms
I, [2020-01-08T16:39:16.683512 #505-47203788704140]  INFO -- : 2020-01-08T16:39:16+0100: [Worker(host:zammad2 pid:505)] Job TicketArticleCommunicateEmailJob [cff0091f-e8fb-49f2-8a0b-8efc56928eac] from DelayedJob(default) with arguments: [3463] (id=5312073) (queue=default) COMPLETED after 1.8043
I, [2020-01-08T16:39:16.688720 #505-47203788704140]  INFO -- : 2020-01-08T16:39:16+0100: [Worker(host:zammad2 pid:505)] Job Transaction::BackgroundJob (id=5312074) RUNNING
I, [2020-01-08T16:39:16.781071 #505-47203788704140]  INFO -- : 2020-01-08T16:39:16+0100: [Worker(host:zammad2 pid:505)] Job Transaction::BackgroundJob (id=5312074) COMPLETED after 0.0922
I, [2020-01-08T16:39:16.786306 #505-47203788704140]  INFO -- : 2020-01-08T16:39:16+0100: [Worker(host:zammad2 pid:505)] Job Transaction::BackgroundJob (id=5312075) RUNNING
I, [2020-01-08T16:39:16.848648 #505-47203788704140]  INFO -- : 2020-01-08T16:39:16+0100: [Worker(host:zammad2 pid:505)] Job Transaction::BackgroundJob (id=5312075) COMPLETED after 0.0622
I, [2020-01-08T16:39:16.853189 #505-47203788704140]  INFO -- : 2020-01-08T16:39:16+0100: [Worker(host:zammad2 pid:505)] Job TicketUserTicketCounterJob [7e1719f4-4a47-4e14-8864-18302c3d6165] from DelayedJob(default) with arguments: [163, 46] (id=5312076) (queue=default) RUNNING
I, [2020-01-08T16:39:16.897338 #505-47203788704140]  INFO -- : Performing TicketUserTicketCounterJob (Job ID: 7e1719f4-4a47-4e14-8864-18302c3d6165) from DelayedJob(default) with arguments: 163, 46
I, [2020-01-08T16:39:16.917440 #505-47203788704140]  INFO -- : Performed TicketUserTicketCounterJob (Job ID: 7e1719f4-4a47-4e14-8864-18302c3d6165) from DelayedJob(default) in 19.93ms
I, [2020-01-08T16:39:16.920909 #505-47203788704140]  INFO -- : 2020-01-08T16:39:16+0100: [Worker(host:zammad2 pid:505)] Job TicketUserTicketCounterJob [7e1719f4-4a47-4e14-8864-18302c3d6165] from DelayedJob(default) with arguments: [163, 46] (id=5312076) (queue=default) COMPLETED after 0.0676
I, [2020-01-08T16:39:16.924906 #505-47203788704140]  INFO -- : 2020-01-08T16:39:16+0100: [Worker(host:zammad2 pid:505)] Job Transaction::BackgroundJob (id=5312077) RUNNING
I, [2020-01-08T16:39:17.210593 #505-47203788704140]  INFO -- : Send notification to: mail_1@domain.com (from:DOMAIN Support team <mail_5@domain.com>/subject:Biglietto aggiornato (devo aprire un ticket) [Ticket#64566])
I, [2020-01-08T16:39:17.514027 #501-47351719517300]  INFO -- : Started GET "/api/v1/ticket_articles/3463?full=true&_=1578497833354" for 10.0.0.50 at 2020-01-08 16:39:17 +0100
I, [2020-01-08T16:39:17.523848 #501-47351719517300]  INFO -- : Processing by TicketArticlesController#show as JSON
I, [2020-01-08T16:39:17.523964 #501-47351719517300]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1578497833354", "id"=>"3463"}
I, [2020-01-08T16:39:17.732302 #501-47351719517300]  INFO -- : Completed 200 OK in 208ms (Views: 141.6ms | ActiveRecord: 5.2ms)
I, [2020-01-08T16:39:17.775734 #505-47203788704140]  INFO -- : Send notification to: mail_3@domain.com (from:DOMAIN Support team <mail_5@domain.com>/subject:Biglietto aggiornato (devo aprire un ticket) [Ticket#64566])
I, [2020-01-08T16:39:18.313773 #505-47203788704140]  INFO -- : Send notification to: mail_4@domain.comt (from:DOMAIN Support team <mail_5@domain.com>/subject:Biglietto aggiornato (devo aprire un ticket) [Ticket#64566])
I, [2020-01-08T16:39:18.911775 #505-47203788704140]  INFO -- : 2020-01-08T16:39:18+0100: [Worker(host:zammad2 pid:505)] Job Transaction::BackgroundJob (id=5312077) COMPLETED after 1.9867
I, [2020-01-08T16:39:25.280980 #505-47203774099560]  INFO -- : execute Channel.fetch (try_count 0)...
I, [2020-01-08T16:39:25.293608 #505-47203774099560]  INFO -- : fetching imap (domain.com/mail_5@domain.com port=143,ssl=false,starttls=false,folder=INBOX,keep_on_server=true)
I, [2020-01-08T16:39:25.584578 #505-47203774099560]  INFO -- :  - message 1/1
I, [2020-01-08T16:39:25.859970 #505-47203774099560]  INFO -- :   - ignore message 1/1 - because message message id already imported
I, [2020-01-08T16:39:25.862605 #505-47203774099560]  INFO -- : done
I, [2020-01-08T16:39:25.894275 #505-47203774099560]  INFO -- : ended Channel.fetch took: 0.675441957 seconds.

MrGeneration · January 8, 2020, 4:34pm

Sorry but fiddling around with a backup of yours is out of my scope.
I can’t help you further.

If you can’t reproduce this on a clean system, there must be something wrong that causes this behaviour. But it doesn’t seem to be a general issue. I know, this doesn’t help you directly.

niddu85 · January 9, 2020, 7:52am

Ok, i do not want you to solve my problem, but could please you guide me on how to investigate (log files or whatever) in order to understand what’s wrong?

MrGeneration · January 9, 2020, 5:56pm

Maybe @thorsteneckel can, I can’t help further.

niddu85 · January 10, 2020, 8:49am

I just found a strange behaviour on the faulty system.
this is what i see in the history of the ticket when i submit a private note, see 3 times “created Article” and twice “Updated article body”:

user1- 3 minutes ago

created Article

3 minutes ago

created Article

created Article

3 minutes ago

updated Article body from ‘Your request (#64566) has been updated by User1

> another note

Please click here to see changes
https://tickets.xxx.xx/#ticket/zoom
’ to ‘Your request (#64566) has been updated by User1

> another note

Please click here to see changes
https://tickets.xxx.xx/#ticket/zoom
’

email sent to ‘user2@xxx.xx, user1@xxx.xx, user3@xxx.xx, user4@xxx.xx, userA@yyy.yy’

updated Article body from ‘
Your ticket (#64566) “devo aprire un ticket” has been updated

Please click here to see changes

https://tickets.xxx.xx/#ticket/zoom

’ to ‘
Your ticket (#64566) “devo aprire un ticket” has been updated

Please click here to see changes

https://tickets.xxx.xx/#ticket/zoom

’

email sent to ‘user5@xxx.xx, user1@aaa.com, user2@xxx.xx, user1@xxx.xx, user3@xxx.xx, user4@xxx.xx, userA@yyy.yy’

User1 - 3 minutes ago

notification sent to ‘user1@xxx.xx(update:online,email)’

notification sent to ‘user2@xxx.xx(update:online,email)’

notification sent to ‘user3@xxx.xx(update:online,email)’

notification sent to ‘userA@yyy.yy(update:online,email)’

while on the hosted server, where the trigger works correctly i see:

1 minute ago

created Article

1 minute ago

created Article

updated Article body from ‘Your request (#40003) has been updated by AAAA

> another note

Please click here to see changes
https://k-a-xxxxxxxxxcom/#ticket/zoom
’ to ‘Your request (#40003) has been updated by AAAAA

> another note

Please click here to see changes
https://k-a-xxxxxxxxxcom/#ticket/zoom
’

email sent to ‘user1@xxx.xx, user2@xxx.xx’

AAAAA - 1 minute ago

notification sent to ‘user2@xxx.xx(update:online,email)’

can you see only 2 Created Article and only 1 Updated Article Body?

maybe this has something to do with the issue?

system · May 9, 2020, 8:49am

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