ActiveRecord::ReadOnlyError: Write query attempted while in readonly mode: UPDATE

[wdiechmann]

been wanting to report on this one for a bit now - here goes:

I have a routine which I foresee will get hit quite a lot thus I push it into a background job. When I call it - I somewhat anticipated the subject error (whilst crossing my fingers for enhancedsqlite3 having my back); you could say fearing the worst, hoping the best:

This is what I see in my log

Started PUT "/pos/employee?api_key=[FILTERED]&id=14" for 127.0.0.1 at 2024-05-29 16:25:10 +0200
Processing by Pos::EmployeeController#update as TURBO_STREAM
  Parameters: {"punch"=>{"punched_at"=>"2024-05-27T16:05"}, "api_key"=>"[FILTERED]", "id"=>"14"}
[reader]   Employee Load (0.1ms)  SELECT "employees".* FROM "employees" WHERE "employees"."access_token" = ? LIMIT ?  [["access_token", "[FILTERED]"], ["LIMIT", 1]]
[reader]   ↳ app/controllers/pos/employee_controller.rb:112:in `verify_employee'
[reader]   Account Load (0.0ms)  SELECT "accounts".* FROM "accounts" WHERE "accounts"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
[reader]   ↳ app/controllers/pos/employee_controller.rb:118:in `verify_employee'
[reader]   Punch Load (0.0ms)  SELECT "punches".* FROM "punches" WHERE "punches"."id" = ? LIMIT ?  [["id", 14], ["LIMIT", 1]]
[reader]   ↳ app/controllers/pos/employee_controller.rb:72:in `update'
[writer]   TRANSACTION (0.0ms)  begin transaction
[writer]   ↳ app/controllers/pos/employee_controller.rb:73:in `update'
[writer]   Punch Update (0.5ms)  UPDATE "punches" SET "punched_at" = ?, "updated_at" = ? WHERE "punches"."id" = ?  [["punched_at", "2024-05-27 14:05:00"], ["updated_at", "2024-05-29 14:25:10.685468"], ["id", 14]]
[writer]   ↳ app/controllers/pos/employee_controller.rb:73:in `update'
[writer]   TRANSACTION (0.0ms)  commit transaction
[writer]   ↳ app/controllers/pos/employee_controller.rb:73:in `update'
[reader]   Employee Load (0.0ms)  SELECT "employees".* FROM "employees" WHERE "employees"."id" = ? LIMIT ?  [["id", 4], ["LIMIT", 1]]
[reader]   ↳ app/controllers/pos/employee_controller.rb:74:in `update'
-----------------
Recalculating abrahamski on 2024-05-27
-----------------
[reader]   Account Load (0.1ms)  SELECT "accounts".* FROM "accounts" WHERE "accounts"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
[reader]   ↳ app/models/concerns/sum_punches.rb:14:in `recalculate'
[reader]   PunchCard Load (0.3ms)  SELECT "punch_cards".* FROM "punch_cards" WHERE "punch_cards"."account_id" = ? AND "punch_cards"."employee_id" = ? AND "punch_cards"."work_date" = ? ORDER BY "punch_cards"."id" ASC LIMIT ?  [["account_id", 1], ["employee_id", 4], ["work_date", "2024-05-27"], ["LIMIT", 1]]
[reader]   ↳ app/models/concerns/sum_punches.rb:14:in `recalculate'
[reader]   Punch Exists? (0.1ms)  SELECT 1 AS one FROM "punches" WHERE "punches"."employee_id" = ? AND "punches"."punched_at" BETWEEN ? AND ? LIMIT ?  [["employee_id", 4], ["punched_at", "2024-05-26 22:00:00"], ["punched_at", "2024-05-27 21:59:59.999999"], ["LIMIT", 1]]
[reader]   ↳ app/models/concerns/sum_punches.rb:22:in `recalculate'
[reader]   Punch Count (0.0ms)  SELECT COUNT(*) FROM "punches" WHERE "punches"."employee_id" = ? AND "punches"."punched_at" BETWEEN ? AND ?  [["employee_id", 4], ["punched_at", "2024-05-26 22:00:00"], ["punched_at", "2024-05-27 21:59:59.999999"]]
[reader]   ↳ app/models/concerns/sum_punches.rb:17:in `recalculate'
-----------------
#<ActiveRecord::ReadOnlyError: Write query attempted while in readonly mode: UPDATE "punches" SET "punch_card_id" = ? WHERE ("punches"."id") IN (SELECT "punches"."id" FROM "punches" WHERE "punches"."employee_id" = ? AND "punches"."punched_at" BETWEEN ? AND ? ORDER BY "punches"."punched_at" DESC)>
-----------------
  Rendered pos/employee/_punch.html.erb (Duration: 0.5ms | GC: 0.0ms)
Completed 200 OK in 71ms (Views: 0.2ms | ActiveRecord: 1.2ms (9 queries, 0 cached) | GC: 1.0ms)

The method in question looks like this:

    punches = employee.punches.where(punched_at: date.beginning_of_day..date.end_of_day).order(punched_at: :desc)
    ...
    when 2; two_punches pc, punches
    ...

    def two_punches(pc, punches)
      punches.update_all punch_card_id: pc.id
      return unless punches.second.in? && punches.first.out?
      pc.update work_minutes: (punches.first.punched_at - punches.second.punched_at) / 60
    end

It is - in fact easily remedied by

          ActiveRecord::Base.connected_to(role: :writing) do
              punches = employee.punches.where(punched_at: date.beginning_of_day..date.end_of_day).order(punched_at: :desc)
              ...
              when 2; two_punches pc, punches
          end

- so my only issue with this is, I guess, I was hoping for enhanced to band-aid this 😉

[fractaledmind]

This is a great report. Thank you. I bet that update_all doesn't call ActiveRecord's transaction method. I need to study the call stack to find if there is a single method that all ActiveRecord write operations call. If not, I will find the two methods we can patch to fix this. Will investigate.

[wdiechmann]

in case you got "distracted" this is quite a nuisance - see https://github.com/rails/solid_cable/issues/47 which to me seems like kind'a collateral damage

had @npezza93 fix it - but I guess that band-aid really belongs somewhere else, right? 😎

[wdiechmann]

hi Stephen - what's your position on this?

Could the enhanced adapter help solve this with some SQL magic? Or will the Locker::Room have to be solved in a (different) gem?

In my point of view we all dance around the concurrency issue without solving the root cause (which to me seems to be bad workflow design) - thoughts?