1.0.2 still raising undefined method `utc' for nil:NilClass

[ryaan-anthony]

I upgraded workarea-emarsys to 1.0.2 and still get this error for all emarsys requests:

NoMethodError: undefined method `utc' for nil:NilClass
  from escher/auth.rb:266:in `long_date'
  from escher/auth.rb:206:in `format_date_for_header'
  from escher/auth.rb:25:in `sign!'
  from workarea/emarsys/gateway.rb:55:in `sign_request'
  from workarea/emarsys/gateway.rb:19:in `create_contact'
  from workarea/emarsys/save_user.rb:19:in `perform'

NoMethodError: undefined method `utc' for nil:NilClass
  from escher/auth.rb:266:in `long_date'
  from escher/auth.rb:206:in `format_date_for_header'
  from escher/auth.rb:25:in `sign!'
  from workarea/emarsys/gateway.rb:55:in `sign_request'
  from workarea/emarsys/gateway.rb:19:in `create_contact'
  from workarea/emarsys/save_order.rb:19:in `perform'

[tubbo]

I ran one of the tests that hit the method that's blowing up in Escher. The debugger got called, and I was able to assert that the date passed in by our Gateway class is not nil. So I don't think the problem here lies within the codebase of this gem.

The Emarsys::SaveUser class is a Sidekiq worker I believe, can you verify that all Sidekiq workers are running the most up-to-date code on your server? My hunch is that one of your workers didn't get the update and is still running the older version of workarea-emarsys, where this was broken.

[ryaan-anthony]

It's 1.0.2 on sidekiq:

root@sidekiq-65f8677586-rjmm4:/workarea# grep emarsys Gemfile.lock
    workarea-emarsys (1.0.2)
  workarea-emarsys (~> 1.0.2)!```

[ryaan-anthony]

The tests are not failing, just the code.

[tubbo]

@ryaan-anthony In the code, it's current_time: Time.current, there's no way any kind of user input could mess this up. The #escher_options are passed into the Escher::Auth class when its instantiated, and the date is used further down in #sign! to actually complete the signing request. Unless Time.current is for some reason returning nil here, I'm still not convinced that this could be happening in the code, but not the tests.

Can you look in the sidekiq logs and see if there's a full backtrace pointing to the directory that the error occurs in? Should be like workarea-emarsys-1.0.1 or something.

[ryaan-anthony]

W, [2019-10-03T12:45:10.668610 #23280]  WARN -- : {"context":"Job raised exception","job":{"class":"Workarea::Emarsys::SaveUser","args":["5d0ab6af86fa89012a86169f"],"retry":true,"queue":"low","log_duplicate_payload":true,"enqueue_on":{"Workarea::User":"save"},"jid":"42d164eed2ab29a0b970ca7c","created_at":1569198248.7874284,"locale":"en","current_modifier_id":null,"site_id":"spell_aus","enqueued_at":1570121110.6519716,"error_message":"undefined method `utc' for nil:NilClass","error_class":"NoMethodError","failed_at":1569198248.8077958,"retry_count":21,"retried_at":1569926387.9449856},"jobstr":"{\"class\":\"Workarea::Emarsys::SaveUser\",\"args\":[\"5d0ab6af86fa89012a86169f\"],\"retry\":true,\"queue\":\"low\",\"log_duplicate_payload\":true,\"enqueue_on\":{\"Workarea::User\":\"save\"},\"jid\":\"42d164eed2ab29a0b970ca7c\",\"created_at\":1569198248.7874284,\"locale\":\"en\",\"current_modifier_id\":null,\"site_id\":\"spell_aus\",\"enqueued_at\":1570121110.6519716,\"error_message\":\"undefined method `utc' for nil:NilClass\",\"error_class\":\"NoMethodError\",\"failed_at\":1569198248.8077958,\"retry_count\":21,\"retried_at\":1569926387.9449856}"}
W, [2019-10-03T12:45:10.668678 #23280]  WARN -- : NoMethodError: undefined method `utc' for nil:NilClass
W, [2019-10-03T12:45:10.668713 #23280]  WARN -- : /workarea/vendored_gems/ruby/2.4.0/gems/escher-1.0.2/lib/escher/auth.rb:266:in `long_date'
/workarea/vendored_gems/ruby/2.4.0/gems/escher-1.0.2/lib/escher/auth.rb:206:in `format_date_for_header'
/workarea/vendored_gems/ruby/2.4.0/gems/escher-1.0.2/lib/escher/auth.rb:25:in `sign!'
/workarea/vendored_gems/ruby/2.4.0/gems/workarea-emarsys-1.0.2/app/lib/workarea/emarsys/gateway.rb:55:in `sign_request'
/workarea/vendored_gems/ruby/2.4.0/gems/workarea-emarsys-1.0.2/app/lib/workarea/emarsys/gateway.rb:19:in `create_contact'
/workarea/vendored_gems/ruby/2.4.0/gems/workarea-emarsys-1.0.2/app/workers/workarea/emarsys/save_user.rb:19:in `perform'
/workarea/vendored_gems/ruby/2.4.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:192:in `execute_job'
/workarea/vendored_gems/ruby/2.4.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:165:in `block (2 levels) in process'
/workarea/vendored_gems/ruby/2.4.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'
/workarea/vendored_gems/ruby/2.4.0/gems/workarea-sentry-1.3.3/app/middleware/workarea/sentry_context_middleware.rb:17:in `call'
/workarea/vendored_gems/ruby/2.4.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/workarea/vendored_gems/ruby/2.4.0/gems/workarea-multi_site-3.1.5/app/middleware/workarea/multi_site_server_middleware.rb:11:in `block in call'
/workarea/vendored_gems/ruby/2.4.0/gems/workarea-multi_site-3.1.5/lib/workarea/site.rb:77:in `with_current'
/workarea/vendored_gems/ruby/2.4.0/gems/workarea-multi_site-3.1.5/app/middleware/workarea/multi_site_server_middleware.rb:11:in `call'
/workarea/vendored_gems/ruby/2.4.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/workarea/vendored_gems/ruby/2.4.0/gems/sidekiq-throttled-0.8.2/lib/sidekiq/throttled/middleware.rb:14:in `call'
/workarea/vendored_gems/ruby/2.4.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/workarea/vendored_gems/ruby/2.4.0/gems/newrelic_rpm-6.6.0.358/lib/new_relic/agent/instrumentation/sidekiq.rb:33:in `block in call'

[tubbo]

ok thanks, there must be something going on with this gem i guess

[meowsus]

@ryaan-anthony v1.0.3 was just released to RubyGems.org and contains a fix for this issue. Sorry for the hassle!