Thanks for your answer!
The error is thrown in
vendor/bundle/ruby/2.6/gems/activerecord-5.2.4.3/lib/active_record/locking/pessimistic.rb:66
before the app tries to get a row lock with “select for update”, it checks if there are unsaved changes.
Almost all tickes were created in version 3.3.0, inbound email.
There is no customization, not even additional fields.
There are SLA for some tickets (errors come with and without SLA).
I’ve attached the logs of three cases:
- error case
- successful case
- workaround (adding a tag)
Thanks again, horst
# --- example of error while updating ticket ----
Started PUT "/api/v1/tickets/2402?all=true" for 192.0.2.10 at 2020-06-30 09:22:07 +0200
Processing by TicketsController#update as JSON
Parameters: {"number"=>"832402", "title"=>"...", "group_id"=>"14", "owner_id"=>1, "customer_id"=>1654, "state_id"=>"1", "priority_id"=>"2", "article"=>{"from"=>"My Name", "to"=>"", "cc"=>"", "subject"=>"", "body"=>"[FILTERED]", "content_type"=>"text/html", "ticket_id"=>2402, "type_id"=>10, "sender_id"=>1, "internal"=>true, "in_reply_to"=>"", "form_id"=>"501751448", "subtype"=>""}, "updated_at"=>"2020-06-25T16:28:04.693Z", "preferences"=>{"channel_id"=>7, "escalation_calculation"=>{"first_response_at"=>nil, "last_update_at"=>"2020-06-25T16:28:04.628Z", "close_at"=>nil, "sla_id"=>2, "sla_updated_at"=>"2019-12-12T10:42:33.669Z", "calendar_id"=>1, "calendar_updated_at"=>"2020-06-25T15:16:01.478Z", "escalation_disabled"=>false}}, "pending_time"=>nil, "id"=>"2402", "all"=>"true"}
session based auth check
(0.1ms) SELECT "roles"."id" FROM "roles" INNER JOIN "roles_users" ON "roles"."id" = "roles_users"."role_id" WHERE "roles_users"."user_id" = $1 [["user_id", 3]]
↳ app/models/user.rb:434
(0.3ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('user_preferences','user_preferences.device') AND permissions.active = TRUE)
↳ app/models/user.rb:434
session for '**@****.eu'
CACHE (0.0ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('user_preferences','user_preferences.device') AND permissions.active = TRUE)
↳ app/models/user.rb:434
Ticket Load (0.3ms) SELECT "tickets".* FROM "tickets" WHERE "tickets"."id" = $1 LIMIT $2 [["id", 2402], ["LIMIT", 1]]
↳ app/controllers/tickets_controller.rb:223
(0.3ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('ticket','ticket.agent') AND permissions.active = TRUE)
↳ app/models/user.rb:434
(0.3ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('ticket','ticket.customer') AND permissions.active = TRUE)
↳ app/models/user.rb:434
Group Load (0.1ms) SELECT "groups".* FROM "groups" WHERE "groups"."id" = $1 LIMIT $2 [["id", 14], ["LIMIT", 1]]
↳ app/policies/ticket_policy.rb:61
CACHE (0.0ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('ticket','ticket.agent') AND permissions.active = TRUE)
↳ app/models/user.rb:434
UserGroup Exists (0.3ms) SELECT 1 AS one FROM "groups_users" LEFT OUTER JOIN "groups" ON "groups"."id" = "groups_users"."group_id" WHERE "groups_users"."user_id" = $1 AND "groups_users"."group_id" = $2 AND ("groups_users"."access") IN ($3, $4) AND "groups"."active" = $5 LIMIT $6 [["user_id", 3], ["group_id", 14], ["access", "change"], ["access", "full"], ["active", true], ["LIMIT", 1]]
↳ app/models/concerns/has_groups.rb:75
CACHE (0.0ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('ticket','ticket.agent') AND permissions.active = TRUE)
↳ app/models/user.rb:434
(0.1ms) BEGIN
↳ app/controllers/tickets_controller.rb:243
(0.1ms) ROLLBACK
↳ app/controllers/tickets_controller.rb:243
#<RuntimeError: Locking a record with unpersisted changes is not supported. Use `save` to persist the changes, or `reload` to discard them explicitly.>
(0.3ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('admin') AND permissions.active = TRUE)
↳ app/models/user.rb:434
Completed 500 Internal Server Error in 15ms (Views: 0.1ms | ActiveRecord: 2.1ms)
# --- example of successful ticket update ---
Started PUT "/api/v1/tickets/2397?all=true" for 192.0.2.10 at 2020-06-30 09:21:34 +0200
Processing by TicketsController#update as JSON
Parameters: {"number"=>"832397", "title"=>"Re: ......", "group_id"=>"14", "owner_id"=>1, "customer_id"=>1720, "state_id"=>"1", "priority_id"=>"2", "article"=>{"from"=>"My Name", "to"=>"", "cc"=>"", "subject"=>"", "body"=>"[FILTERED]", "content_type"=>"text/html", "ticket_id"=>"2397", "type_id"=>10, "sender_id"=>1, "internal"=>true, "in_reply_to"=>"", "form_id"=>"501685049", "subtype"=>""}, "updated_at"=>"2020-06-30T07:21:32.443Z", "preferences"=>{"channel_id"=>7, "escalation_calculation"=>{"first_response_at"=>nil, "last_update_at"=>"2020-06-25T11:39:33.833Z", "close_at"=>nil, "sla_id"=>2, "sla_updated_at"=>"2019-12-12T10:42:33.669Z", "calendar_id"=>1, "calendar_updated_at"=>"2020-06-29T15:17:04.441Z", "escalation_disabled"=>false}}, "pending_time"=>nil, "id"=>"2397", "all"=>"true"}
session based auth check
(0.1ms) SELECT "roles"."id" FROM "roles" INNER JOIN "roles_users" ON "roles"."id" = "roles_users"."role_id" WHERE "roles_users"."user_id" = $1 [["user_id", 3]]
↳ app/models/user.rb:434
(0.3ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('user_preferences','user_preferences.device') AND permissions.active = TRUE)
↳ app/models/user.rb:434
session for '**@****.eu'
CACHE (0.0ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."i
d" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('user_preferences','user_preferences.device') AND permissions.active = TRUE)
↳ app/models/user.rb:434
Ticket Load (0.1ms) SELECT "tickets".* FROM "tickets" WHERE "tickets"."id" = $1 LIMIT $2 [["id", 2397], ["LIMIT", 1]]
↳ app/controllers/tickets_controller.rb:223
(0.3ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('ticket','ticket.agent') AND permissions.active = TRUE)
↳ app/models/user.rb:434
(0.4ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('ticket','ticket.customer') AND permissions.active = TRUE)
↳ app/models/user.rb:434
Group Load (0.1ms) SELECT "groups".* FROM "groups" WHERE "groups"."id" = $1 LIMIT $2 [["id", 14], ["LIMIT", 1]]
↳ app/policies/ticket_policy.rb:61
CACHE (0.0ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('ticket','ticket.agent') AND permissions.active = TRUE)
↳ app/models/user.rb:434
UserGroup Exists (0.2ms) SELECT 1 AS one FROM "groups_users" LEFT OUTER JOIN "groups" ON "groups"."id" = "groups_users"."group_id" WHERE "groups_users"."user_id" = $1 AND "groups_users"."group_id" = $2 AND ("groups_users"."access") IN ($3, $4) AND "groups"."active" = $5 LIMIT $6 [["user_id", 3], ["group_id", 14], ["access", "change"], ["access", "full"], ["active", true], ["LIMIT", 1]]
↳ app/models/concerns/has_groups.rb:75
CACHE (0.0ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = "permissions_roles"."role_id" WHERE (roles.id IN (2,1) AND roles.active = TRUE AND permissions.name IN ('ticket','ticket.agent') AND permissions.active = TRUE)
↳ app/models/user.rb:434
(0.1ms) BEGIN
↳ app/controllers/tickets_controller.rb:243
Ticket Load (0.4ms) SELECT "tickets".* FROM "tickets" WHERE "tickets"."id" = $1 LIMIT $2 FOR UPDATE [["id", 2397], ["LIMIT", 1]]
↳ app/controllers/tickets_controller.rb:243
(0.2ms) SELECT COUNT(*) AS "size", MAX("object_manager_attributes"."updated_at") AS timestamp FROM "object_manager_attributes" WHERE "object_manager_attributes"."active" = $1 [["active", true]]
↳ app/models/object_manager/attribute/validation.rb:52
User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2 [["id", 1720], ["LIMIT", 1]]
↳ app/models/ticket.rb:1257
Ticket Update (0.5ms) UPDATE "tickets" SET "preferences" = $1, "updated_at" = $2 WHERE "tickets"."id" = $3 [["preferences", "--- !ruby/hash:ActiveSupport::HashWithIndifferentAccess\nchannel_id: 7\nescalation_calculation: !ruby/hash:ActiveSupport::HashWithIndifferentAccess\n first_response_at:\n last_update_at: '2020-06-25T11:39:33.833Z'\n close_at:\n sla_id: 2\n sla_updated_at: '2019-12-12T10:42:33.669Z'\n calendar_id: 1\n calendar_updated_at: '2020-06-29T15:17:04.441Z'\n escalation_disabled: false\n"], ["updated_at", "2020-06-30 07:21:34.512000"], ["id", 2397]]
↳ app/controllers/tickets_controller.rb:244
Ticket.find(2397) notify UPDATED 2020-06-30 07:21:34 UTC
ActiveJobLock Load (0.2ms) SELECT "active_job_locks".* FROM "active_job_locks" WHERE "active_job_locks"."lock_key" = $1 LIMIT $2 FOR UPDATE [["lock_key", "SearchIndexJob/Ticket/2397"], ["LIMIT", 1]]
↳ app/jobs/concerns/has_active_job_lock.rb:117
ActiveJobLock Create (0.1ms) INSERT INTO "active_job_locks" ("lock_key", "active_job_id", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["lock_key", "SearchIndexJob/Ticket/2397"], ["active_job_id", "32fd19d6-d0c3-41ac-8fed-11b55876c841"], ["created_at", "2020-06-30 07:21:34.524912"], ["updated_at", "2020-06-30 07:21:34.524912"]]
↳ app/jobs/concerns/has_active_job_lock.rb:60
Delayed::Backend::ActiveRecord::Job Create (0.1ms) INSERT INTO "delayed_jobs" ("priority", "handler", "run_at", "queue", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5, $6) RETURNING "id" [["priority", 300], ["handler", "--- !ruby/object:ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper\njob_data:\n job_class: SearchIndexJob\n job_id: 32fd19d6-d0c3-41ac-8fed-11b55876c841\n provider_job_id:\n queue_name: default\n priority: 300\n arguments:\n - Ticket\n - 2397\n executions: 0\n locale: en\n"], ["run_at", "2020-06-30 07:21:34.525792"], ["queue", "default"], ["created_at", "2020-06-30 07:21:34.525000"], ["updated_at", "2020-06-30 07:21:34.525000"]]
↳ app/models/concerns/has_search_index_backend.rb:27
Delayed::Backend::ActiveRecord::Job Update All (0.1ms) UPDATE "delayed_jobs" SET "attempts" = 0 WHERE "delayed_jobs"."id" = $1 [["id", 1256775]]
# --- example of work-around by adding tag to ticket ---
Started PUT "/api/v1/tickets/2402?all=true" for 192.0.2.10 at 2020-06-30 09:22:25 +0200
(1.6ms) COMMIT
↳ app/models/tag.rb:42
Processing by TicketsController#update as JSON
Parameters: {"number"=>"832402", "title"=>"...", "group_id"=>"14", "owner_id"=>1, "customer_id"=>1654, "state_id"=>"1", "priority_id"=>"2", "updated_at"=>"2020-06-25T16:28:04.693Z", "preferenc>
session based auth check
(0.1ms) BEGIN
↳ app/models/application_model/can_touch_references.rb:23
(0.5ms) SELECT "roles"."id" FROM "roles" INNER JOIN "roles_users" ON "roles"."id" = "roles_users"."role_id" WHERE "roles_users"."user_id" = $1 [["user_id", 3]]
↳ app/models/user.rb:434
Ticket Update (0.8ms) UPDATE "tickets" SET "updated_at" = $1 WHERE "tickets"."id" = $2 [["updated_at", "2020-06-30 07:22:25.190000"], ["id", 2402]]
↳ app/models/application_model/can_touch_references.rb:23
Ticket.find(2402) notify TOUCH 2020-06-30 07:22:25 UTC
(0.8ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = >
↳ app/models/user.rb:434
session for '**@****.eu'
ActiveJobLock Load (0.3ms) SELECT "active_job_locks".* FROM "active_job_locks" WHERE "active_job_locks"."lock_key" = $1 LIMIT $2 FOR UPDATE [["lock_key", "SearchIndexJob/Ticket/2402"], ["LI>
↳ app/jobs/concerns/has_active_job_lock.rb:117
CACHE (0.0ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles".">
↳ app/models/user.rb:434
ActiveJobLock Create (0.5ms) INSERT INTO "active_job_locks" ("lock_key", "active_job_id", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["lock_key", "SearchIndexJob/Tic>
↳ app/jobs/concerns/has_active_job_lock.rb:60
Ticket Load (1.0ms) SELECT "tickets".* FROM "tickets" WHERE "tickets"."id" = $1 LIMIT $2 [["id", 2402], ["LIMIT", 1]]
↳ app/controllers/tickets_controller.rb:223
Delayed::Backend::ActiveRecord::Job Create (0.5ms) INSERT INTO "delayed_jobs" ("priority", "handler", "run_at", "queue", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5, $6) RETURNING >
↳ app/models/concerns/has_search_index_backend.rb:47
Delayed::Backend::ActiveRecord::Job Update All (0.5ms) UPDATE "delayed_jobs" SET "attempts" = 0 WHERE "delayed_jobs"."id" = $1 [["id", 1256780]]
↳ app/jobs/application_job/has_delayed_job_monitoring_compatibilty.rb:17
Enqueued SearchIndexJob (Job ID: 2a680b4a-2c39-4b23-bb42-7ff47f03caf6) to DelayedJob(default) with arguments: "Ticket", 2402
(0.3ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = >
↳ app/models/user.rb:434
(1.2ms) COMMIT
↳ app/models/application_model/can_touch_references.rb:23
(0.5ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles"."id" = >
↳ app/models/user.rb:434
Ticket Load (0.1ms) SELECT "tickets".* FROM "tickets" WHERE "tickets"."id" = $1 LIMIT $2 [["id", 2402], ["LIMIT", 1]]
↳ app/models/observer/ticket/escalation_update.rb:23
Group Load (0.1ms) SELECT "groups".* FROM "groups" WHERE "groups"."id" = $1 LIMIT $2 [["id", 14], ["LIMIT", 1]]
↳ app/policies/ticket_policy.rb:61
CACHE (0.0ms) SELECT "permissions"."preferences" FROM "permissions" INNER JOIN "permissions_roles" ON "permissions_roles"."permission_id" = "permissions"."id" INNER JOIN "roles" ON "roles".">
↳ app/models/user.rb:434
UserGroup Exists (0.2ms) SELECT 1 AS one FROM "groups_users" LEFT OUTER JOIN "groups" ON "groups"."id" = "groups_users"."group_id" WHERE "groups_users"."user_id" = $1 AND "groups_users"."gro>
↳ app/models/concerns/has_groups.rb:75
Sla Load (0.5ms) SELECT "slas".* FROM "slas" ORDER BY "slas"."name" ASC, "slas"."created_at" ASC
↳ app/models/ticket/escalation.rb:271
Ticket Load (0.5ms) SELECT "tickets".* FROM "tickets" WHERE ("tickets"."state_id" IN ('1','2') AND "tickets"."group_id" IN ('14')) AND "tickets"."id" = $1 LIMIT $2 [["id", 2402], ["LIMIT", >
↳ app/models/ticket/escalation.rb:276
Calendar Load (0.2ms) SELECT "calendars".* FROM "calendars" WHERE "calendars"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]]
↳ app/models/ticket/escalation.rb:79
History Load (0.4ms) SELECT "histories".* FROM "histories" WHERE ("histories"."history_object_id" = $1 AND "histories"."o_id" = $2 OR "histories"."history_object_id" = $3 AND "histories"."rel>
↳ app/models/history.rb:168
Ticket::State Load (0.2ms) SELECT "ticket_states".* FROM "ticket_states" WHERE "ticket_states"."ignore_escalation" = $1 [["ignore_escalation", true]]
↳ app/models/ticket/escalation.rb:328