Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Already on GitHub? Sign in to your account

Added what seems to be all that is needed to get this working for Rails ... #14

Closed
wants to merge 1 commit into
from

Conversation

Projects
None yet
3 participants

erkki123 commented Jul 2, 2013

...and ActiveRecord 4.0.0.

Collaborator

mguymon commented Aug 14, 2013

This pull wont work with the latest changes. Ill try reworking with the latest.

Collaborator

mguymon commented Aug 14, 2013

I added a new branch rails4 for adding support. Unfortunately it looks like there is a bug with Psyche and Arel when using a serialize column with ActiveRecord. Appears a collision on the count method that Psych is using and Arel is overriding.


The rspec output (run with -b):

 1) Auditing#snap #snap should serialize model
     Failure/Error: let(:tree) { Tree.create :name => 'a graspy vine', plants: [weed] }
     ArgumentError:
       wrong number of arguments (2 for 1)
     # /home/zinger/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/arel-4.0.0/lib/arel/expressions.rb:3:in `count'
     # /home/zinger/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:225:in `binary?'
     # /home/zinger/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:234:in `visit_String'
     # /home/zinger/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /home/zinger/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /home/zinger/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'

@mguymon mguymon referenced this pull request Aug 14, 2013

Merged

Rails4 support #26

@mguymon mguymon closed this Aug 14, 2013

I have the impression I am still seeing this problem in Rails 4.0.0 and Rails 4.0.1
(I did not see this problem in Rails 3.2.15 but now hitting it when migrating to Rails 4; also on
simpler hashes, I do not see the problem)

The debug code and the hash that I am trying to dump and the result shown below:

35 def log_message(action, log_data)
36   puts "AAA"
37   puts log_data.inspect
38   puts log_data.class
39   puts "BBB"
40    yaml = YAML.dump(log_data)
41    puts "CCC"
...
✗ rspec -b ./spec/models/order/factory_spec.rb:25 
...
AAA
{:order=>#<Order uuid: "a6be89c0-e073-4689-80a4-c8fcbc30c90b", name: "New Year's Eve deal", description: "Pizza and beer", order_status_id: 53, bms_fridge: "6934", bms_freezer: "1245", bms_normal_temp: "0723", amount_fund_type_id: 22, amount: #<BigDecimal:7fe735d98950,'0.7E1',9(27)>, deliver_fund_type_id: 22, delivery_price: #<BigDecimal:7fe73414d9d0,'0.0',9(36)>, service_provider_fund_type_id: 22, service_provider_price: #<BigDecimal:7fe735d98950,'0.7E1',9(27)>, resident_id: "ffcd474a-0ab7-43c5-b0aa-d8dd28e9619d", service_provider_id: "764fa4d7-dca1-41c7-91f0-738a9437b95b", created_at: "2013-11-12 16:42:48", updated_at: "2013-11-12 16:42:48", order_type_id: 10, order_date: "2011-12-27", req_delivery_date: "2012-01-01", req_delivery_time_range: "09:00:00..12:30:00", comment: "Call on gsm when delivered">, :order_items=>#<ActiveRecord::Associations::CollectionProxy [#<OrderItem order_id: "a6be89c0-e073-4689-80a4-c8fcbc30c90b", product_id: "a900a7c1-ab16-4113-80e7-5e7da689fc49", unit_id: 1, bms_type_id: 28, name: "Product name 1", description: "Product description", end_user_price: #<BigDecimal:7fe73410bb48,'0.7E1',9(45)>, fund_type_id: 22, created_at: nil, updated_at: nil, quantity: #<BigDecimal:7fe7345e7108,'0.2E1',9(36)>, uuid: "405b1084-8ed1-4509-acb0-ac09012ffe30", amount_billed: #<BigDecimal:7fe73410bb48,'0.7E1',9(45)>, comment: nil>]>}
Hash
BBB
F

Failures:

  1) Order factory is saved
     Failure/Error: order = FactoryGirl.create(:order)
     ArgumentError:
       wrong number of arguments (2 for 1)
     # /Users/peter_v/.rvm/gems/ruby-1.9.3-p448@...../gems/arel-4.0.1/lib/arel/expressions.rb:3:in `count'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:225:in `binary?'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:234:in `visit_String'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:313:in `block in visit_Array'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:313:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:313:in `visit_Array'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:293:in `block in visit_Hash'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:291:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:291:in `visit_Hash'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:293:in `block in visit_Hash'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:291:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:291:in `visit_Hash'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:67:in `push'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych.rb:242:in `dump'
     # ./lib/log_to_audit_file.rb:40:in `log_message'
...

Collaborator

mguymon commented Nov 12, 2013

So auditable is raising this error when you attempt to save a snapshot?

@mguymon yes indeed.

Building my model (FactoryGirl.build) is OK, but on the save, I have an after_save hook that will call my "log_message" function that triggers this issue.

Seems indeed to come from the yaml_tree implementation in Ruby 1.9.3. This code is in the ruby_1_9_3 branch
(that source code is from p470, which is not exactly the ruby p448 I am running in the tests, but close enough):

✗ pwd -P
/Users/peter_v/Documents/data/projects/ruby/ruby/ext/psych/lib/psych/visitors

➜  visitors git:(ruby_1_9_3) ✗ grep -A6 'def binary' yaml_tree.rb
      def binary? string
        string.encoding == Encoding::ASCII_8BIT ||
          string.index("\x00") ||
          string.count("\x00-\x7F", "^ -~\t\r\n").fdiv(string.length) > 0.3
      end
      private :binary?
...

➜  ruby git:(ruby_1_9_3) ✗ cat version.h
#define RUBY_VERSION "1.9.3"
#define RUBY_PATCHLEVEL 470

and naively instrumenting the "expressions.rb" implementation in Arel like this:

module Arel
  module Expressions
    def count (distinct = false, foo = 'bar')
      puts "DDD" * 20
      puts distinct.inspect
      puts foo.inspect
      puts "EEE" * 20
      Nodes::Count.new [self], distinct
    end
...

now yields this, which is similar to this original issue. With that naive debug patch, the ruby code gets on method call further, but then blocks on undefined fdiv method.

HTH ...

AAA
{:order=>#<Order uuid: "fe6a0b3e-2803-4c92-9c61-140fe47b3a3b", name: "New Year's Eve deal", description: "Pizza and beer", order_status_id: 53, bms_fridge: "6934", bms_freezer: "1245", bms_normal_temp: "0723", amount_fund_type_id: 22, amount: #<BigDecimal:7feca4f3f938,'0.7E1',9(27)>, deliver_fund_type_id: 22, delivery_price: #<BigDecimal:7feca944ab40,'0.0',9(36)>, service_provider_fund_type_id: 22, service_provider_price: #<BigDecimal:7feca4f3f938,'0.7E1',9(27)>, resident_id: "ffcd474a-0ab7-43c5-b0aa-d8dd28e9619d", service_provider_id: "1ac64fcd-e426-4343-936d-9f756785fdcd", created_at: "2013-11-12 17:14:41", updated_at: "2013-11-12 17:14:41", order_type_id: 10, order_date: "2011-12-27", req_delivery_date: "2012-01-01", req_delivery_time_range: "09:00:00..12:30:00", comment: "Call on gsm when delivered">, :order_items=>#<ActiveRecord::Associations::CollectionProxy [#<OrderItem order_id: "fe6a0b3e-2803-4c92-9c61-140fe47b3a3b", product_id: "13d4337c-5943-49af-806a-ce29404a3e62", unit_id: 1, bms_type_id: 28, name: "Product name 1", description: "Product description", end_user_price: #<BigDecimal:7feca4d12b60,'0.7E1',9(45)>, fund_type_id: 22, created_at: nil, updated_at: nil, quantity: #<BigDecimal:7feca96d6288,'0.2E1',9(36)>, uuid: "753d98a7-73c3-4713-81bf-d65828143b73", amount_billed: #<BigDecimal:7feca4d12b60,'0.7E1',9(45)>, comment: nil>]>}
Hash
BBB
DDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDD
"\x00-\x7F"
"^ -~\t\r\n"
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE
F

Failures:

  1) Order factory is saved
     Failure/Error: order = FactoryGirl.create(:order)
     NoMethodError:
       undefined method `fdiv' for #<Arel::Nodes::Count:0x007feca4f0db18>
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:225:in `binary?'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:234:in `visit_String'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:313:in `block in visit_Array'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:313:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:313:in `visit_Array'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:293:in `block in visit_Hash'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:291:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:291:in `visit_Hash'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:293:in `block in visit_Hash'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:291:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:291:in `visit_Hash'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:67:in `push'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych.rb:242:in `dump'
     # ./lib/log_to_audit_file.rb:40:in `log_message'
     # ./lib/log_to_audit_file.rb:31:in `block in log_to_audit_file'
     # ./lib/log_to_audit_file.rb:30:in `open'
     # ./lib/log_to_audit_file.rb:30:in `log_to_audit_file'
     # ./lib/log_to_audit_file.rb:18:in `log_create_to_audit_file'
...
Collaborator

mguymon commented Nov 12, 2013

So this is tricky, since the problem is outside of Auditable really. Appears the problem is caused when attempting to serialize an object with nested AR proxies. Is it possible to materialize all the references to AR in the object first, before passing it off?

I tried this (not sure if that is what you asked me to try ... more specific directions appreciated).

 def log_message(action, log_data)
    puts "AAA"
    puts log_data.inspect
    puts log_data.class
    puts "BBB"
    if log_data[:order]
      puts "HHH"
      puts log_data[:order].order_items.to_a
      puts "III"
    end

    if log_data[:order_items]
      puts "JJJ"
      puts log_data[:order_items].to_a
      puts "KKK"
    end

    yaml = YAML.dump(log_data)
    puts "CCC"

but still fails. There are other has_many and belongs_to associations from order and order_items ...
(but they are not logged in this call). This also has the debug puts in the expressions.rb present.

Thanks again !

AAA
{:order=>#<Order uuid: "28040d95-629c-4618-a04a-3749eecb820d", name: "New Year's Eve deal", description: "Pizza and beer", order_status_id: 53, bms_fridge: "6934", bms_freezer: "1245", bms_normal_temp: "0723", amount_fund_type_id: 22, amount: #<BigDecimal:7fee36f48e78,'0.7E1',9(27)>, deliver_fund_type_id: 22, delivery_price: #<BigDecimal:7fee3554f580,'0.0',9(36)>, service_provider_fund_type_id: 22, service_provider_price: #<BigDecimal:7fee36f48e78,'0.7E1',9(27)>, resident_id: "ffcd474a-0ab7-43c5-b0aa-d8dd28e9619d", service_provider_id: "e45e8769-09a0-4427-a2ca-d61381ccd56d", created_at: "2013-11-12 17:48:33", updated_at: "2013-11-12 17:48:33", order_type_id: 10, order_date: "2011-12-27", req_delivery_date: "2012-01-01", req_delivery_time_range: "09:00:00..12:30:00", comment: "Call on gsm when delivered">, :order_items=>#<ActiveRecord::Associations::CollectionProxy [#<OrderItem order_id: "28040d95-629c-4618-a04a-3749eecb820d", product_id: "61e320b9-0422-4f1e-a2d7-579b015d3f7e", unit_id: 1, bms_type_id: 28, name: "Product name 1", description: "Product description", end_user_price: #<BigDecimal:7fee33bbb420,'0.7E1',9(45)>, fund_type_id: 22, created_at: nil, updated_at: nil, quantity: #<BigDecimal:7fee355c8480,'0.2E1',9(36)>, uuid: "a3d70ab4-c938-4c81-8d23-2dae36a0e1bd", amount_billed: #<BigDecimal:7fee33bbb420,'0.7E1',9(45)>, comment: nil>]>}
Hash
BBB
HHH
#<OrderItem:0x007fee3bf3b8b8>
III
JJJ
#<OrderItem:0x007fee3bf3b8b8>
KKK
DDD
"\x00-\x7F"
"^ -~\t\r\n"
EEE
F

Failures:

  1) Order factory is saved
     Failure/Error: order.save!
     NoMethodError:
       undefined method `fdiv' for #<Arel::Nodes::Count:0x007fee355e5648>
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:225:in `binary?'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:234:in `visit_String'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:449:in `block in dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `each'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:447:in `dump_ivars'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:125:in `visit_Object'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:103:in `accept'
     # /Users/peter_v/.rvm/rubies/ruby-1.9.3-p448/lib/ruby/1.9.1/psych/visitors/yaml_tree.rb:313:in `block in visit_Array'
....
Collaborator

mguymon commented Nov 12, 2013

Try the following, which should tell you what part of the object is causing problems when being converted to Yaml:

log_data.each do |key,val|
  puts "Attempting to serialize #{key} of #{val.inspect}"
  begin
    YAML.dump(val)
    puts "  success"
  rescue
    puts "  failed due to #{$!}"
  end   
end

The following will materialize any collection proxies, which may be the culprit. Check for CollectionProxy before sending log_data to YAML.dump:

log_data.each do |key, val|
  if val.is_a?(ActiveRecord::Associations::CollectionProxy)
    log_data[key] = val.to_a
  end
end

Thanks for helping out, even if this is not really an issue of the auditable project.
Indeed, your debugging code revealed the problem more clearly.

Before the materialization:

Attempting to serialize order_items of #<ActiveRecord::Associations::CollectionProxy [#<OrderItem order_id: "7597bb03-beed-433c-a703-843c52cc4856", product_id: "ad8ec885-e44e-4cca-b569-47ad9c36ff31", unit_id: 1, bms_type_id: 28, name: "Product name 1", description: "Product description", end_user_price: #<BigDecimal:7fb945a3e5c0,'0.7E1',9(45)>, fund_type_id: 22, created_at: nil, updated_at: nil, quantity: #<BigDecimal:7fb947626170,'0.2E1',9(36)>, uuid: "fc20f148-2aab-4cdc-9060-6fdba5b999e8", amount_billed: #<BigDecimal:7fb945a3e5c0,'0.7E1',9(45)>, comment: nil>]>
  failed due to wrong number of arguments (2 for 1)

After materialization (replacing the proxy with the materialized array) with

      if val.is_a?(ActiveRecord::Associations::CollectionProxy)
        log_data[key] = val.to_a
      end

the YAML.dump works on the array.

Attempting to serialize order_items of [#<OrderItem order_id: "7597bb03-beed-433c-a703-843c52cc4856", product_id: "ad8ec885-e44e-4cca-b569-47ad9c36ff31", unit_id: 1, bms_type_id: 28, name: "Product name 1", description: "Product description", end_user_price: #<BigDecimal:7fb945a3e5c0,'0.7E1',9(45)>, fund_type_id: 22, created_at: nil, updated_at: nil, quantity: #<BigDecimal:7fb947626170,'0.2E1',9(36)>, uuid: "fc20f148-2aab-4cdc-9060-6fdba5b999e8", amount_billed: #<BigDecimal:7fb945a3e5c0,'0.7E1',9(45)>, comment: nil>]
  success

I think this can be a work-around now for my log_message.

I tried to find a proper fix in Arel (e.g. trying without success rails/arel#169 ) but I failed to find a clean patch for Arel that would resolve this case properly.

Collaborator

mguymon commented Nov 12, 2013

Glad I could help

So, probably, the root cause was recently fixed (9 and 11 Nov 2013) in arel and is now available in the 4-0-stable branch in arel. See rails/arel#216 . Using this code in Gemfile, fixed it without the materialization :

gem 'arel', git: 'git://github.com/rails/arel.git', branch: '4-0-stable'
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment