Jump to content
Supertex

PayPal App v4.039 - double stock decrement

Recommended Posts

Twice now, my store has had the customer's return from PP and the IPN both land at the exact same time.  When this happens, stock is deducted twice.  

 

I'm no code whiz, but it -appears- that the catalog/ext/modules/payment/paypal/standard_ipn.php is missing the check that I find in catalog/includes/modules/payment/paypal_standard.php: 

// Before the stock quantity check is performed in checkout_process.php, detect if the quantity
// has already beed deducated in the IPN to avoid a quantity == 0 redirect
      if ( $this->enabled === true ) {
        if ( defined('FILENAME_CHECKOUT_PROCESS') && (basename($PHP_SELF) == FILENAME_CHECKOUT_PROCESS) ) {
          if ( tep_session_is_registered('payment') && ($payment == $this->code) ) {
            $this->pre_before_check();
          }
        }
      }

I only noticed this because I happened to be watching when a customer purchased a quantity of 4 of one item.  We had 7 in stock prior to his purchase.  When his order completed, we had "-1".

 

post-292008-0-62221600-1427205753_thumb.jpg

 

Then again yesterday, I looked at the orders section and found a large order (many line items) in which every line item's stock count was double decremented.  I ended up having 4 products with negative quantities.

 

post-292008-0-95223900-1427205858_thumb.jpg

 

I have the store set NOT to allow checkout while out of stock.  And as I already mentioned, this ONLY happens when the customer's return and the IPN land at the exact same time.

 

Also, I feel sure this is in the IPN file, as I have both catalog/includes/modules/payment/paypal_standard.php and catalog/checkout_process.php commented out in order to leave products "active" when stock reaches zero, instead of disabling them completely.  I have not yet done this to the IPN file.  Since I'm getting negative quantities, it seems the culprit must be the IPN file:

            //if ( ($stock_left < 1) && (STOCK_ALLOW_CHECKOUT == 'false') ) {

              //tep_db_query("update " . TABLE_PRODUCTS . " set products_status = '0' where products_id = '" . tep_get_prid($order->products[$i]['id']) . "'");

            //}

This has only happened twice so far, that I know of.  But if it ever slips one past me, my inventory will be wrecked.  

 

I could sure use a hand here - I have no idea how this is happening. 

Share this post


Link to post
Share on other sites

@@Supertex

 

Hi, I believe, in theory, with PayPal Standard in the new PayPal App it is possible for order processing to happen twice. In practice it is probably extremely unlikely (there has to be immaculate timing?). I will try to explain what I believe happens, hopefully it will throw some light on your problem.
 
Final order processing can occur when PayPal sends the IPN back and/or when the customer returns to site.
 
When the IPN notification is returned from PayPal it should be directed to ext/modules/payment/paypal/standard_ipn.php (defined in line 359ish of paypal_atandard.php). Here, the status of the order in the orders table is checked (line 69ish), final order processing only continues if the status is equal to OSCOM_APP_PAYPAL_PS_PREPARE_ORDER_STATUS_ID (probably ‘1’ (Pending) in a standard setup).
 
When the customer returns to site (to checkout_process.php, defined in line 361ish of paypal_atandard.php), a new payment class is created, this executes ‘function pre_before_check()’. At the end of the function the status of the order in the order table is again checked (line 647ish) for OSCOM_APP_PAYPAL_PS_PREPARE_ORDER_STATUS_ID, if it is not equal (i.e. it has been updated) the final order processing in ‘function before_process()’ is bypassed.
 
To check this out, use the PayPal sandbox -
  1. note the values of OSCOM_APP_PAYPAL_PS_PREPARE_ORDER_STATUS_ID and OSCOM_APP_PAYPAL_PS_ORDER_STATUS_ID in the configuration table.
  2. create an order, before logging in to PayPal to make payment, check the status of the order – it should be OSCOM_APP_PAYPAL_PS_PREPARE_ORDER_STATUS_ID.
  3. after completing payment, before returning from PayPal but after the IPN has been sent (should be immediate), check the order status – it should be equal OSCOM_APP_PAYPAL_PS_ORDER_STATUS_ID (probably ‘2’ (Processing) in a standard setup) – there should also be a status history for the order visible in admin.
  4. if you want to check returning to site before the IPN is executed, rename ext/modules/payment/paypal/standard_ipn.php so that it is not found. Rename it back after you return from PayPal (the IPN will normally be sent again).
 
Your screen prints show that the status has been updated by the IPN (last line of comments is Source: IPN) and probably by checkout_process (last line of comments does not show Source: IPN).
 
Also beware: if a customer adds comments to an order, if they do not return to site from PayPal, the comments will be lost. The comments are not available to the IPN!

 

Share this post


Link to post
Share on other sites

Had another occurrence of something else that I've had happen a few times:  A disappearing order.  

 

It's not an issue with a null or zero status ...the order just disappears from the database entirely.  There was an IPN record in the logs, but no corresponding order.

 

Now I think I -might- have a clue as to how this happens:

 

Customer contacted me to ensure his order had been placed, because he'd gotten confused in PP's interface while trying to pay with CC.  It seems he accidentally followed a link to apply for a PP credit card.  Once he realized he was offtrack, he backed up, decided to pay with his PP account instead of a CC.  His payment completed, but he was shown 'an error.'  When he checked his PP account, he confirmed that I was sent his payment.  So he contacted me and I found no order - even running queries for the order number in multiple tables.  I refunded him in PP, and the refund showed up in the app logs too, but no record of the transaction other than that.

 

So...what happens in this scenario?  What conditions must be met in order for a customer return/IPN to delete an order?   If there was an error at paypal, why did the order status not simply remain "pending"?  Is it possible that because he navigated away from the normal 'path' of payment, that it flagged the order as having been subject to tampering?

Share this post


Link to post
Share on other sites

Hi - the PayPal Standard will delete an order:

function selection() {
      global $cart_PayPal_Standard_ID;

      if (tep_session_is_registered('cart_PayPal_Standard_ID')) {
        $order_id = substr($cart_PayPal_Standard_ID, strpos($cart_PayPal_Standard_ID, '-')+1);

        $check_query = tep_db_query('select orders_id from ' . TABLE_ORDERS_STATUS_HISTORY . ' where orders_id = "' . (int)$order_id . '" limit 1');

        if (tep_db_num_rows($check_query) < 1) {
          tep_db_query('delete from ' . TABLE_ORDERS . ' where orders_id = "' . (int)$order_id . '"');
          tep_db_query('delete from ' . TABLE_ORDERS_TOTAL . ' where orders_id = "' . (int)$order_id . '"');
          tep_db_query('delete from ' . TABLE_ORDERS_STATUS_HISTORY . ' where orders_id = "' . (int)$order_id . '"');
          tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS . ' where orders_id = "' . (int)$order_id . '"');
          tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS_ATTRIBUTES . ' where orders_id = "' . (int)$order_id . '"');
          tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS_DOWNLOAD . ' where orders_id = "' . (int)$order_id . '"');

          tep_session_unregister('cart_PayPal_Standard_ID');
        }
      }

and

 function confirmation() {
      global $cartID, $cart_PayPal_Standard_ID, $customer_id, $languages_id, $order, $order_total_modules;

      if (tep_session_is_registered('cartID')) {
        $insert_order = false;

        if (tep_session_is_registered('cart_PayPal_Standard_ID')) {
          $order_id = substr($cart_PayPal_Standard_ID, strpos($cart_PayPal_Standard_ID, '-')+1);

          $curr_check = tep_db_query("select currency from " . TABLE_ORDERS . " where orders_id = '" . (int)$order_id . "'");
          $curr = tep_db_fetch_array($curr_check);

          if ( ($curr['currency'] != $order->info['currency']) || ($cartID != substr($cart_PayPal_Standard_ID, 0, strlen($cartID))) ) {
            $check_query = tep_db_query('select orders_id from ' . TABLE_ORDERS_STATUS_HISTORY . ' where orders_id = "' . (int)$order_id . '" limit 1');

            if (tep_db_num_rows($check_query) < 1) {
              tep_db_query('delete from ' . TABLE_ORDERS . ' where orders_id = "' . (int)$order_id . '"');
              tep_db_query('delete from ' . TABLE_ORDERS_TOTAL . ' where orders_id = "' . (int)$order_id . '"');
              tep_db_query('delete from ' . TABLE_ORDERS_STATUS_HISTORY . ' where orders_id = "' . (int)$order_id . '"');
              tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS . ' where orders_id = "' . (int)$order_id . '"');
              tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS_ATTRIBUTES . ' where orders_id = "' . (int)$order_id . '"');
              tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS_DOWNLOAD . ' where orders_id = "' . (int)$order_id . '"');
            }

            $insert_order = true;
          }
        } else {
          $insert_order = true;
        }

So if the customer ends up on checkout_payment or checkout_confirmation with that session in place then the order gets zapped.

 

In checkout_confirmation another order then gets created - so you have a missing order number (slap on wrist if you get your accounts audited), sounds like your guy managed to get back to the store with the session intact somehow.

 

You could try a little tweak and, instead of deleting the order change it to a status of 'Paypal cancelled' or something - ideally that'd be done by way of another admin configuration entry but here's a quick and dirty idea:

 

Go to the admin create a new order status 'PayPal - cancelled' set that to viewable by the admin, invisible to the customer and no emails. Now you'll need to grab the id from the database and use it something like this:

        //comment out all the delete queries
        //  tep_db_query('delete from ' . TABLE_ORDERS . ' where orders_id = "' . (int)$order_id . '"');
        //  tep_db_query('delete from ' . TABLE_ORDERS_TOTAL . ' where orders_id = "' . (int)$order_id . '"');
        //  tep_db_query('delete from ' . TABLE_ORDERS_STATUS_HISTORY . ' where orders_id = "' . (int)$order_id . '"');
        //  tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS . ' where orders_id = "' . (int)$order_id . '"');
        //  tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS_ATTRIBUTES . ' where orders_id = "' . (int)$order_id . '"');
        //  tep_db_query('delete from ' . TABLE_ORDERS_PRODUCTS_DOWNLOAD . ' where orders_id = "' . (int)$order_id . '"');


        //now update the order status to 'hide' it from the customer

      $sql_data_array = array('orders_id' => $order_id,
                              'orders_status_id' => X,//where X=teh cancelled status id
                              'date_added' => 'now()',
                              'customer_notified' => (SEND_EMAILS == 'true') ? '1' : '0',
                              'comments' => 'PayPal pre order now cancelled');

      tep_db_perform(TABLE_ORDERS_STATUS_HISTORY, $sql_data_array);
      
      tep_db_query("update " . TABLE_ORDERS . " set orders_status = 'X', last_modified = now() where orders_id = '" . (int)$order_id . "'");

That should leave the order in a state that you can see it - it should not decrement inventory as that is handled elsewhere.

 

It will screw up your order /tax amounts if you don't do any sort of filtering so, if you want to zero the totals for this order try something like:

        //give the order total a value of 0.00
        // zap all the existing orders_total
        tep_db_query("delete from " . TABLE_ORDERS_TOTAL . " where orders_id = '" . $order_id. "'");
        // zero the orders_products
        tep_db_query("update " . TABLE_ORDERS_PRODUCTS . " set products_quantity = '0' where orders_id = '" . $order_id . "'");
        // now give an ot_total of zero
        tep_db_query("insert into " . TABLE_ORDERS_TOTAL. " (orders_id, title, text, value, class, sort_order) values ('" . $order_id . "', 'Total', '0.00', '0','ot_total', '99')");

That last chunk of code comes from an osC spinoff so there may be some tweaks needed and/or some other tables that you can zero so that the admin reports are not skewed. e.g. I'm not sure where this module updates the 'products_ordered' column in the products table so you'd need to check that out.

 

One other idea on your other post about the double decrement in quantities - you could just rely on the IPN callback to handle the quantities and comment out the code for the customer return?

Edited by Bob Terveuren

Share this post


Link to post
Share on other sites

Bob to the rescue!  Thank you so much for the reply.  A bit there to digest, but I'll get on it and see what I can make happen.

 

As far as commenting out the customer return,that's something I was considering, but was unsure of what side effects might come of it.  As trier mentioned...the comments are not handled by the IPN, and I do use the comments section often, so I don't know.

 

Leaving town for a few days tomorrow, but I'll hit this when I get back.

 

Again, thank you very much.

Share this post


Link to post
Share on other sites

Hi

 if ((DOWNLOAD_ENABLED != 'true') || (!$stock_values['products_attributes_filename'])) {
              $stock_left = $stock_values['products_quantity'] - $order->products[$i]['qty'];
            } else {
              $stock_left = $stock_values['products_quantity'];
            }
          //  tep_db_query("update " . TABLE_PRODUCTS . " set products_quantity = '" . (int)$stock_left . "' where products_id = '" . tep_get_prid($order->products[$i]['id']) . "'");
            if ( ($stock_left < 1) && (STOCK_ALLOW_CHECKOUT == 'false') ) {
             // tep_db_query("update " . TABLE_PRODUCTS . " set products_status = '0' where products_id = '" . tep_get_prid($order->products[$i]['id']) . "'");
            }

Looking at the payment module file - apply the two // comments to the two lines in before_process() - that will skip the changes to the product table but do all the other customer 'stuff' like comments/emails etc etc

 

Lines 134 - 138 in the ipn listener also handle quantity so your stock will reconcile

 

Where you have a decent IPN system (like PayPal) that will keep trying to ping your IPN listener then I'd use that every time to update the order/send the emails etc and just send the customer browser return to either checkout_success or checkout_payment(failed) as you can always guarantee that if there's a way of screwing the system then an innocent customer will find it (the old 'hey! What does this Big Red Button do? type of fella)

 

Of course if the PayPal IPn fails then your stock will not decrement - I'd suggest peeking at the IPN history in your Paypal account from time to time to see if there's any disasters in there (but then I'm a paranoid type of guy) but, on the whole, IPN from Paypal these days is pretty sound.

Share this post


Link to post
Share on other sites

This morning, I made the changes from post 5.  I had another order disappear on me...but this time I contacted my webhost with the date and time that the order was placed, and had them check the server log.  Here's what they found:

 

[Wed Jul 01 15:32:14 2015] [error] [client xxx.xxx.xxx.xxx] PHP Warning:  PHP Startup: Unable to load dynamic library '/usr/local/php53/lib/php/extensions/no-debug-non-zts-20090626/memcache.so' - /usr/local/php53/lib/php/extensions/no-debug-non-zts-20090626/memcache.so: cannot open shared object file: No such file or directory in Unknown on line 0, referer: https://www.mysite.com/checkout_shipping.php

 

The IP was in fact the IP of the customer.  This query, and the discovery of the error seems to have piqued a larger response from the webhost than usual.  I'm curious to see how this works out.  I really have no idea though, if this error has anything to do with the missing order.

 

I know in other cases, the customer was diverted by an ambiguous link in Paypal, that took him off course from checkout.  By the time he got back on track, finished the order, and landed back on our site, he was shown an error, and the system had deleted his order.

 

Not sure what happened on the paypal side of this latest transaction, but the fact that the server error log points to an event that occured after leaving checkout_shipping.php is interesting.

Share this post


Link to post
Share on other sites

/usr/local/php53/lib/php/extensions/no-debug-non-zts-20090626

 

That is a known cPanel problem (according to my host).  My own host suffered the same problem until they "fined" me for going over my webspace allowance ... until I pointed out that it was due to the error_log filling up 100s of megabytes daily of similar such errors.  Once I pointed it out, they were kind enough to refund me, and get all their servers patched.  I have to say though that I am not sure what the patch consisted of, how they did it or what they did. 


This is a signature that appears on all my posts.  
IF YOU MAKE A POST REQUESTING HELP...please state the exact version
of osCommerce that you are using. THANKS

 
Get the latest Responsive osCommerce CE (community edition) here

Share this post


Link to post
Share on other sites

Forgive my ignorance...

 

Do you happen to know enough about that error that you might see how it would be capable of causing an order deletion?  Or is the server error likely something that happens often (perhaps on every transaction), and the deletion is unrelated?

Share this post


Link to post
Share on other sites

No clue, sorry.


This is a signature that appears on all my posts.  
IF YOU MAKE A POST REQUESTING HELP...please state the exact version
of osCommerce that you are using. THANKS

 
Get the latest Responsive osCommerce CE (community edition) here

Share this post


Link to post
Share on other sites

@@Bob Terveuren

 

 

So if the customer ends up on checkout_payment or checkout_confirmation with that session in place then the order gets zapped.

 

In checkout_confirmation another order then gets created - so you have a missing order number (slap on wrist if you get your accounts audited), sounds like your guy managed to get back to the store with the session intact somehow.

 

So, is this a built-in redundancy?  It seems like I remember figuring out that normal order creation (money orders, for example) was handled by checkout_confirmation (or perhaps checkout_process?) but something about paypal required that an order ID be created sooner in the process, so for Paypal, orders were generated as the customer left checkout_payment.  Is the code you quoted designed to delete the 'premature' order_id and replace it with the one generated 'normally' (by checkout_confirmation)?

Share this post


Link to post
Share on other sites

 

@kymation @burt @Harald Ponce de Leon

This thread has gotten a bit off topic, but I'd like to pull back to the subject of the OP, and get the problem back on the table.  

I'm still seeing events where the customer return from PayPal, and the IPN land at the exact same time, or close enough that BOTH events trigger a stock decrement.  

Problem is, I only become aware when I see something odd, like a negative stock number, which shouldn't be possible - at least as a result of order completion.  This time, once I realized it happened again, I went back through the orders_status_history table, and looked for consecutive duplicate lines.  I only went back 6 months, but I found 5 instances where stock was hit for double...and only one of the 5 resulted in a negative number, or I'd never have known.  This is wreaking havoc on inventory numbers.

How can this be combated? I could see perhaps requesting a delay on the IPN dispatch from PP, but that would only really reduce the potential for this to happen...it's not really a 'fix'.

Like I mentioned...you can see this in the orders_status_history, because you get a double entry for "payment completed" for the same order ID/status.  If a query can be structured that will compare lines from the table and find any that match with the exception of the order_status_history_id, then a flag can be set and something added to the error/message stack on the admin that would at least provide an alert that it's occurred.

double-dec.jpg

For the record, the left and right half of the image are from different orders, but it still creates a clear picture of what's going on.

Edited by Supertex
explained the image

Share this post


Link to post
Share on other sites

@Supertex Shawn that's both interesting and troublesome. I don't think I've ever seen this.   I noticed in the image you posted that the SHIPPED status is shown twice too....is that just a coincidence?

Dan

 

Share this post


Link to post
Share on other sites

@Dan Cole  It is coincidence.  The site is integrated with Stamps.com, and it auto-updates status once a shipping label has printed, but I don't have it emailing the customer the status update automatically.  So in that case, in order for the customer to know the order shipped, a second 'shipped' status was issued with an email notification condition...note the checkmarks.

And yes, it's troublesome.  I'd seen it early on, but figured the chances of both events occurring that close to each other very often was slim.  I was wrong.  I've had issues with inventory for some time, and now I see why.  Like I said...the nasty part of this issue, is that you'd never know it was happening until you see something odd like a "-1" for an item quantity.  Now...the odds of the return and the IPN both landing in the same second, I would have thought was low.  The odds of it happening on an order where a quantity of 1 was ordered, and a quantity of only 1 was available...even lower...almost like getting hit by lightning twice.  So, that should indicate, at least to some degree, just how frequently this has to be occurring and NOT being noticed.  So far, just skimming over the DB tables, I see it occurring once a month, and one of those orders was 27 line items with quantities varying between 4 and 50.  This is a very real problem.

Share this post


Link to post
Share on other sites

@Supertex Shawn your idea of developing a query to see if you can identify when this occurs and perhaps how often it happens might be informative....I'm thinking that it could be used as an alert as you point out and perhaps a few of us could run it against our databases to see how much of an issue it actually is.  

Dan

Share this post


Link to post
Share on other sites

Going to try some things like this:

SELECT * FROM `orders_status_history` WHERE `orders_id` IN (
	SELECT `orders_id` FROM `orders_status_history` WHERE `customer_notified` =1 AND `orders_status_id`=2 HAVING count (`orders_id`) >1
) ORDER BY `orders_id`

Didn't work as I threw it together...got a #1630 'function db.count' does not exist.  I'll work on it more tomorrow.

Share this post


Link to post
Share on other sites

Just a thought

but if the ipn and return land at exactly the same time wouldn't you also get 2 x emails? which could alert you to the problem or am i way off?

 

Share this post


Link to post
Share on other sites

Perhaps.  However, I don't think I've ever gotten emails when an order is submitted...I wouldn't want any more emails than I'm getting already.  So either I saw that option very early on, and turned it off, or 2.3.1 doesn't have that option.

 

Share this post


Link to post
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now

×