893126 - [traceback] IntegrityError in /bango/billing: duplicate transaction uuid in solitude

Status: RESOLVED FIXED

(Marketplace Graveyard :: Payments/Refunds, defect, P2)

Description

[Andy McKay]

In solitude on prod:

https://sentry.prod.solitude.allizomaws.com/amo/paymentsfirefoxcom/group/28/

Comment 1

[Kumar McMillan [:kumar]]

We made strides toward fixing this in bug 883453 but I suspected it wasn't a bullet proof solution.

Full traceback for convenience:

/bango/billing/: IntegrityError (1062, "Duplicate entry 'webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85' for key 'uuid'")
  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/tastypie/resources.py", line 192, in wrapper
    response = callback(request, *args, **kwargs)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/tastypie/resources.py", line 397, in dispatch_list
    return self.dispatch('list', request, **kwargs)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/solitude/solitude/base.py", line 285, in dispatch
    return super(BaseResource, self).dispatch(request_type, request, **kw)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/tastypie/resources.py", line 427, in dispatch
    response = method(request, **kwargs)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/tastypie/resources.py", line 1165, in post_list
    updated_bundle = self.obj_create(bundle, request=request, **self.remove_api_resource_names(kwargs))

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/solitude/lib/bango/resources/billing.py", line 129, in obj_create
    create.send(sender=self, bundle=bundle, data=create_data, form=form)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/dispatch/dispatcher.py", line 172, in send
    response = receiver(signal=self, sender=sender, **named)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/solitude/lib/transactions/models.py", line 137, in create_bango_transaction
    seller_product=seller_product)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/solitude/solitude/base.py", line 433, in safer_get_or_create
    return self.create(**kw), True

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/db/models/manager.py", line 137, in create
    return self.get_query_set().create(**kwargs)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/db/models/query.py", line 377, in create
    obj.save(force_insert=True, using=self.db)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/db/models/base.py", line 463, in save
    self.save_base(using=using, force_insert=force_insert, force_update=force_update)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/db/models/base.py", line 551, in save_base
    result = manager._insert([self], fields=fields, return_id=update_pk, using=using, raw=raw)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/db/models/manager.py", line 203, in _insert
    return insert_query(self.model, objs, fields, **kwargs)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/db/models/query.py", line 1593, in insert_query
    return query.get_compiler(using=using).execute_sql(return_id)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/db/models/sql/compiler.py", line 912, in execute_sql
    cursor.execute(sql, params)

  File "/data/solitude/www/payments.firefox.com/releases/1373574871-2013.07.11/venv/lib/python2.6/site-packages/django/db/backends/mysql/base.py", line 114, in execute
    return self.cursor.execute(query, args)

  File "/usr/lib64/python2.6/site-packages/MySQLdb/cursors.py", line 173, in execute
    self.errorhandler(self, exc, value)

  File "/usr/lib64/python2.6/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
    raise errorclass, errorvalue

Comment 2

[Kumar McMillan [:kumar]]

oddly enough it looks like two instances of this transaction were triggered simultaneously:

[[e-mail]1 07]$ grep webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85 2013-07-12
Jul 12 11:16:59 localhost6.localdomain: [] w.pay.tasks:INFO configuring payment in background for trans webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85 :/data/www/marketplace.firefox.com-webpay/webpay/webpay/pay/tasks.py:69
Jul 12 11:16:59 localhost6.localdomain: [] w.pay.tasks:INFO configuring payment in background for trans webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85 :/data/www/marketplace.firefox.com-webpay/webpay/webpay/pay/tasks.py:69
Jul 12 11:17:01 localhost6.localdomain: [] w.pay.tasks:INFO icon URL for webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85: https://marketplace.cdn.mozilla.net/product-icons/0/8.png :/data/www/marketplace.firefox.com-webpay/webpay/webpay/pay/tasks.py:140
Jul 12 11:17:01 localhost6.localdomain: [] w.pay.tasks:INFO icon URL for webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85: https://marketplace.cdn.mozilla.net/product-icons/0/8.png :/data/www/marketplace.firefox.com-webpay/webpay/webpay/pay/tasks.py:140
Jul 12 11:17:01 localhost6.localdomain: [] w.solitude:INFO transaction webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85: seller: 318 :/data/www/marketplace.firefox.com-webpay/webpay/lib/solitude/api.py:188
Jul 12 11:17:01 localhost6.localdomain: [] w.solitude:INFO transaction webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85: bango product: /bango/product/31/ :/data/www/marketplace.firefox.com-webpay/webpay/lib/solitude/api.py:199
Jul 12 11:17:01 localhost6.localdomain: [] w.solitude:INFO transaction webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85: seller: 318 :/data/www/marketplace.firefox.com-webpay/webpay/lib/solitude/api.py:188
Jul 12 11:17:01 localhost6.localdomain: [] w.solitude:INFO transaction webpay:93212ccf-2e25-40fa-b4e4-0aa355a3ff85: bango product: /bango/product/31/ :/data/www/marketplace.firefox.com-webpay/webpay/lib/solitude/api.py:199

Comment 3

[Andy McKay]

I wonder if that was a celery hiccup. Ideally celery tasks should be idempotent.

Comment 4

[Andy McKay]

This API is done by calling celery, I'm tempted to say that in this case we should raise a 419 error and let the client deal with it rather than a 500.

Comment 5

[Andy McKay]

https://github.com/mozilla/solitude/commit/d66384

Comment 6

[Kumar McMillan [:kumar]]

this is still happening intermittently in production 

https://sentry.prod.solitude.allizomaws.com/amo/paymentsfirefoxcom/group/28/

The user will see a payment spinner and the payment will never start so I'm bumping up priority

Comment 7

[Kumar McMillan [:kumar]]

The logs show that this is another case of the same transaction being configured in the same session, seconds apart. I think it is triggered by a specific logged in state on a repeat payment.

Comment 8

[Kumar McMillan [:kumar]]

proposed patch to solve this a little better https://github.com/mozilla/webpay/pull/222

Comment 9

[Kumar McMillan [:kumar]]

Fixed: https://github.com/mozilla/webpay/commit/b46e1599317c7582123dc1bbf192fe2253b0caaf