tansengming/stripe-rails

undefined method `data' for []:Array

wonderer007 opened this issue · 11 comments

Stripe webhook call

POST /stripe/events

resulting in crash

NoMethodError (undefined method `data' for []:Array):
  path/ruby/2.3.0/gems/stripe-rails-1.9.1/app/models/stripe/event_dispatch.rb:6:in `block in dispatch_stripe_event'
  path/ruby/2.3.0/gems/stripe-rails-1.9.1/app/models/stripe/event_dispatch.rb:23:in `retrieve_stripe_event'
  path/ruby/2.3.0/gems/stripe-rails-1.9.1/app/models/stripe/event_dispatch.rb:5:in `dispatch_stripe_event'
  path/ruby/2.3.0/gems/stripe-rails-1.9.1/app/controllers/stripe/events_controller.rb:7:in `create'
  path/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
  path/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/abstract_controller/base.rb:198:in `process_action'
  path/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/rendering.rb:10:in `process_action'
  path/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
  path/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:117:in `call'

ruby 2.3.3
stripe 5.14.0
stripe-rails1.9.1

Hi @wonderer007 do you have more information about the webhook? It'll be great to have a payload to help with debug. How are you triggering the webhook?

I'm seeing the same issue in our application.
This is the only webhook we've implemented currently:

after_customer_subscription_deleted do |subscription, event|
    Subscription.find_by(stripe_subscription_id: subscription.id).cancel!
  end

API Version: config.stripe.api_version = '2019-09-09'
Signing_secret and other keys are in place.

Here's the raw stacktrace:

NoMethodError: undefined method `data' for []:Array
  from stripe/event_dispatch.rb:5:in `block in dispatch_stripe_event'
  from stripe/event_dispatch.rb:22:in `retrieve_stripe_event'
  from stripe/event_dispatch.rb:4:in `dispatch_stripe_event'
  from stripe/events_controller.rb:7:in `create'
  from action_controller/metal/basic_implicit_render.rb:4:in `send_action'
  from abstract_controller/base.rb:188:in `process_action'
  from action_controller/metal/rendering.rb:30:in `process_action'
  from abstract_controller/callbacks.rb:20:in `block in process_action'
  from active_support/callbacks.rb:126:in `call'
  from active_support/callbacks.rb:506:in `block (2 levels) in compile'
  from active_support/callbacks.rb:455:in `call'
  from active_support/callbacks.rb:448:in `block (2 levels) in around'
  from active_support/callbacks.rb:286:in `block (2 levels) in halting'
  from react/rails/controller_lifecycle.rb:31:in `use_react_component_helper'
  from active_support/callbacks.rb:382:in `block in make_lambda'
  from active_support/callbacks.rb:285:in `block in halting'
  from active_support/callbacks.rb:447:in `block in around'
  from active_support/callbacks.rb:455:in `call'
  from active_support/callbacks.rb:448:in `block (2 levels) in around'
  from active_support/callbacks.rb:286:in `block (2 levels) in halting'
  from route_translator/extensions/action_controller.rb:23:in `set_locale_from_url'
  from active_support/callbacks.rb:382:in `block in make_lambda'
  from active_support/callbacks.rb:285:in `block in halting'
  from active_support/callbacks.rb:447:in `block in around'
  from active_support/callbacks.rb:455:in `call'
  from active_support/callbacks.rb:448:in `block (2 levels) in around'
  from active_support/callbacks.rb:286:in `block (2 levels) in halting'
  from raven/integrations/rails/controller_transaction.rb:7:in `block in included'
  from active_support/callbacks.rb:391:in `instance_exec'
  from active_support/callbacks.rb:391:in `block in make_lambda'
  from active_support/callbacks.rb:285:in `block in halting'
  from active_support/callbacks.rb:447:in `block in around'
  from active_support/callbacks.rb:455:in `call'
  from active_support/callbacks.rb:101:in `__run_callbacks__'
  from active_support/callbacks.rb:750:in `_run_process_action_callbacks'
  from active_support/callbacks.rb:90:in `run_callbacks'
  from abstract_controller/callbacks.rb:19:in `process_action'
  from action_controller/metal/rescue.rb:20:in `process_action'
  from action_controller/metal/instrumentation.rb:32:in `block in process_action'
  from active_support/notifications.rb:164:in `block in instrument'
  from active_support/notifications/instrumenter.rb:21:in `instrument'
  from active_support/notifications.rb:164:in `instrument'
  from action_controller/metal/instrumentation.rb:30:in `process_action'
  from action_controller/metal/params_wrapper.rb:248:in `process_action'
  from searchkick/logging.rb:212:in `process_action'
  from active_record/railties/controller_runtime.rb:18:in `process_action'
  from abstract_controller/base.rb:126:in `process'
  from action_view/rendering.rb:30:in `process'
  from action_controller/metal.rb:190:in `dispatch'
  from action_controller/metal.rb:262:in `dispatch'
  from action_dispatch/routing/route_set.rb:50:in `dispatch'
  from action_dispatch/routing/route_set.rb:32:in `serve'
  from action_dispatch/journey/router.rb:39:in `block in serve'
  from action_dispatch/journey/router.rb:26:in `each'
  from action_dispatch/journey/router.rb:26:in `serve'
  from action_dispatch/routing/route_set.rb:727:in `call'
  from rails/engine.rb:522:in `call'
  from rails/railtie.rb:193:in `public_send'
  from rails/railtie.rb:193:in `method_missing'
  from action_dispatch/routing/mapper.rb:17:in `block in <class:Constraints>'
  from action_dispatch/routing/mapper.rb:46:in `serve'
  from action_dispatch/journey/router.rb:39:in `block in serve'
  from action_dispatch/journey/router.rb:26:in `each'
  from action_dispatch/journey/router.rb:26:in `serve'
  from action_dispatch/routing/route_set.rb:727:in `call'
  from action_dispatch/middleware/static.rb:136:in `call'
  from omniauth/strategy.rb:192:in `call!'
  from omniauth/strategy.rb:169:in `call'
  from ga_events/middleware.rb:11:in `call'
  from warden/manager.rb:36:in `block in call'
  from warden/manager.rb:34:in `catch'
  from warden/manager.rb:34:in `call'
  from rack/etag.rb:25:in `call'
  from rack/conditional_get.rb:38:in `call'
  from rack/head.rb:12:in `call'
  from rack/session/abstract/id.rb:232:in `context'
  from rack/session/abstract/id.rb:226:in `call'
  from action_dispatch/middleware/cookies.rb:613:in `call'
  from action_dispatch/middleware/callbacks.rb:38:in `block in call'
  from active_support/callbacks.rb:97:in `__run_callbacks__'
  from active_support/callbacks.rb:750:in `_run_call_callbacks'
  from active_support/callbacks.rb:90:in `run_callbacks'
  from action_dispatch/middleware/callbacks.rb:36:in `call'
  from action_dispatch/middleware/remote_ip.rb:79:in `call'
  from action_dispatch/middleware/debug_exceptions.rb:49:in `call'
  from action_dispatch/middleware/show_exceptions.rb:31:in `call'
  from rails/rack/logger.rb:36:in `call_app'
  from rails/rack/logger.rb:24:in `block in call'
  from active_support/tagged_logging.rb:69:in `block in tagged'
  from active_support/tagged_logging.rb:26:in `tagged'
  from active_support/tagged_logging.rb:69:in `tagged'
  from rails/rack/logger.rb:24:in `call'
  from request_store/middleware.rb:19:in `call'
  from action_dispatch/middleware/request_id.rb:24:in `call'
  from rack/method_override.rb:22:in `call'
  from rack/runtime.rb:22:in `call'
  from action_dispatch/middleware/executor.rb:12:in `call'
  from action_dispatch/middleware/static.rb:136:in `call'
  from rack/sendfile.rb:111:in `call'
  from raven/integrations/rack.rb:51:in `call'
  from rails/engine.rb:522:in `call'
  from puma/configuration.rb:225:in `call'
  from puma/server.rb:658:in `handle_request'
  from puma/server.rb:472:in `process_client'
  from puma/server.rb:332:in `block in run'
  from puma/thread_pool.rb:133:in `block in spawn_thread'

Hi @wonderer007 and @aarhusgregersen I've added some code on #181 to dump some debugging information to try to figure this out. Can you update your Gemfile to

gem 'stripe-rails', git: 'https://github.com/tansengming/stripe-rails', branch: 'feature/request-debug'

and let me know what it's showing on the log when the error happens? The log should look something like:

undefined method `data' for []:Array -- Request Params: {"id"=>"evt_00000000000001", \
"type"=>"customer.updated", "data"=>{"object"=>"customer", "fingerprint"=>"xxxyyyzzz"\
}, "controller"=>"stripe/events", "action"=>"create", "event"=>{"id"=>"evt_0000000000\
0001", "type"=>"customer.updated", "data"=>{"object"=>"customer", "fingerprint"=>"xxx\
yyyzzz"}}}

For the record I tried this out with the following API versions and didn't see any issues:

Ruby 2.6.2
stripe (5.17.0)
stripe-rails (1.9.1)
rails (5.2.4.2)

stripe_api 2018-09-24

image

stripe_api 2020-03-02

image

@tansengming thank you for getting back to me/us!
I feel like such a dumbass now. It seems this was due to wrong keys (specifically signing_secret) being set for the application, so it would error out instead of letting us know the key was wrong.
I changed the key and entirely forgot about responding to the issue here - hopefully, this might be the issue others are seeing too.

No worries @aarhusgregersen thanks for the update. I'll try to see if I can fix that error message.

More notes: when I tried using a webhook with an incorrect signing secret, the logs returned "No signatures found matching the expected signature for payload". So I still can't recreate the error.

2020-03-30T22:01:58.297358+00:00 app[web.1]: E, [2020-03-30T22:01:58.297226 #9] ERROR -- : [2dd5fe04-c7f5-4f6f-8163-a12ee46d05a9] No signatures found matching the expected signature for payload
2020-03-30T22:01:58.299484+00:00 app[web.1]: I, [2020-03-30T22:01:58.299400 #9]  INFO -- : [2dd5fe04-c7f5-4f6f-8163-a12ee46d05a9] Completed 400 Bad Request in 8ms

I'm sorry @tansengming I wish I could be of more help. I wish I remember what we changed to fix it, but I already forgot 😓

@aarhusgregersen no worries!

I'm gonna keep this issue open in case other folks are seeing this. Hopefully we'll get to the bottom of this one day.

I can shed some light on this since I ran into the same issue. The problem isn't having the wrong signing_secret but rather having a nil signing_secret.

In my code I was setting signing_secret (not signing_secrets) this way:

Rails.application.config.stripe.signing_secret = Rails.application.secrets.stripe_signing_secret

However, in development I don't have that variable set in my secrets configuration so it's akin to writing:

Rails.application.config.stripe.signing_secret = nil

Now when the stripe-rails devs changed to signing_secrets they maintained a method to set signing_secret= for compatibility:

# for backwards compatibility treat signing_secret as an alias for signing_secrets
def signing_secret=(value)
  self.signing_secrets = Array(value)
end

retrieve_stripe_event in app/models/stripe/event_dispatch.rb checks for the existence of signing_secrets to determine whether to process the webhook data as is or to ask Stripe for the data through the API:

  if Object.const_defined?('Stripe::Webhook') && sig_header && endpoint_secrets
    event = webhook_event(body, sig_header, endpoint_secrets)
  else
    event = Stripe::Event.retrieve(id)
  end

You'd think that if Rails.application.config.stripe.signing_secret is set to nil then the check on endpoint_secrets would fail and retrieve_stripe_event would just ask Stripe for the event, however, that's not the case. The call to Array(nil) in signing_secret= actually returns [] instead of nil which makes the if condition on the presence of endpoint_secrets pass. Note that this doesn't happen if signing_secret/signing_secrets are not set to begin with. ::Rails.application.config.stripe.signing_secrets in that case returns nil.

I'd suggest adding a guard clause to signing_secret=

  def signing_secret=(value)
    return if value.nil?

    self.signing_secrets = Array(value)
  end

I'm not sure if that would have other knock on effects so modifying the if condition in retrieve_stripe_event could be good enough.

TL;DR: Make sure you set Rails.application.config.stripe.signing_secret with a value that isn't nil.

Edits: The number of times I wrote singing_secret astounds me. At least it sounds nice.

thanks a bunch @martron this makes a lot of sense!

I'll be happy to merge any PR you want to make with your suggested changes, I think it should work!