dj-stripe icon indicating copy to clipboard operation
dj-stripe copied to clipboard

Duplicate event errors when receiving duplicate webhooks from Stripe

Open RaceDirectorsHQ opened this issue 4 years ago • 10 comments

Hi,

For a while now, we've been getting duplicate event errors on our webhook.

This is the full traceback and error:

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/backends/utils.py" in _execute
 84.                 return self.cursor.execute(sql, params)

The above exception (duplicate key value violates unique constraint "djstripe_event_stripe_id_key"
DETAIL:  Key (id)=(evt_1HJr21IYqDxf18x89cVYyoRP) already exists.
) was the direct cause of the following exception:

File "/app/.heroku/python/lib/python3.6/site-packages/django/core/handlers/exception.py" in inner
 34.             response = get_response(request)

File "/app/.heroku/python/lib/python3.6/site-packages/django/core/handlers/base.py" in _get_response
 115.                 response = self.process_exception_by_middleware(e, request)

File "/app/.heroku/python/lib/python3.6/site-packages/django/core/handlers/base.py" in _get_response
 113.                 response = wrapped_callback(request, *callback_args, **callback_kwargs)

File "/app/.heroku/python/lib/python3.6/site-packages/sentry_sdk/integrations/django/views.py" in callback
 52.             return old_callback(*args, **kwargs)

File "/app/.heroku/python/lib/python3.6/site-packages/sentry_sdk/integrations/django/views.py" in callback
 52.             return old_callback(*args, **kwargs)

File "/app/.heroku/python/lib/python3.6/site-packages/django/views/generic/base.py" in view
 71.             return self.dispatch(request, *args, **kwargs)

File "/app/.heroku/python/lib/python3.6/site-packages/django/utils/decorators.py" in _wrapper
 45.         return bound_method(*args, **kwargs)

File "/app/.heroku/python/lib/python3.6/site-packages/django/views/decorators/csrf.py" in wrapped_view
 54.         return view_func(*args, **kwargs)

File "/app/.heroku/python/lib/python3.6/site-packages/django/views/generic/base.py" in dispatch
 97.         return handler(request, *args, **kwargs)

File "/app/.heroku/python/lib/python3.6/site-packages/djstripe/views.py" in post
 35.         trigger = WebhookEventTrigger.from_request(request)

File "/app/.heroku/python/lib/python3.6/site-packages/djstripe/models/webhooks.py" in from_request
 117.             raise e

File "/app/.heroku/python/lib/python3.6/site-packages/djstripe/models/webhooks.py" in from_request
 103.                     obj.process(save=False)

File "/app/.heroku/python/lib/python3.6/site-packages/djstripe/models/webhooks.py" in process
 187.         self.event = Event.process(self.json_body)

File "/app/.heroku/python/lib/python3.6/site-packages/djstripe/models/core.py" in process
 1353.             ret = cls._create_from_stripe_object(data)

File "/app/.heroku/python/lib/python3.6/site-packages/djstripe/models/base.py" in _create_from_stripe_object
 436.             instance.save(force_insert=True)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/models/base.py" in save
 741.                        force_update=force_update, update_fields=update_fields)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/models/base.py" in save_base
 779.                 force_update, using, update_fields,

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/models/base.py" in _save_table
 870.             result = self._do_insert(cls._base_manager, using, fields, update_pk, raw)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/models/base.py" in _do_insert
 908.                                using=using, raw=raw)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/models/manager.py" in manager_method
 82.                 return getattr(self.get_queryset(), name)(*args, **kwargs)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/models/query.py" in _insert
 1186.         return query.get_compiler(using=using).execute_sql(return_id)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/models/sql/compiler.py" in execute_sql
 1335.                 cursor.execute(sql, params)

File "/app/.heroku/python/lib/python3.6/site-packages/raven/contrib/django/client.py" in execute
 127.             return real_execute(self, sql, params)

File "/app/.heroku/python/lib/python3.6/site-packages/sentry_sdk/integrations/django/__init__.py" in execute
 489.             return real_execute(self, sql, params)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/backends/utils.py" in execute
 67.         return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/backends/utils.py" in _execute_with_wrappers
 76.         return executor(sql, params, many, context)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/backends/utils.py" in _execute
 84.                 return self.cursor.execute(sql, params)

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/utils.py" in __exit__
 89.                 raise dj_exc_value.with_traceback(traceback) from exc_value

File "/app/.heroku/python/lib/python3.6/site-packages/django/db/backends/utils.py" in _execute
 84.                 return self.cursor.execute(sql, params)

Exception Type: IntegrityError at /stripe/webhook/
Exception Value: duplicate key value violates unique constraint "djstripe_event_stripe_id_key"
DETAIL:  Key (id)=(evt_1HJr21IYqDxf18x89cVYyoRP) already exists.

A consequence of that is that, although Djstripe objects are unpdated and kept in sync fine, our webhook handlers are not triggering. For example, if we have an action set up when a subscription is moved to past_due, like so:

@webhooks.handler('customer.subscription.updated')
def subscription_past_due(event, **kwargs):
    obj = event.data['object']
    prev_attrs = event.data['previous_attributes']
    previous_status = prev_attrs.get('status', None)
    if previous_status and obj['status'] == 'past_due':
       # do stuff

it never executes, although it works fine when calling the function manually with the relevant customer.subscription.updated event.

Environment:

  • dj-stripe version: 2.3.0
  • Your Stripe account's default API version: 2020-08-27
  • Database: Postgres 12.1
  • Python version: 3.6.0
  • Django version: 2.2.6

RaceDirectorsHQ avatar Sep 14 '20 10:09 RaceDirectorsHQ

Can you tell me the value of your DJSTRIPE_WEBHOOK_VALIDATION setting ("verify_signature", "retrieve_event" or unset)?

jleclanche avatar Sep 14 '20 10:09 jleclanche

Hi @jleclanche - Thanks for your help. I'm not settings DJSTRIPE_WEBHOOK_VALIDATION anywhere so it's whatever the default is.

RaceDirectorsHQ avatar Sep 14 '20 14:09 RaceDirectorsHQ

@RaceDirectorsHQ do you know why you're getting duplicate events?

If it's complaining that the event already exists, then the event has already been synced… which would most likely only happen with a webhook.

It's possible you're receiving the webhooks twice (maybe you set up two webhook endpoints?). It isn't supposed to crash, but in this case, you would still have the first webhook process triggering your bound events.

jleclanche avatar Sep 14 '20 18:09 jleclanche

To check you can take a look at your endpoints dashboard and verify if there's duplicate endpoints. More info the better.

jleclanche avatar Sep 14 '20 18:09 jleclanche

@jleclanche - I checked on Stripe and there's only one webhook endpoint.

The error I'm getting:

UniqueViolation: duplicate key value violates unique constraint "djstripe_event_stripe_id_key" DETAIL: Key (id)=(***) already exists.

suggests that the event is already created.

If there is a first event that comes through fine before the duplicate, my webhook handlers are not getting triggered. Would I need to import my webhook handlers in my AppConfig, same as for signals? I haven't done that so far, because I didn't see anything to that effect anywhere in the docs.

RaceDirectorsHQ avatar Sep 15 '20 06:09 RaceDirectorsHQ

You'd need to have them somewhere they can be found, yes. I do usually put them in apps.py.

There's three separate issues being described here:

  1. You have an event being created / detected twice, for a reason I'd like to understand.
  2. Your webhooks are not getting triggered
  3. The duplicate key violation causes a crash when the event is called again (I'm not sure what should happen, but it should be handled, not crashing)

jleclanche avatar Sep 16 '20 07:09 jleclanche

So I did two things that seem to have fixed both the duplicate event error and the webhooks not being triggered issue.

  1. I imported my webhook handlers file in my app's AppConfig like so:
class PaymentsConfig(AppConfig):
    name = 'payments'

    def ready(self):
        import payments.signals
        import payments.webhooks

I'm still not sure that's really needed there... I haven't come across such an instruction in the docs or elsewhere, but I just tried it because signals need to be imported that way and I guess webhooks work similarly, so it was worth a try.

  1. I upgraded my Heroku plan from the hobby plan that allows the server to sleep between requests to a paid one that doesn't. I noticed on my Stripe webhook dashboard that several events were timing out, which was probably because of the Heroku server taking time to come online. Since upgrading the server plan to one that doesn't sleep, all events come through without timeouts - and without duplicates.

It could be the case that somehow previously the event was being received at the webhook endpoint but without sending back a 200 response which may have caused Stripe to try again - hence the duplicate.

I'll keep an eye over the next few days, but it looks like these two tweaks may have taken care of my issues.

Thanks again for the help, @jleclanche

RaceDirectorsHQ avatar Sep 16 '20 11:09 RaceDirectorsHQ

signals need to be imported that way and I guess webhooks work similarly, so it was worth a try

It's more that, if they're not imported anywhere else, they simply won't be picked up. But I'm making a note of this and will try to clarify the documentation (I'm working on doc next week).

I upgraded my Heroku plan from the hobby plan that allows the server to sleep between requests to a paid one that doesn't. I noticed on my Stripe webhook dashboard that several events were timing out, which was probably because of the Heroku server taking time to come online. Since upgrading the server plan to one that doesn't sleep, all events come through without timeouts - and without duplicates.

Ok, yeah, this … makes sense, I think. It's basically causing an undefined state. I think an easy way to reproduce this might be to have two webhook endpoints going to the same dj-stripe instance.

I'll keep this issue open so we can solve this particular type of situation.

jleclanche avatar Sep 16 '20 21:09 jleclanche

Thanks a lot for your help, @jleclanche!

RaceDirectorsHQ avatar Sep 17 '20 05:09 RaceDirectorsHQ

@jleclanche This issue no longer seems relevant. Can be closed?

arnav13081994 avatar Sep 01 '22 17:09 arnav13081994