rails / solid_queue

Database-backed Active Job backend
MIT License
1.84k stars 110 forks source link

ActiveRecord::StatementInvalid SQLite3::CorruptException - but it's not! #294

Closed wdiechmann closed 1 month ago

wdiechmann commented 1 month ago

I've been getting this strange error for some time now - chalked it up to me not adding correct arguments ( - but the thing is; on a "fresh" file this does not happen or at least I think so)

My development.sqlite works fine and the solid_queue too - as the log will tell you - when I throw it some work "manually", but somehow the SolidQueue::RecurringExecution Insert gets the wrong impression of the database...or I don't know

11:48:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.1ms)  begin transaction
11:48:00 web.1  | [ActiveJob] [writer]   SolidQueue::Job Create (12.5ms)  INSERT INTO "solid_queue_jobs" ("queue_name", "class_name", "arguments", "priority", "active_job_id", "scheduled_at", "finished_at", "concurrency_key", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) RETURNING "id"  [["queue_name", "default"], ["class_name", "BackgroundManagerJob"], ["arguments", "{\"job_class\":\"BackgroundManagerJob\",\"job_id\":\"69bd0679-7599-4f98-96b5-8fe4e5709811\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[],\"executions\":0,\"exception_executions\":{},\"locale\":\"da\",\"timezone\":\"UTC\",\"enqueued_at\":\"2024-08-23T09:48:00.011104000Z\",\"scheduled_at\":\"2024-08-23T09:48:00.011040000Z\"}"], ["priority", 0], ["active_job_id", "69bd0679-7599-4f98-96b5-8fe4e5709811"], ["scheduled_at", "2024-08-23 09:48:00.011040"], ["finished_at", nil], ["concurrency_key", "[FILTERED]"], ["created_at", "2024-08-23 09:48:00.011582"], ["updated_at", "2024-08-23 09:48:00.011582"]]
11:48:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
11:48:00 web.1  | [ActiveJob] [writer]   SolidQueue::Job Load (1.6ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3470], ["LIMIT", 1]]
11:48:00 web.1  | [ActiveJob] [writer]   SolidQueue::ReadyExecution Create (0.2ms)  INSERT INTO "solid_queue_ready_executions" ("job_id", "queue_name", "priority", "created_at") VALUES (?, ?, ?, ?) RETURNING "id"  [["job_id", 3470], ["queue_name", "default"], ["priority", 0], ["created_at", "2024-08-23 09:48:00.069136"]]
11:48:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
11:48:00 web.1  | [ActiveJob] Enqueued BackgroundManagerJob (Job ID: 69bd0679-7599-4f98-96b5-8fe4e5709811) to SolidQueue(default)
11:48:00 web.1  | [writer]   SolidQueue::RecurringExecution Insert (0.2ms)  INSERT INTO "solid_queue_recurring_executions" ("job_id","task_key","run_at","created_at") VALUES (3470, 'background_job_scheduler', '2024-08-23 09:48:00', STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW')) ON CONFLICT ("task_key","run_at") DO NOTHING RETURNING "id"
11:48:00 web.1  | [writer]   TRANSACTION (0.0ms)  rollback transaction
11:48:00 web.1  | SolidQueue-0.5.0 Error enqueuing recurring task (63.2ms)  task: "background_job_scheduler", at: "2024-08-23T09:48:00Z"
11:48:00 web.1  | SolidQueue-0.5.0 Error in thread (0.0ms)  error: "ActiveRecord::StatementInvalid SQLite3::CorruptException: database disk image is malformed"
11:48:27 web.1  | [writer]   TRANSACTION (0.2ms)  begin transaction
11:48:27 web.1  | [writer]   SolidQueue::Process Update (4.0ms)  UPDATE "solid_queue_processes" SET "last_heartbeat_at" = ? WHERE "solid_queue_processes"."id" = ?  [["last_heartbeat_at", "2024-08-23 09:48:27.028474"], ["id", 950]]
11:48:27 web.1  | [writer]   TRANSACTION (0.2ms)  commit transaction
11:48:27 web.1  | [writer]   TRANSACTION (0.1ms)  begin transaction
11:48:27 web.1  | [writer]   SolidQueue::Process Update (1.3ms)  UPDATE "solid_queue_processes" SET "last_heartbeat_at" = ? WHERE "solid_queue_processes"."id" = ?  [["last_heartbeat_at", "2024-08-23 09:48:27.082442"], ["id", 951]]
11:48:27 web.1  | [writer]   TRANSACTION (0.1ms)  commit transaction
11:48:27 web.1  | [writer]   TRANSACTION (0.1ms)  begin transaction
11:48:27 web.1  | [writer]   SolidQueue::Process Update (1.2ms)  UPDATE "solid_queue_processes" SET "last_heartbeat_at" = ? WHERE "solid_queue_processes"."id" = ?  [["last_heartbeat_at", "2024-08-23 09:48:27.092663"], ["id", 952]]
11:48:27 web.1  | [writer]   TRANSACTION (0.1ms)  commit transaction
11:48:38 web.1  | [writer]   SolidQueue::Job Load (0.2ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3470], ["LIMIT", 1]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   CompletedEmployeeNotifier Load (0.0ms)  SELECT "noticed_events".* FROM "noticed_events" WHERE "noticed_events"."type" = ? AND "noticed_events"."id" = ? LIMIT ?  [["type", "CompletedEmployeeNotifier"], ["id", 17], ["LIMIT", 1]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] Performing Noticed::EventJob (Job ID: 2d6a800f-68eb-43c6-9429-dd692cfc7cf6) from SolidQueue(default) enqueued at 2024-08-23T09:48:38.057286000Z with arguments: #<GlobalID:0x00000001250fe058 @uri=#<URI::GID gid://mortimer/CompletedEmployeeNotifier/17>>
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   Noticed::Notification Load (0.1ms)  SELECT "noticed_notifications".* FROM "noticed_notifications" WHERE "noticed_notifications"."event_id" = ?  [["event_id", 17]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  begin transaction
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::Job Create (0.9ms)  INSERT INTO "solid_queue_jobs" ("queue_name", "class_name", "arguments", "priority", "active_job_id", "scheduled_at", "finished_at", "concurrency_key", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) RETURNING "id"  [["queue_name", "default"], ["class_name", "DeliveryMethods::TurboStream"], ["arguments", "{\"job_class\":\"DeliveryMethods::TurboStream\",\"job_id\":\"a6c32ba2-8aab-4f4a-8cbd-239c84b53503\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[{\"_aj_serialized\":\"ActiveJob::Serializers::SymbolSerializer\",\"value\":\"turbo_stream\"},{\"_aj_globalid\":\"gid://mortimer/CompletedEmployeeNotifier::Notification/62\"}],\"executions\":0,\"exception_executions\":{},\"locale\":\"da\",\"timezone\":\"UTC\",\"enqueued_at\":\"2024-08-23T09:48:38.157600000Z\",\"scheduled_at\":\"2024-08-23T09:48:38.157479000Z\"}"], ["priority", 0], ["active_job_id", "a6c32ba2-8aab-4f4a-8cbd-239c84b53503"], ["scheduled_at", "2024-08-23 09:48:38.157479"], ["finished_at", nil], ["concurrency_key", "[FILTERED]"], ["created_at", "2024-08-23 09:48:38.157780"], ["updated_at", "2024-08-23 09:48:38.157780"]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::Job Load (3.5ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3471], ["LIMIT", 1]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::ReadyExecution Create (0.1ms)  INSERT INTO "solid_queue_ready_executions" ("job_id", "queue_name", "priority", "created_at") VALUES (?, ?, ?, ?) RETURNING "id"  [["job_id", 3471], ["queue_name", "default"], ["priority", 0], ["created_at", "2024-08-23 09:48:38.164631"]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.1ms)  commit transaction
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] Enqueued DeliveryMethods::TurboStream (Job ID: a6c32ba2-8aab-4f4a-8cbd-239c84b53503) to SolidQueue(default) with arguments: :turbo_stream, #<GlobalID:0x000000010445fb00 @uri=#<URI::GID gid://mortimer/CompletedEmployeeNotifier::Notification/62>>
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  begin transaction
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::Job Create (0.9ms)  INSERT INTO "solid_queue_jobs" ("queue_name", "class_name", "arguments", "priority", "active_job_id", "scheduled_at", "finished_at", "concurrency_key", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) RETURNING "id"  [["queue_name", "default"], ["class_name", "DeliveryMethods::TurboStream"], ["arguments", "{\"job_class\":\"DeliveryMethods::TurboStream\",\"job_id\":\"eeae769f-9a24-44ab-a791-bee0e1126060\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[{\"_aj_serialized\":\"ActiveJob::Serializers::SymbolSerializer\",\"value\":\"turbo_stream\"},{\"_aj_globalid\":\"gid://mortimer/CompletedEmployeeNotifier::Notification/63\"}],\"executions\":0,\"exception_executions\":{},\"locale\":\"da\",\"timezone\":\"UTC\",\"enqueued_at\":\"2024-08-23T09:48:38.168299000Z\",\"scheduled_at\":\"2024-08-23T09:48:38.168250000Z\"}"], ["priority", 0], ["active_job_id", "eeae769f-9a24-44ab-a791-bee0e1126060"], ["scheduled_at", "2024-08-23 09:48:38.168250"], ["finished_at", nil], ["concurrency_key", "[FILTERED]"], ["created_at", "2024-08-23 09:48:38.168454"], ["updated_at", "2024-08-23 09:48:38.168454"]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::Job Load (1.3ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3472], ["LIMIT", 1]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::ReadyExecution Create (0.1ms)  INSERT INTO "solid_queue_ready_executions" ("job_id", "queue_name", "priority", "created_at") VALUES (?, ?, ?, ?) RETURNING "id"  [["job_id", 3472], ["queue_name", "default"], ["priority", 0], ["created_at", "2024-08-23 09:48:38.173544"]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.1ms)  commit transaction
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] Enqueued DeliveryMethods::TurboStream (Job ID: eeae769f-9a24-44ab-a791-bee0e1126060) to SolidQueue(default) with arguments: :turbo_stream, #<GlobalID:0x0000000121d57b00 @uri=#<URI::GID gid://mortimer/CompletedEmployeeNotifier::Notification/63>>
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  begin transaction
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::Job Create (1.0ms)  INSERT INTO "solid_queue_jobs" ("queue_name", "class_name", "arguments", "priority", "active_job_id", "scheduled_at", "finished_at", "concurrency_key", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) RETURNING "id"  [["queue_name", "default"], ["class_name", "DeliveryMethods::TurboStream"], ["arguments", "{\"job_class\":\"DeliveryMethods::TurboStream\",\"job_id\":\"0a39fcff-6acb-483a-bf15-954e8c0c2719\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[{\"_aj_serialized\":\"ActiveJob::Serializers::SymbolSerializer\",\"value\":\"turbo_stream\"},{\"_aj_globalid\":\"gid://mortimer/CompletedEmployeeNotifier::Notification/64\"}],\"executions\":0,\"exception_executions\":{},\"locale\":\"da\",\"timezone\":\"UTC\",\"enqueued_at\":\"2024-08-23T09:48:38.177364000Z\",\"scheduled_at\":\"2024-08-23T09:48:38.177290000Z\"}"], ["priority", 0], ["active_job_id", "0a39fcff-6acb-483a-bf15-954e8c0c2719"], ["scheduled_at", "2024-08-23 09:48:38.177290"], ["finished_at", nil], ["concurrency_key", "[FILTERED]"], ["created_at", "2024-08-23 09:48:38.177524"], ["updated_at", "2024-08-23 09:48:38.177524"]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::Job Load (1.1ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3473], ["LIMIT", 1]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::ReadyExecution Create (0.2ms)  INSERT INTO "solid_queue_ready_executions" ("job_id", "queue_name", "priority", "created_at") VALUES (?, ?, ?, ?) RETURNING "id"  [["job_id", 3473], ["queue_name", "default"], ["priority", 0], ["created_at", "2024-08-23 09:48:38.182389"]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.2ms)  commit transaction
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] Enqueued DeliveryMethods::TurboStream (Job ID: 0a39fcff-6acb-483a-bf15-954e8c0c2719) to SolidQueue(default) with arguments: :turbo_stream, #<GlobalID:0x0000000122e13f48 @uri=#<URI::GID gid://mortimer/CompletedEmployeeNotifier::Notification/64>>
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  begin transaction
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::Job Create (1.7ms)  INSERT INTO "solid_queue_jobs" ("queue_name", "class_name", "arguments", "priority", "active_job_id", "scheduled_at", "finished_at", "concurrency_key", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) RETURNING "id"  [["queue_name", "default"], ["class_name", "DeliveryMethods::TurboStream"], ["arguments", "{\"job_class\":\"DeliveryMethods::TurboStream\",\"job_id\":\"44cc48ac-6215-4437-b272-72261bde0fa2\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[{\"_aj_serialized\":\"ActiveJob::Serializers::SymbolSerializer\",\"value\":\"turbo_stream\"},{\"_aj_globalid\":\"gid://mortimer/CompletedEmployeeNotifier::Notification/65\"}],\"executions\":0,\"exception_executions\":{},\"locale\":\"da\",\"timezone\":\"UTC\",\"enqueued_at\":\"2024-08-23T09:48:38.187525000Z\",\"scheduled_at\":\"2024-08-23T09:48:38.187448000Z\"}"], ["priority", 0], ["active_job_id", "44cc48ac-6215-4437-b272-72261bde0fa2"], ["scheduled_at", "2024-08-23 09:48:38.187448"], ["finished_at", nil], ["concurrency_key", "[FILTERED]"], ["created_at", "2024-08-23 09:48:38.187735"], ["updated_at", "2024-08-23 09:48:38.187735"]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::Job Load (1.8ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3474], ["LIMIT", 1]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   SolidQueue::ReadyExecution Create (0.1ms)  INSERT INTO "solid_queue_ready_executions" ("job_id", "queue_name", "priority", "created_at") VALUES (?, ?, ?, ?) RETURNING "id"  [["job_id", 3474], ["queue_name", "default"], ["priority", 0], ["created_at", "2024-08-23 09:48:38.194127"]]
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] [writer]   TRANSACTION (0.1ms)  commit transaction
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] Enqueued DeliveryMethods::TurboStream (Job ID: 44cc48ac-6215-4437-b272-72261bde0fa2) to SolidQueue(default) with arguments: :turbo_stream, #<GlobalID:0x0000000104b9d228 @uri=#<URI::GID gid://mortimer/CompletedEmployeeNotifier::Notification/65>>
11:48:38 web.1  | [ActiveJob] [Noticed::EventJob] [2d6a800f-68eb-43c6-9429-dd692cfc7cf6] Performed Noticed::EventJob (Job ID: 2d6a800f-68eb-43c6-9429-dd692cfc7cf6) from SolidQueue(default) in 61.28ms
11:48:38 web.1  | [writer]   SolidQueue::Job Load (0.0ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3471], ["LIMIT", 1]]
11:48:38 web.1  | [writer]   TRANSACTION (0.0ms)  begin transaction
11:48:38 web.1  | [writer]   SolidQueue::Job Update (0.9ms)  UPDATE "solid_queue_jobs" SET "updated_at" = ?, "finished_at" = ? WHERE "solid_queue_jobs"."id" = ?  [["updated_at", "2024-08-23 09:48:38.203409"], ["finished_at", "2024-08-23 09:48:38.203409"], ["id", 3470]]
11:48:38 web.1  | [writer]   SolidQueue::ClaimedExecution Destroy (0.0ms)  DELETE FROM "solid_queue_claimed_executions" WHERE "solid_queue_claimed_executions"."id" = ?  [["id", 3648]]
11:48:38 web.1  | [writer]   TRANSACTION (0.1ms)  commit transaction
wdiechmann commented 1 month ago

Starting off of a fresh file (or rather, a salvaged development.sqlite3 with all solidqueue* tables truncated) this is what greets me:

12:13:39 web.1  | [writer]   SolidQueue::RecurringTask Upsert (0.4ms)  INSERT INTO "solid_queue_recurring_tasks" ("key","schedule","command","class_name","arguments","queue_name","priority","static","description","created_at","updated_at") VALUES ('background_job_scheduler', 'every minute', NULL, 'BackgroundManagerJob', NULL, NULL, 0, 1, NULL, STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW'), STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW')) ON CONFLICT ("key") DO UPDATE SET updated_at=(CASE WHEN ("schedule" IS excluded."schedule" AND "command" IS excluded."command" AND "class_name" IS excluded."class_name" AND "arguments" IS excluded."arguments" AND "queue_name" IS excluded."queue_name" AND "priority" IS excluded."priority" AND "static" IS excluded."static" AND "description" IS excluded."description") THEN "solid_queue_recurring_tasks".updated_at ELSE STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW') END),"schedule"=excluded."schedule","command"=excluded."command","class_name"=excluded."class_name","arguments"=excluded."arguments","queue_name"=excluded."queue_name","priority"=excluded."priority","static"=excluded."static","description"=excluded."description" RETURNING "id"
12:13:39 web.1  | [writer]   SolidQueue::RecurringTask Load (0.1ms)  SELECT "solid_queue_recurring_tasks".* FROM "solid_queue_recurring_tasks" WHERE "solid_queue_recurring_tasks"."key" = ?  [["key", "background_job_scheduler"]]
12:13:39 web.1  | SolidQueue-0.5.0 Started Dispatcher (31.2ms)  pid: 71480, hostname: "Walthers-MBAir-2.local", process_id: 955, polling_interval: 1, batch_size: 500, concurrency_maintenance_interval: 600, recurring_schedule: ["background_job_scheduler"]
12:13:39 web.1  | [writer]   SolidQueue::Semaphore Ids (0.4ms)  SELECT "solid_queue_semaphores"."id" FROM "solid_queue_semaphores" WHERE "solid_queue_semaphores"."expires_at" < ? ORDER BY "solid_queue_semaphores"."id" ASC LIMIT ?  [["expires_at", "2024-08-23 10:13:39.209446"], ["LIMIT", 500]]
12:13:39 web.1  | [writer]   SolidQueue::BlockedExecution Pluck (0.3ms)  SELECT DISTINCT "solid_queue_blocked_executions"."concurrency_key" FROM "solid_queue_blocked_executions" WHERE "solid_queue_blocked_executions"."expires_at" < ? LIMIT ?  [["expires_at", "2024-08-23 10:13:39.223082"], ["LIMIT", 500]]
12:13:39 web.1  | SolidQueue-0.5.0 Unblock jobs (4.5ms)  limit: 500, size: 0
12:13:39 css.1  | 
12:13:39 css.1  | Rebuilding...
12:13:40 css.1  | 
12:13:40 css.1  | Done in 576ms.
12:14:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.0ms)  begin transaction
12:14:00 web.1  | [ActiveJob] [writer]   SolidQueue::Job Create (0.2ms)  INSERT INTO "solid_queue_jobs" ("queue_name", "class_name", "arguments", "priority", "active_job_id", "scheduled_at", "finished_at", "concurrency_key", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) RETURNING "id"  [["queue_name", "default"], ["class_name", "BackgroundManagerJob"], ["arguments", "{\"job_class\":\"BackgroundManagerJob\",\"job_id\":\"262fd23e-d1a6-4b73-8046-68788d7cb7f4\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[],\"executions\":0,\"exception_executions\":{},\"locale\":\"da\",\"timezone\":\"UTC\",\"enqueued_at\":\"2024-08-23T10:14:00.045481000Z\",\"scheduled_at\":\"2024-08-23T10:14:00.045366000Z\"}"], ["priority", 0], ["active_job_id", "262fd23e-d1a6-4b73-8046-68788d7cb7f4"], ["scheduled_at", "2024-08-23 10:14:00.045366"], ["finished_at", nil], ["concurrency_key", "[FILTERED]"], ["created_at", "2024-08-23 10:14:00.052114"], ["updated_at", "2024-08-23 10:14:00.052114"]]
12:14:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
12:14:00 web.1  | [ActiveJob] [writer]   SolidQueue::Job Load (0.1ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3475], ["LIMIT", 1]]
12:14:00 web.1  | [ActiveJob] [writer]   SolidQueue::ReadyExecution Create (0.6ms)  INSERT INTO "solid_queue_ready_executions" ("job_id", "queue_name", "priority", "created_at") VALUES (?, ?, ?, ?) RETURNING "id"  [["job_id", 3475], ["queue_name", "default"], ["priority", 0], ["created_at", "2024-08-23 10:14:00.066350"]]
12:14:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
12:14:00 web.1  | [ActiveJob] Enqueued BackgroundManagerJob (Job ID: 262fd23e-d1a6-4b73-8046-68788d7cb7f4) to SolidQueue(default)
12:14:00 web.1  | [writer]   SolidQueue::RecurringExecution Insert (0.1ms)  INSERT INTO "solid_queue_recurring_executions" ("job_id","task_key","run_at","created_at") VALUES (3475, 'background_job_scheduler', '2024-08-23 10:14:00', STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW')) ON CONFLICT ("task_key","run_at") DO NOTHING RETURNING "id"
12:14:00 web.1  | [writer]   TRANSACTION (0.3ms)  commit transaction
12:14:00 web.1  | SolidQueue-0.5.0 Enqueued recurring task (49.0ms)  task: "background_job_scheduler", active_job_id: "262fd23e-d1a6-4b73-8046-68788d7cb7f4", at: "2024-08-23T10:14:00Z"
12:14:00 web.1  | [writer]   SolidQueue::Job Load (0.0ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 3475], ["LIMIT", 1]]
12:14:00 web.1  | [ActiveJob] [BackgroundManagerJob] [262fd23e-d1a6-4b73-8046-68788d7cb7f4] Performing BackgroundManagerJob (Job ID: 262fd23e-d1a6-4b73-8046-68788d7cb7f4) from SolidQueue(default) enqueued at 2024-08-23T10:14:00.045481000Z
12:14:00 web.1  | [ActiveJob] [BackgroundManagerJob] [262fd23e-d1a6-4b73-8046-68788d7cb7f4] Performed BackgroundManagerJob (Job ID: 262fd23e-d1a6-4b73-8046-68788d7cb7f4) from SolidQueue(default) in 0.56ms
12:14:00 web.1  | [writer]   TRANSACTION (0.0ms)  begin transaction
12:14:00 web.1  | [writer]   SolidQueue::Job Update (0.6ms)  UPDATE "solid_queue_jobs" SET "updated_at" = ?, "finished_at" = ? WHERE "solid_queue_jobs"."id" = ?  [["updated_at", "2024-08-23 10:14:00.166630"], ["finished_at", "2024-08-23 10:14:00.166630"], ["id", 3475]]
12:14:00 web.1  | [writer]   SolidQueue::ClaimedExecution Destroy (0.0ms)  DELETE FROM "solid_queue_claimed_executions" WHERE "solid_queue_claimed_executions"."id" = ?  [["id", 3653]]
12:14:00 web.1  | [writer]   TRANSACTION (0.1ms)  commit transaction

Telling me all is good and well 😄

rosa commented 1 month ago

Huh, this one is so strange, I had never seen it before. When you said:

when I throw it some work "manually", but somehow the SolidQueue::RecurringExecution Insert gets the wrong impression of the database...or I don't know

Do you mean when you enqueue jobs manually? And it breaks when jobs are enqueued because of your app running?

wdiechmann commented 1 month ago

I think it’s strange too - I mean when I start it fresh all is good - and even when the errors from the recurring job defined in the solid_queue.yml start showing up I can still enqueue jobs manually, so I don’t know what really happens but the recurring jobs obviously stop working Med venlig hilsenWaltherDen 24. aug. 2024 kl. 14.14 skrev Rosa Gutierrez @.***>: Huh, this one is so strange, I had never seen it before. When you said:

when I throw it some work "manually", but somehow the SolidQueue::RecurringExecution Insert gets the wrong impression of the database...or I don't know

Do you mean when you enqueue jobs manually? And it breaks when jobs are enqueued because of your app running?

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you authored the thread.Message ID: @.***>

wdiechmann commented 1 month ago

I'm not 100% sure - but close enough to risk closing this issue with a warning to anyone hitting this 'rabbit hole'

Do not let your dev run on localhost whilst 1) using any kind of backup/sync service like dropbox/one_drive/synology_drive/et al and 2) putting your localhost into sleep mode - or at least have this little "fixsqlite" readily at hand:

bin/fix.sql

.mode insert
.output dump_all.sql
.dump
# bin/fixsqlite
date=$(date +%d_%m_%Y)
cd ./storage
cp development.sqlite3 backup_development.sqlite3
mv development.sqlite3 corrupted_$date.sqlite3
touch dump_all.sql
rm -f dump_all.sql dump_all_notrans.sql
sqlite3 corrupted_$date.sqlite3 < ../bin/fix.sql
{ echo "PRAGMA synchronous = OFF ;"; cat dump_all.sql; } | grep -v -e TRANSACTION -e ROLLBACK -e COMMIT >dump_all_notrans.sql 
sqlite3 development.sqlite3 ".read dump_all_notrans.sql"
sqlite3 development.sqlite3 "PRAGMA integrity_check;"                                                                        
cd ..
rosa commented 1 month ago

@wdiechmann, may I ask whether you ran into this again and what your recurring task

background_job_scheduler

was doing?

wdiechmann commented 1 month ago

no - or rather I did but each time it's 99% sure that my dropbox or some other backup/sync thing was screwing up the file 'cause if I keep it fresh there is not a problem

as for the 'doing part':

sure - it's still some sandbox-y kind of stuff (eg the crude cron-ish thing will get swapped out for some real cron and what not), but the gist of it is that employees will setup events in a calendar to do some 'auto-punching' for them: as per EU regulation all workers are required to punch in/out - but danish work regulations are very tight as it is and most danish workers are in fact better protected than what the EU regulation proposes, so what we offer is a means to stay compliant, ie show digital trail of punching, with out the worker having to actually do it 😆

I know - it's humbug - but anyways, here's the config/solid_queue.yml

default: &default
  dispatchers:
    - polling_interval: 1
      batch_size: 500
      recurring_tasks:
        background_job_scheduler:
          interval: 60
          class: BackgroundManagerJob
          queue: default
          schedule: every minute
          enabled: true
  workers:
    - queues: "*"
      threads: 5
      processes: 1
      polling_interval: 0.1

development:
 <<: *default

test:
 <<: *default

production:
 <<: *default

and here is the BackgroundManagerJob class

class BackgroundManagerJob < ApplicationJob
  queue_as :default

  #
  # step 1 background jobs will be running 3 jobs
  #
  #   1: employee_state_job
  #   2: employee_eu_state_job
  #   3: employee_auto_punch_job
  #
  def perform
    dt = DateTime.current
    prepare_state_job if dt.hour == 5 and dt.min == 0
    prepare_eu_state_job if dt.hour == 5 and dt.min == 5
    prepare_auto_punch_job if dt.hour == 23 and dt.min == 50
    rescue => error
      UserMailer.error_report(error.to_s, "BackgroundManagerJob.perform").deliver_later
  end

  def prepare_state_job
    Account.all.each do |account|
      if account.employees.any?
        EmployeeStateJob.perform_later account: account
      end
    end
  end

  def prepare_eu_state_job
    Account.all.each do |account|
      if account.employees.any?
        EmployeeEuStateJob.perform_later account: account
      end
    end
  end

  def prepare_auto_punch_job
    Account.all.each do |account|
      if account.employees.any?
        EmployeeAutoPunchJob.perform_now account: account
      end
    end
    true
  end
end

and here is the EmployeeAutoPunchJob (the other two only pump emails out)

class EmployeeAutoPunchJob < ApplicationJob
  queue_as :default

  def perform(**args)
    super(**args)
    date=DateTime.current
    Employee.by_account.each do |employee|
      next if employee.did_punch(date)
      employee.punch_by_calendar(date)
    end
  end
end

and in case you're wondering what the super(**args) is doing - here is the ApplicationJob

class ApplicationJob < ActiveJob::Base
  include Alco::SqlStatements
  #
  # most jobs will need to know what account and user they are working with
  # - so jobs inheriting from this will call super(args)
  #
  def perform **args
    account = args[:account] || Account.find(args[:account_id]) rescue Account.first
    Current.account = account
  rescue => exception
    say exception
  end
  #
  # allow jobs to say what they need to say
  #
  def say(msg)
    Rails.logger.info { "----------------------------------------------------------------------" }
    Rails.logger.info { msg }
    Rails.logger.info { "----------------------------------------------------------------------" }
  end

  def switch_locale(locale = nil, &action)
    locale ||= (locale || I18n.default_locale)
    I18n.with_locale(locale, &action)
  end

  def user_time_zone(tz = nil, &block)
    timezone = tz || Current.user.time_zone || Current.account.time_zone rescue nil
    timezone.blank? ?
      Time.use_zone("Europe/Copenhagen", &block) :
      Time.use_zone(timezone, &block)
  end
end

and further, here is the SqlStatements

module Mortimer
  module Alco::SqlStatements
    #
    # returns an array of hashes representing the result (column => value)
    # or an ActiveRecord::Result object
    #
    def execute_statement(sql, return_hash = false)
      records = ActiveRecord::Base.connection.exec_query(sql)
      if return_hash
        records.entries
      else
        records
      end
    end
  end
end

and finally here is (part of) the Employee


    def did_punch(date)
      todays_punches(date: date).any?
    end

    def punch_by_calendar(date)
      all_calendars.each do |calendar|
        tz = calendar.time_zone
        calendar.events.each do |event|
          if event.occurs?({ from: date.beginning_of_week, to: date.end_of_week }, date, tz)
            from_at = DateTime.new date.year, date.month, date.day, event.from_time.hour, event.from_time.min, 0, tz
            to_at = DateTime.new date.year, date.month, date.day, event.to_time.hour, event.to_time.min, 0, tz
            reason = event.work_type
            ip = "calendar punch"
            PunchJob.new.punch_it!(self, reason, ip, from_at, to_at, event.comment)
          end
        end
      end
      Rails.env.local? ?
        PunchCardJob.perform_now(account: account, employee: self, date: date) :
        PunchCardJob.perform_later(account: account, employee: self, date: date)
      true
    rescue => error
      UserMailer.error_report(error.to_s, "Employee#punch_by_calendar").deliver_later
    end
rosa commented 1 month ago

Thank you so much for all the info, really appreciate it! 🙏 🙏

wdiechmann commented 1 month ago

context

I did as told in /environments/development.rb


  # Highlight code that enqueued background job in logs.
  config.active_job.queue_adapter = :solid_queue
  config.solid_queue.connects_to = { database: { writing: :writer, reading: :reader } }
  config.active_job.enqueue_after_transaction_commit = :never

if I Ctrl-C the dev and start it again, here is what I get:

19:50:22 web.1  | SolidQueue-0.5.0 Register Worker (18.0ms)  pid: 23903, hostname: "Walthers-MBAir-2.local", process_id: 1279
19:50:22 web.1  | SolidQueue-0.5.0 Started Worker (19.8ms)  pid: 23903, hostname: "Walthers-MBAir-2.local", process_id: 1279, polling_interval: 0.1, queues: "*", thread_pool_size: 5
19:50:22 web.1  | [writer]   SolidQueue::RecurringTask Upsert (0.3ms)  INSERT INTO "solid_queue_recurring_tasks" ("key","schedule","command","class_name","arguments","queue_name","priority","static","description","created_at","updated_at") VALUES ('background_job_scheduler', 'every minute', NULL, 'BackgroundManagerJob', NULL, NULL, 0, 1, NULL, STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW'), STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW')) ON CONFLICT ("key") DO UPDATE SET updated_at=(CASE WHEN ("schedule" IS excluded."schedule" AND "command" IS excluded."command" AND "class_name" IS excluded."class_name" AND "arguments" IS excluded."arguments" AND "queue_name" IS excluded."queue_name" AND "priority" IS excluded."priority" AND "static" IS excluded."static" AND "description" IS excluded."description") THEN "solid_queue_recurring_tasks".updated_at ELSE STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW') END),"schedule"=excluded."schedule","command"=excluded."command","class_name"=excluded."class_name","arguments"=excluded."arguments","queue_name"=excluded."queue_name","priority"=excluded."priority","static"=excluded."static","description"=excluded."description" RETURNING "id"
19:50:22 web.1  | [writer]   SolidQueue::RecurringTask Load (0.1ms)  SELECT "solid_queue_recurring_tasks".* FROM "solid_queue_recurring_tasks" WHERE "solid_queue_recurring_tasks"."key" = ?  [["key", "background_job_scheduler"]]
19:50:22 web.1  | SolidQueue-0.5.0 Started Dispatcher (33.2ms)  pid: 23902, hostname: "Walthers-MBAir-2.local", process_id: 1278, polling_interval: 1, batch_size: 500, concurrency_maintenance_interval: 600, recurring_schedule: ["background_job_scheduler"]
19:50:22 web.1  | [writer]   SolidQueue::Semaphore Ids (0.1ms)  SELECT "solid_queue_semaphores"."id" FROM "solid_queue_semaphores" WHERE "solid_queue_semaphores"."expires_at" < ? ORDER BY "solid_queue_semaphores"."id" ASC LIMIT ?  [["expires_at", "2024-09-06 17:50:22.424597"], ["LIMIT", 500]]
19:50:22 web.1  | [writer]   SolidQueue::BlockedExecution Pluck (0.1ms)  SELECT DISTINCT "solid_queue_blocked_executions"."concurrency_key" FROM "solid_queue_blocked_executions" WHERE "solid_queue_blocked_executions"."expires_at" < ? LIMIT ?  [["expires_at", "2024-09-06 17:50:22.441959"], ["LIMIT", 500]]
19:50:22 web.1  | SolidQueue-0.5.0 Unblock jobs (4.7ms)  limit: 500, size: 0
19:50:22 web.1  | [writer]   SolidQueue::Job Load (0.1ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 10629], ["LIMIT", 1]]
19:50:22 web.1  | [ActiveJob] [ActiveStorage::AnalyzeJob] [1dadecc0-732d-4b3a-a4b7-df9cd3747d41] [writer]   ActiveStorage::Blob Load (0.1ms)  SELECT "active_storage_blobs".* FROM "active_storage_blobs" WHERE "active_storage_blobs"."id" = ? LIMIT ?  [["id", 12], ["LIMIT", 1]]
19:50:22 web.1  | [ActiveJob] [ActiveStorage::AnalyzeJob] [1dadecc0-732d-4b3a-a4b7-df9cd3747d41] Performing ActiveStorage::AnalyzeJob (Job ID: 1dadecc0-732d-4b3a-a4b7-df9cd3747d41) from SolidQueue(default) enqueued at 2024-09-02T20:36:24.229809000Z with arguments: #<GlobalID:0x0000000107907998 @uri=#<URI::GID gid://mortimer/ActiveStorage::Blob/12>>
19:50:22 web.1  | objc[23903]: +[__NSCFConstantString initialize] may have been in progress in another thread when fork() was called.
19:50:22 web.1  | objc[23903]: +[__NSCFConstantString initialize] may have been in progress in another thread when fork() was called. We cannot safely call it or ignore it in the fork() child process. Crashing instead. Set a breakpoint on objc_initializeAfterForkError to debug.
19:50:23 css.1  | 
19:50:23 css.1  | Rebuilding...
19:50:23 web.1  | SolidQueue-0.5.0 Replaced terminated Worker (1.2ms)  pid: 23903, status: "no exit status set", pid_from_status: 23903, signaled: true, stopsig: nil, termsig: 6, hostname: "Walthers-MBAir-2.local"
19:50:23 web.1  | [writer]   TRANSACTION (0.0ms)  begin transaction
19:50:23 web.1  | [writer]   SolidQueue::Process Create (3.8ms)  INSERT INTO "solid_queue_processes" ("kind", "last_heartbeat_at", "supervisor_id", "pid", "hostname", "metadata", "created_at") VALUES (?, ?, ?, ?, ?, ?, ?) RETURNING "id"  [["kind", "Worker"], ["last_heartbeat_at", "2024-09-06 17:50:23.406183"], ["supervisor_id", 1277], ["pid", 23916], ["hostname", "Walthers-MBAir-2.local"], ["metadata", "{\"polling_interval\":0.1,\"queues\":\"*\",\"thread_pool_size\":5}"], ["created_at", "2024-09-06 17:50:23.411862"]]
19:50:23 web.1  | [writer]   TRANSACTION (0.1ms)  commit transaction
19:50:23 web.1  | SolidQueue-0.5.0 Register Worker (13.9ms)  pid: 23916, hostname: "Walthers-MBAir-2.local", process_id: 1280
19:50:23 web.1  | SolidQueue-0.5.0 Started Worker (15.9ms)  pid: 23916, hostname: "Walthers-MBAir-2.local", process_id: 1280, polling_interval: 0.1, queues: "*", thread_pool_size: 5
19:50:23 css.1  | 
19:50:23 css.1  | Done in 917ms.

(notice lines 12-13-ish where something goes awry - not sure what that is - but it looks like it recovers nicely [see below])

19:54:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.1ms)  begin transaction
19:54:00 web.1  | [ActiveJob] [writer]   SolidQueue::Job Create (20.1ms)  INSERT INTO "solid_queue_jobs" ("queue_name", "class_name", "arguments", "priority", "active_job_id", "scheduled_at", "finished_at", "concurrency_key", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) RETURNING "id"  [["queue_name", "default"], ["class_name", "BackgroundManagerJob"], ["arguments", "{\"job_class\":\"BackgroundManagerJob\",\"job_id\":\"706b6806-f3f9-4401-925d-b0a6a5a10ebc\",\"provider_job_id\":null,\"queue_name\":\"default\",\"priority\":null,\"arguments\":[],\"executions\":0,\"exception_executions\":{},\"locale\":\"da\",\"timezone\":\"UTC\",\"enqueued_at\":\"2024-09-06T17:54:00.010912000Z\",\"scheduled_at\":\"2024-09-06T17:54:00.010758000Z\"}"], ["priority", 0], ["active_job_id", "706b6806-f3f9-4401-925d-b0a6a5a10ebc"], ["scheduled_at", "2024-09-06 17:54:00.010758"], ["finished_at", nil], ["concurrency_key", "[FILTERED]"], ["created_at", "2024-09-06 17:54:00.012647"], ["updated_at", "2024-09-06 17:54:00.012647"]]
19:54:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
19:54:00 web.1  | [ActiveJob] [writer]   SolidQueue::Job Load (2.1ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 11631], ["LIMIT", 1]]
19:54:00 web.1  | [ActiveJob] [writer]   SolidQueue::ReadyExecution Create (0.2ms)  INSERT INTO "solid_queue_ready_executions" ("job_id", "queue_name", "priority", "created_at") VALUES (?, ?, ?, ?) RETURNING "id"  [["job_id", 11631], ["queue_name", "default"], ["priority", 0], ["created_at", "2024-09-06 17:54:00.044171"]]
19:54:00 web.1  | [ActiveJob] [writer]   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
19:54:00 web.1  | [ActiveJob] Enqueued BackgroundManagerJob (Job ID: 706b6806-f3f9-4401-925d-b0a6a5a10ebc) to SolidQueue(default)
19:54:00 web.1  | [writer]   SolidQueue::RecurringExecution Insert (0.4ms)  INSERT INTO "solid_queue_recurring_executions" ("job_id","task_key","run_at","created_at") VALUES (11631, 'background_job_scheduler', '2024-09-06 17:54:00', STRFTIME('%Y-%m-%d %H:%M:%f', 'NOW')) ON CONFLICT ("task_key","run_at") DO NOTHING RETURNING "id"
19:54:00 web.1  | [writer]   TRANSACTION (0.2ms)  commit transaction
19:54:00 web.1  | SolidQueue-0.5.0 Enqueued recurring task (41.2ms)  task: "background_job_scheduler", active_job_id: "706b6806-f3f9-4401-925d-b0a6a5a10ebc", at: "2024-09-06T17:54:00Z"
19:54:00 web.1  | [writer]   SolidQueue::Job Load (0.0ms)  SELECT "solid_queue_jobs".* FROM "solid_queue_jobs" WHERE "solid_queue_jobs"."id" = ? LIMIT ?  [["id", 11631], ["LIMIT", 1]]
19:54:00 web.1  | [ActiveJob] [BackgroundManagerJob] [706b6806-f3f9-4401-925d-b0a6a5a10ebc] Performing BackgroundManagerJob (Job ID: 706b6806-f3f9-4401-925d-b0a6a5a10ebc) from SolidQueue(default) enqueued at 2024-09-06T17:54:00.010912000Z
19:54:00 web.1  | [ActiveJob] [BackgroundManagerJob] [706b6806-f3f9-4401-925d-b0a6a5a10ebc] Performed BackgroundManagerJob (Job ID: 706b6806-f3f9-4401-925d-b0a6a5a10ebc) from SolidQueue(default) in 0.9ms
19:54:00 web.1  | [writer]   TRANSACTION (0.1ms)  begin transaction
19:54:00 web.1  | [writer]   SolidQueue::Job Update (0.9ms)  UPDATE "solid_queue_jobs" SET "updated_at" = ?, "finished_at" = ? WHERE "solid_queue_jobs"."id" = ?  [["updated_at", "2024-09-06 17:54:00.133159"], ["finished_at", "2024-09-06 17:54:00.133159"], ["id", 11631]]
19:54:00 web.1  | [writer]   SolidQueue::ClaimedExecution Destroy (0.0ms)  DELETE FROM "solid_queue_claimed_executions" WHERE "solid_queue_claimed_executions"."id" = ?  [["id", 11965]]
19:54:00 web.1  | [writer]   TRANSACTION (0.1ms)  commit transaction
wdiechmann commented 1 month ago

Thank you so much for all the info, really appreciate it! 🙏 🙏

ohh @rosa it's me thanking you for all the hard work you put into this! Without open source we'd all still be fighting DLL hell on those pesky windoze machines with no remedies to aid 😄

keep up the wonderful work - and reach out if I can do anything / test anything plz!