Comments (6)
Thanks for the logs.
We can see that in the first case meta rollback (SET LOCAL logidze.meta TO DEFAULT;
) happens right before the touch: true
triggered UPDATE
(and right after the first UPDATE
).
I will try to reproduce it in tests.
from logidze.
Interesting.
Could you please provide a bit more details? How do you define the responsible, how do you update records?
from logidze.
Models relation is 2 levels deep:
Production
class has_one :decision
, which in turn has_many :capas
, both with touch: true
. I am using accepts_nested_attributes_for
in both Decision
and CAPA
in order to be able to edit related decision and capas in one form.
ProductionsController#update
includes Logidze.with_responsible(current_user.id){@production.update(production_params)}
, which works as expected when there are any changes in the Production
instance. But in case there are no changes to production instance itself, update action is not storing _r
, which is not what I expect - by touching parent model I am updating updated_at
timestamp every time. Updated_at is stored in logidze history hash, but m => {_r}
tree is missing for production. Updated production child models do have metadata hash (only if there are changes in their respected instances, though).
Thanks for your help on the matter.
from logidze.
Thanks!
I have no ideas so far. The metadata is set for the whole block in the very beginning and used by all triggers.
One suggestion is to try log SQL queries and see what't happening under the hood.
Can you please drop the following line of code right before Logidze.with_responsible
and provide logs for both cases:
ActiveRecord::Base.logger = Logger.new(STDOUT)
?
from logidze.
Hi @palkan
Here's the log for update action when Production
instance child CAPA
instance date attribute is changed ONLY:
D, [2023-04-13T21:08:32.214082 #82826] DEBUG -- : TRANSACTION (0.1ms) BEGIN
D, [2023-04-13T21:08:32.214393 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block in update'
D, [2023-04-13T21:08:32.214600 #82826] DEBUG -- : (0.2ms) SET LOCAL logidze.meta = '{"_r":37}';
D, [2023-04-13T21:08:32.214813 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block in update'
D, [2023-04-13T21:08:32.216382 #82826] DEBUG -- : Nonconformity Load (0.1ms) SELECT "nonconformities".* FROM "nonconformities" WHERE "nonconformities"."reportable_id" = $1 AND "nonconformities"."reportable_type" = $2 LIMIT $3 [["reportable_id", 4], ["reportable_type", "Production"], ["LIMIT", 1]]
D, [2023-04-13T21:08:32.216742 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.217465 #82826] DEBUG -- : Decision Load (0.1ms) SELECT "decisions".* FROM "decisions" WHERE "decisions"."production_id" = $1 LIMIT $2 [["production_id", 4], ["LIMIT", 1]]
D, [2023-04-13T21:08:32.217830 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.218711 #82826] DEBUG -- : CAPA Load (0.2ms) SELECT "capas".* FROM "capas" WHERE "capas"."decision_id" = $1 AND "capas"."id" IN ($2, $3) [["decision_id", 4], ["id", 5], ["id", 6]]
D, [2023-04-13T21:08:32.219095 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.219983 #82826] DEBUG -- : Identification Load (0.1ms) SELECT "identifications".* FROM "identifications" WHERE "identifications"."production_id" = $1 AND "identifications"."id" IN ($2, $3) [["production_id", 4], ["id", 4], ["id", 5]]
D, [2023-04-13T21:08:32.220317 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.221044 #82826] DEBUG -- : WorkOrder Load (0.1ms) SELECT "work_orders".* FROM "work_orders" WHERE "work_orders"."nbr" = $1 LIMIT $2 [["nbr", "4499563_01"], ["LIMIT", 1]]
D, [2023-04-13T21:08:32.221283 #82826] DEBUG -- : ↳ app/models/production.rb:25:in `block in work_orders_attributes='
D, [2023-04-13T21:08:32.222042 #82826] DEBUG -- : WorkOrder Load (0.2ms) SELECT "work_orders".* FROM "work_orders" INNER JOIN "jobs" ON "work_orders"."id" = "jobs"."work_order_id" WHERE "jobs"."production_id" = $1 [["production_id", 4]]
D, [2023-04-13T21:08:32.222321 #82826] DEBUG -- : ↳ app/models/production.rb:28:in `work_orders_attributes='
D, [2023-04-13T21:08:32.223533 #82826] DEBUG -- : CACHE User Load (0.0ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" DESC LIMIT $2 [["id", 37], ["LIMIT", 1]]
D, [2023-04-13T21:08:32.223998 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.225046 #82826] DEBUG -- : Activity Load (0.1ms) SELECT "activities".* FROM "activities" WHERE "activities"."id" = $1 ORDER BY "activities"."id" ASC LIMIT $2 [["id", 3], ["LIMIT", 1]]
D, [2023-04-13T21:08:32.225532 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.226501 #82826] DEBUG -- : Reject Load (0.1ms) SELECT "rejects".* FROM "rejects" WHERE "rejects"."id" = $1 ORDER BY "rejects"."id" ASC LIMIT $2 [["id", 7], ["LIMIT", 1]]
D, [2023-04-13T21:08:32.226985 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.228029 #82826] DEBUG -- : Task Load (0.1ms) SELECT "tasks".* FROM "tasks" WHERE "tasks"."id" = $1 ORDER BY "tasks"."id" ASC LIMIT $2 [["id", 9], ["LIMIT", 1]]
D, [2023-04-13T21:08:32.228525 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.229905 #82826] DEBUG -- : User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" DESC LIMIT $2 [["id", 26], ["LIMIT", 1]]
D, [2023-04-13T21:08:32.230619 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.237555 #82826] DEBUG -- : CAPA Update (4.5ms) UPDATE "capas" SET "date" = $1 WHERE "capas"."id" = $2 [["date", "2023-04-27"], ["id", 6]]
D, [2023-04-13T21:08:32.238160 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:08:32.238833 #82826] DEBUG -- : (0.1ms) SET LOCAL logidze.meta TO DEFAULT;
D, [2023-04-13T21:08:32.239098 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block in update'
D, [2023-04-13T21:08:32.240971 #82826] DEBUG -- : Production Update (1.5ms) UPDATE "productions" SET "updated_at" = $1 WHERE "productions"."id" = $2 [["updated_at", "2023-04-13 19:08:32.238573"], ["id", 4]]
D, [2023-04-13T21:08:32.241331 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block in update'
D, [2023-04-13T21:08:32.241969 #82826] DEBUG -- : TRANSACTION (0.5ms) COMMIT
Log for a use case when Production
instance attribute is changed as well
D, [2023-04-13T21:16:15.913142 #82826] DEBUG -- : TRANSACTION (0.1ms) BEGIN
D, [2023-04-13T21:16:15.913570 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block in update'
D, [2023-04-13T21:16:15.913872 #82826] DEBUG -- : (0.2ms) SET LOCAL logidze.meta = '{"_r":37}';
D, [2023-04-13T21:16:15.914203 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block in update'
D, [2023-04-13T21:16:15.916658 #82826] DEBUG -- : Nonconformity Load (0.2ms) SELECT "nonconformities".* FROM "nonconformities" WHERE "nonconformities"."reportable_id" = $1 AND "nonconformities"."reportable_type" = $2 LIMIT $3 [["reportable_id", 4], ["reportable_type", "Production"], ["LIMIT", 1]]
D, [2023-04-13T21:16:15.917199 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.918229 #82826] DEBUG -- : Decision Load (0.2ms) SELECT "decisions".* FROM "decisions" WHERE "decisions"."production_id" = $1 LIMIT $2 [["production_id", 4], ["LIMIT", 1]]
D, [2023-04-13T21:16:15.918751 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.919995 #82826] DEBUG -- : CAPA Load (0.3ms) SELECT "capas".* FROM "capas" WHERE "capas"."decision_id" = $1 AND "capas"."id" IN ($2, $3) [["decision_id", 4], ["id", 5], ["id", 6]]
D, [2023-04-13T21:16:15.920587 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.921841 #82826] DEBUG -- : Identification Load (0.2ms) SELECT "identifications".* FROM "identifications" WHERE "identifications"."production_id" = $1 AND "identifications"."id" IN ($2, $3) [["production_id", 4], ["id", 4], ["id", 5]]
D, [2023-04-13T21:16:15.922314 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.923085 #82826] DEBUG -- : WorkOrder Load (0.1ms) SELECT "work_orders".* FROM "work_orders" WHERE "work_orders"."nbr" = $1 LIMIT $2 [["nbr", "4499563_01"], ["LIMIT", 1]]
D, [2023-04-13T21:16:15.923379 #82826] DEBUG -- : ↳ app/models/production.rb:25:in `block in work_orders_attributes='
D, [2023-04-13T21:16:15.924390 #82826] DEBUG -- : WorkOrder Load (0.3ms) SELECT "work_orders".* FROM "work_orders" INNER JOIN "jobs" ON "work_orders"."id" = "jobs"."work_order_id" WHERE "jobs"."production_id" = $1 [["production_id", 4]]
D, [2023-04-13T21:16:15.924776 #82826] DEBUG -- : ↳ app/models/production.rb:28:in `work_orders_attributes='
D, [2023-04-13T21:16:15.925854 #82826] DEBUG -- : CACHE User Load (0.0ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" DESC LIMIT $2 [["id", 37], ["LIMIT", 1]]
D, [2023-04-13T21:16:15.926417 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.927656 #82826] DEBUG -- : Activity Load (0.2ms) SELECT "activities".* FROM "activities" WHERE "activities"."id" = $1 ORDER BY "activities"."id" ASC LIMIT $2 [["id", 3], ["LIMIT", 1]]
D, [2023-04-13T21:16:15.928205 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.929109 #82826] DEBUG -- : Reject Load (0.2ms) SELECT "rejects".* FROM "rejects" WHERE "rejects"."id" = $1 ORDER BY "rejects"."id" ASC LIMIT $2 [["id", 7], ["LIMIT", 1]]
D, [2023-04-13T21:16:15.929627 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.930525 #82826] DEBUG -- : Task Load (0.1ms) SELECT "tasks".* FROM "tasks" WHERE "tasks"."id" = $1 ORDER BY "tasks"."id" ASC LIMIT $2 [["id", 9], ["LIMIT", 1]]
D, [2023-04-13T21:16:15.931039 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.937948 #82826] DEBUG -- : Production Update (5.9ms) UPDATE "productions" SET "updated_at" = $1, "qty_detected" = $2 WHERE "productions"."id" = $3 [["updated_at", "2023-04-13 19:16:15.931545"], ["qty_detected", "7"], ["id", 4]]
D, [2023-04-13T21:16:15.938326 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block (2 levels) in update'
D, [2023-04-13T21:16:15.939160 #82826] DEBUG -- : (0.1ms) SET LOCAL logidze.meta TO DEFAULT;
D, [2023-04-13T21:16:15.939402 #82826] DEBUG -- : ↳ app/controllers/productions_controller.rb:59:in `block in update'
D, [2023-04-13T21:16:15.939956 #82826] DEBUG -- : TRANSACTION (0.5ms) COMMIT
I am not sure if this will help to investigate my issue. In both cases meta is correctly set to m => { "_r" => 37}
, which is current_user.id
value. Perhaps this is a postgresql issue? I am on version 12.4 BTW.
from logidze.
I will try to reproduce it in tests.
Ok, it took me quite a time but I finally figured this out. See caf7d90
tl;dr touch: true
callbacks are executed after commits; since with_meta
wraps the execution into a transaction by default, changes made outside of it doesn't include the meta information. Solution? Use with_meta(x, transactional: false)
(as in the test) if possible.
from logidze.
Related Issues (20)
- Tracking changes on JSONB column error
- How to list all versions of a record? HOT 4
- Association versioning with ignore_log_data and at(version: ) doesn't return expected results HOT 5
- Partition-friendly logging (triggers) HOT 3
- JSONB column and switch_to! with append: true HOT 2
- PG::UndefinedFunction: ERROR: function hstore(model_name) does not exist HOT 1
- Meta per request HOT 1
- Logidze.ignore_log_data_by_default causing db:migrate errors HOT 2
- Responsible from different sources HOT 3
- Associations versioning - accessing versions with `at(version: #)` HOT 2
- How to tell logidze about a new column HOT 8
- GlobalID support for metadata
- reload_log_data doesn't work when used with acts_as_paranoid and deleted records HOT 2
- docs: logdize cannot set session meta data when using a connection pool HOT 1
- How can I get the last 100 versions of a model? regardless of the record HOT 2
- Saving log with only metadata changes HOT 1
- Not possible to use latest logidze and anyway_config with Ruby 3.3.0 HOT 1
- Make Sequel support independent from ActiveRecord and ActiveSupport
- Updating history when column names change HOT 3
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from logidze.