Received 3 IPNs for the same transaction, only one flagged as duplicate

[newearthmartin]

Hi!
I received 3 IPNs for the same transaction with the same data, but only one was flagged as duplicate. They have all the same transaction id and all the same payment status, and are all separated by one minute (3:00 am 3:01 am 3:02 am).

Only one got marked as duplicate so my system ended up processing the same payment twice.

[newearthmartin]

I manually executed the verify() method on the unflagged, second IPN and now it is correctly marked as duplicate txn_id.
I also manually executed that on the original IPN and it correctly remains unflagged.

So a workaround would be to call verify() again on every IPN received and check if it remains unflagged.

[spookylukey]

This sounds like a valid issue. The code here looks buggy for the case when you have out-of-order notification of IPNs:

django-paypal/paypal/standard/helpers.py

Lines 17 to 38 in 24d914b

	def duplicate_txn_id(ipn_obj):
	"""
	Returns True if a record with this transaction id exists and its
	payment_status has not changed.
	This function has been completely changed from its previous implementation
	where it used to specifically only check for a Pending->Completed
	transition.
	"""
	# get latest similar transaction(s)
	similars = (ipn_obj.__class__._default_manager
	.filter(txn_id=ipn_obj.txn_id)
	.exclude(id=ipn_obj.id)
	.exclude(flag=True)
	.order_by('-created_at')[:1])
	if len(similars) > 0:
	# we have a similar transaction, has the payment_status changed?
	return similars[0].payment_status == ipn_obj.payment_status
	return False

Could you check for your case that there were other IPNs with the same txn_id but different payment_status? Otherwise, we have to look further for the cause.

We should probably be instead checking for duplicate (txn_id, payment_status). I say "probably*, because that would involve trusting that PayPal are doing something sensible with how they send IPNs, or at least documented. Based on experience it's possible that neither are true...

[newearthmartin]

Clearly, the code above checks only if the latest similar IPN has the same payment status. If the latest has a different status but the previous has the same, it doesn't recognize it as duplicate.

So the question is why we make this difference and not just this?:

duplicates = (ipn_obj.__class__._default_manager 
    .filter(txn_id=ipn_obj.txn_id) 
    .exclude(id=ipn_obj.id) 
    .exclude(flag=True)
    .exclude(payment_status=ipn_obj.payment_status)                 
return duplicates.exists()

---

Still, it doesn't seem that that's what's going on here. If you look at the picture above, those are the only IPNs with that txn_id and all have the same payment_status. There are no other IPNs. After I ran verify() again (which calls duplicate_txn_id()) one that was unflagged (3:01 am) became flagged as duplicate.

So maybe it happened that the first two (3 am and 3:01 am) arrived concurrently?

Here is the picture after running verify() on them again: