Closed tjozwik closed 3 years ago
Hi @tjozwik, the bit where the Task is deleted seems to be missing from the log, so I can't tell what its values were set to. Can you please create a log with that bit included?
Thanks for your reply, @mvz.
New log:
Running via Spring preloader in process 18184
Loading development environment (Rails 6.1.3.1)
2.7.2 :001 > Project.last.tasks
Project Load (0.4ms) SELECT "projects".* FROM "projects" WHERE "projects"."deleted_at" IS NULL ORDER BY "projects"."id" DESC LIMIT $1 [["LIMIT", 1]]
Task Load (0.5ms) SELECT "tasks".* FROM "tasks" WHERE "tasks"."deleted_at" IS NULL AND "tasks"."project_id" = $1 /* loading for inspect */ LIMIT $2 [["project_id", 2], ["LIMIT", 11]]
=> #<ActiveRecord::Associations::CollectionProxy [#<Task id: 11, created_at: "2021-04-24 22:44:58.533309000 +0000", updated_at: "2021-04-24 22:46:47.039178000 +0000", project_id: 2, deleted_at: nil>]>
2.7.2 :002 > Project.last.destroy
Project Load (1.1ms) SELECT "projects".* FROM "projects" WHERE "projects"."deleted_at" IS NULL ORDER BY "projects"."id" DESC LIMIT $1 [["LIMIT", 1]]
TRANSACTION (0.5ms) BEGIN
Task Load (0.4ms) SELECT "tasks".* FROM "tasks" WHERE "tasks"."deleted_at" IS NULL AND "tasks"."project_id" = $1 [["project_id", 2]]
Task Update All (0.7ms) UPDATE "tasks" SET deleted_at = '2021-04-24 22:47:20.197967' WHERE "tasks"."deleted_at" IS NULL AND "tasks"."id" = $1 [["id", 11]]
Project Update All (0.5ms) UPDATE "projects" SET deleted_at = '2021-04-24 22:47:20.200802' WHERE "projects"."deleted_at" IS NULL AND "projects"."id" = $1 [["id", 2]]
TRANSACTION (1.9ms) COMMIT
=> #<Project id: 2, created_at: "2021-04-18 11:10:19.333492000 +0000", updated_at: "2021-04-24 22:46:05.365023000 +0000", deleted_at: "2021-04-24 22:47:20.201914418 +0000">
2.7.2 :003 > Project.with_deleted.last.recover
Project Load (0.3ms) SELECT "projects".* FROM "projects" ORDER BY "projects"."id" DESC LIMIT $1 [["LIMIT", 1]]
TRANSACTION (0.3ms) BEGIN
Task Load (0.5ms) SELECT "tasks".* FROM "tasks" WHERE "tasks"."deleted_at" IS NOT NULL AND "tasks"."project_id" = $1 AND (tasks.deleted_at > '2021-04-24 22:45:20.200802') AND (tasks.deleted_at < '2021-04-24 22:49:20.200802') [["project_id", 2]]
Project Load (0.3ms) SELECT "projects".* FROM "projects" WHERE "projects"."deleted_at" IS NULL AND "projects"."id" = $1 LIMIT $2 [["id", 2], ["LIMIT", 1]]
Project Update (0.5ms) UPDATE "projects" SET "updated_at" = $1, "deleted_at" = $2 WHERE "projects"."id" = $3 [["updated_at", "2021-04-24 22:47:41.823478"], ["deleted_at", nil], ["id", 2]]
TRANSACTION (1.0ms) COMMIT
=> true
2.7.2 :004 > Project.last.tasks
Project Load (1.4ms) SELECT "projects".* FROM "projects" WHERE "projects"."deleted_at" IS NULL ORDER BY "projects"."id" DESC LIMIT $1 [["LIMIT", 1]]
Task Load (1.2ms) SELECT "tasks".* FROM "tasks" WHERE "tasks"."deleted_at" IS NULL AND "tasks"."project_id" = $1 /* loading for inspect */ LIMIT $2 [["project_id", 2], ["LIMIT", 11]]
=> #<ActiveRecord::Associations::CollectionProxy []>
After executing Task Load query (that was generated in the project recovery transaction), I can see that the task is matched properly. Anyway, it hasn't been updated and deleted_at
attribute still has the same value that had been set during the project deletion.
2.7.2 :007 > sql = 'SELECT "tasks".* FROM "tasks" WHERE "tasks"."deleted_at" IS NOT NULL AND "tasks"."project_id" = 2 AND (tasks.deleted_at > \'2021-04-24 22:45:20.200802\') AND (tasks.deleted_at < \'2021-04-24 22:49:20.200802\')'
=> "SELECT \"tasks\".* FROM \"tasks\" WHERE \"tasks\".\"deleted_at\" IS NOT NULL AND \"tasks\".\"project_id\" = 2 AND (tasks.dele...
2.7.2 :008 > result = ActiveRecord::Base.connection.execute(sql)
(0.5ms) SELECT "tasks".* FROM "tasks" WHERE "tasks"."deleted_at" IS NOT NULL AND "tasks"."project_id" = 2 AND (tasks.deleted_at > '2021-04-24 22:45:20.200802') AND (tasks.deleted_at < '2021-04-24 22:49:20.200802')
=> #<PG::Result:0x000056080e9070b0 status=PGRES_TUPLES_OK ntuples=1 nfields=13 cmd_tuples=1>
2.7.2 :009 > result.to_a
=> [{"id"=>11, "created_at"=>2021-04-24 22:44:58.533309 UTC, "updated_at"=>2021-04-24 22:46:47.039178 UTC, "project_id"=>2, "deleted_at"=>2021-04-24 22:47:20.197967 UTC}]
I was able to reproduce this with an otherwise empty Rails app. What happens is that recovery of Task fails silently because the belongs_to
adds a validation that Project must exist. Since the Tasks are recovered before the Project, validation fails.
This problem did not surface in ActsAsParanoid's tests because Rails' default setting that makes belongs_to relations required by default is part of Rails and not of ActiveRecord: https://github.com/rails/rails/blob/8210d0a9d8a632fefc46b7b7d4b957b051a79d93/railties/lib/rails/application/configuration.rb#L91
I've created two ActiveRecord's models -
Project
andTask
. Each of them uses ActsAsParanoid with the datetimedeleted_at
column.I've created one project and one dependent task:
When I destroy created project, task is being correctly soft-deleted. Unfortunately, it is not recovered with its project, even if it matches the default two-minute recover window:
Shouldn't it be automatically recovered with the project? There is an information in Readme about recovering dependent records that suggests it should be recovered then: