Closed (duplicate)
Project:
Ubercart
Version:
6.x-2.7
Component:
Orders
Priority:
Normal
Category:
Support request
Assigned:
Unassigned
Reporter:
Created:
20 Apr 2012 at 03:59 UTC
Updated:
21 Apr 2012 at 01:21 UTC
We've had a handful of orders, about 1%, get moved directly to completed without intervention from the store admins.
Normally we expect the status to be payment received until we do something, of course. What I'm seeing is NOT the same as #1504592: Completes order prematurely where this was due to the products being non-shippable.
- Ubercart 2.7, Ubercart Views 6.x-3.2+0-dev (UC Views has been updated to stable version 3.2, but nothing in the release notes discusses something like that. I just mention it because it does impact order states).
- our products are shippable and marked as such
- the conditional action "Complete non-shippable order after payment received" is disabled
- this is intermittent. Items that normally show correctly as "payment received" will sometimes mysteriously end up as "completed" when first viewed by the store admins
- admins first noticed this on March 16, 2012
- happens with both Paypal Express Checkout orders and credit card orders, though most cases have been Paypal (about 5 Paypal and 1 CC transaction, which I think is disproportionately biased towards PP, but with this small a sample, not sure that means anything).
Any ideas on tracking this down would be most appreciated!
Comments
Comment #1
longwaveAre you using PayPal WPP or something else for the credit card transactions? (not that I think this is the problem, but good to get as much info as possible)
When this happens, is "payment received" ever recorded in the order/admin comments or order log?
Comment #2
ergophobe commentedHey longwave
1. Yup - Paypal WPP - meant to add that to the original. I was a bit unclear there. What I was trying to say is there are both payments marked as "Paypal" and payments marked as "Credit Card" and so, some cases where the IPN response comes into play and others where it does not.
We were seeing the problem with issue #1192018: Duplicate order notification e-mail, and duplicate stock decrement, which is now fixed. Don't know if they could be related, but we didn't see the issue I'm describing here until a fair bit after the fix was in for #1192018.
Something seems to have changed in March, but I'm not sure what it is.
2. is "payment received" ever recorded
Yup. Everything looks normal. Here's the log for one of the orders where this happened. The last comment in the admin comments (25 rez complete again) is by one of the store admins, user #25, initials REZ who manually added that comment to flag the order as having this problem.
It's intermittent and odd, but short of a "You idiot, you forgot to check this box" solution, I'm looking for ideas of things to monitor and ways to capture/retrieve data that might pin down what's causing this action to fire.
Thanks so much for your time!
Comment #3
longwaveWhat about in the "log" tab? (you may need to sanitize some data before reposting that information here)
Comment #4
longwaveAnd is there any difference at all in the orders where this occurred vs the orders that work as expected?
I am guessing this may be a race condition issue between PayPal IPNs and users clicking back to the site, but not really sure, and we are supposed to have tests to prove that these actions can occur in either order.
Comment #5
ergophobe commentedDoh! Idiot... finally looked at the logs tab. Now it gets interesting.
Looking through the logs for a number of orders, the store admin bumped a few orders from Payment Received to Processing at 10:19.
At 6:37 the next morning, he moved a couple of orders to "Complete" and noticed order 3102 was incorrectly labelled as complete.
Now here's the interesting part. This is the log for 3102.
Note the time stamp - it appears that it is being moved from Payment Received to Processing and then to Completed in one quick action.
So now you've got me on the track for some questions to ask of the store admins. I'll see if he can remember what he was doing at 12:20 that day and find out if this is indeed a bug or operator error (he initially thought operator error, but since noticing the problem says he's been paying extra close attention to make sure it is not. Hopefully that means he'll remember something about it too.)
It appears that when he changes it to Processing, it immediately fired twice. So the question is whether this is a glitch in the system or whether or not he pushed the submit button twice.
I will ask him how he is marking it complete (i.e. order by order or using UC View VBO) and verify that he did advance it to Processing on purpose. Once I have those answers, I'll get back to you.
Thanks for your help
Comment #6
ergophobe commentedOkay, some more feedback from the guys. A couple of things
1. When they move an order to Processing, it's usually done bulk using Views Bulk Operations Ubercart Views.
2. When they move an order to Completed, it is always done from the individual order screen on an order by order basis.
When I looked at the raw log entries in the database to get a little more granularity on the timestamp, I found two orders that had this happened. They both were moved from Payment Received to Processing and I think everyone agrees this was an intentional operation by the admin. But then two seconds later, they both got moved to Completed.
Here are the log entries. Two comments
- these are all the status changes for these two orders with the important one bolded
- these are all the status changes during that period for the store
So now I'm thinking this is perhaps a VBO or a UC Views issue, not a general Ubercart issue. Thoughts?
Comment #7
ergophobe commentedSince this has gotten long and with confusing info and it seems to be a UC Views or VBO issue, I'm closing this one as dupe and editing it down to reopen as #1541370: Move to next state moves orders two states