Problem or not? Incorrect integer value for column customer_notified

[robax]

Excellent.. I'll make a note to watch this file on the next upgrade.
Thanks heaps for this!

And thanks for your comments too Rod.
Rob

[robax]

hmm poop

I'm still seeing this error in the logs. It seems to be related to PayPal refunds.

[20-Mar-2015 12:33:42 Australia/Sydney] PHP Fatal error: 1366:Incorrect integer value: '' for column 'customer_notified' at row 1 :: INSERT INTO orders_status_history (orders_id, orders_status_id, date_added, comments, customer_notified) VALUES ('4125', '1', now(), 'PayPal status: Refunded @ 18:32:39 Mar 19, 2015 PDT
Parent Trans ID:xxxxxxxxxxxxxxxx
Trans ID:xxxxxxxxxxxxxxxxxxxx
Amount: -9.25 AUD', '') in C:\...............\includes\classes\db\mysql\query_factory.php on line 120


It looks like the error is recorded a number of times in a day and then it stops. Like it's on a schedule.

In fact, I can see rows on the PayPal IPN tab within Zen Cart that correspond to the errors.

It looks like there are about 16 entries for each refund. I would guess that PayPal limits the number of times it sends these.

It does look like the refunds work at PayPal, but are not recorded in the cart because I can't see any notes on the order saying so.

This store has been running for several years and the owner (my sister) has never said anything is wrong, but she might not know, and if the refunds are going back to the customer then that's fine.


So this time I downloaded a fresh ZC 1.5.1 zip and compared the file system. Everything appears to be intact, with only the OZPost module and various language changes showing up in WinMerge.

It is the case that my db is upgraded from as early as ZC 1.3.8.

So.. could this be something to do with upgrades over time, or possibly a PayPal configuration issue? I'm assuming that if it records the error as above, then it must be coming back to the right place from PayPal.. otherwise it'd record nothing at all.

Any idea are appreciated.
Regards
Rob

[RodG]

hmm poop
I'm still seeing this error in the logs. It seems to be related to PayPal refunds.

That 'fix' that swguy gave... You'll need to apply the same fix to other parts of the code that contain the

$db->Execute("insert into " . TABLE_ORDERS_STATUS_HISTORY

code call.

It looks like the error is recorded a number of times in a day and then it stops. Like it's on a schedule.

Just to be perfectly clear here, are you saying that these events DO NOT coincide with you (the store admin) submitting a PayPal Refund request?

It looks like there are about 16 entries for each refund. I would guess that PayPal limits the number of times it sends these.

It does look like the refunds work at PayPal, but are not recorded in the cart because I can't see any notes on the order saying so.

If you don't know anything about trying to provide PayPal refunds, this is starting to now look like you are seeing a possible hack/exploit attempt.

This store has been running for several years and the owner (my sister) has never said anything is wrong, but she might not know, and if the refunds are going back to the customer then that's fine.

But if those refunds shouldn't be going to *any* customer, then that's not fine.

So this time I downloaded a fresh ZC 1.5.1 zip and compared the file system. Everything appears to be intact, with only the OZPost module and various language changes showing up in WinMerge.

This will be the case if the V1.5.1 code has this bug/problem (which may or may not be fixed in V1.5.4)

It is the case that my db is upgraded from as early as ZC 1.3.8.

So.. could this be something to do with upgrades over time,

No.

or possibly a PayPal configuration issue?

No.

I'm assuming that if it records the error as above, then it must be coming back to the right place from PayPal.. otherwise it'd record nothing at all.

I had initially assumed that the events being logged would coincide with PP refunds being given, but based on these latest comments I'm assuming that this is probably some kind of exploit attempt, and for me, that changes things a lot. So much so that it is theoretically possible you may not even want to fix this bug on the basis that the fix may turn the failed exploit into a successful one.

As for the error being triggered and logged, my thoughts are that this is caused with one of the PHP/MySQL updates that have become a lot more restrictive in what rules can be 'broken' with no ill effect (such as the ability to use a NULL where an INT is expected). IOW, developers now need to take a little bit more care about validating user inputs before using them.

Cheers
RodG

[mc12345678]

That 'fix' that swguy gave... You'll need to apply the same fix to other parts of the code that contain the

$db->Execute("insert into " . TABLE_ORDERS_STATUS_HISTORY

code call.



Just to be perfectly clear here, are you saying that these events DO NOT coincide with you (the store admin) submitting a PayPal Refund request?



If you don't know anything about trying to provide PayPal refunds, this is starting to now look like you are seeing a possible hack/exploit attempt.



But if those refunds shouldn't be going to *any* customer, then that's not fine.



This will be the case if the V1.5.1 code has this bug/problem (which may or may not be fixed in V1.5.4)



No.



No.



I had initially assumed that the events being logged would coincide with PP refunds being given, but based on these latest comments I'm assuming that this is probably some kind of exploit attempt, and for me, that changes things a lot. So much so that it is theoretically possible you may not even want to fix this bug on the basis that the fix may turn the failed exploit into a successful one.

As for the error being triggered and logged, my thoughts are that this is caused with one of the PHP/MySQL updates that have become a lot more restrictive in what rules can be 'broken' with no ill effect (such as the ability to use a NULL where an INT is expected). IOW, developers now need to take a little bit more care about validating user inputs before using them.

Cheers
RodG

I was thinking that perhaps the "16" reoccurrences were like ipn updates that were failing and therefore notification of the initial refund was being tried again. But as well, can see the concern that possibly it is an attempted exploit... Maybe a way to filter to allow just one of the notifications to go through (small price or something) by some unique identifier to see the total result?

Or better yet, try installing lat9s mydebug backtrace plugin... The error messages should provide much more granularity of what section(s) of code are causing the error by identifying where the sql is that is "not correct".

[RodG]

I was thinking that perhaps the "16" reoccurrences were like ipn updates that were failing and therefore notification of the initial refund was being tried again.

You're probably right about the retries. but regardless of whether it was just one failed refund update or a hundred of them, the fact that they are occurring at all (and are not being instigated by the store owner) is cause for concern in this instance 'cos if it is an exploit attempt (and I'm a long way from being convinced it is) the error log would suggest that they had far more access to the DB than a hacker should have gotten.

Cheers
Rod.

[robax]

Thanks for the replies Rod and 'mc'

The refunds do correspond to a refund made by the store operator through the ZC admin. What I'm seeing with the repeated records in the debug logs are IPNs from PayPal telling the cart to record the refund. And it will likely send the IPN for a limited number of times, same as the IPN for payment fail/success is done.

The refund is not recorded in the order in Zen cart, although it does happen at PayPal. I think the error message about the incorrect integer value is probably correct and don't think it's a hack, but then I'm the fix should have worked as well.

I've searched the files for all instances of "TABLE_ORDERS_STATUS_HISTORY" and then looked for any instances associated with inserts into the table. This only exists in the orders.php which is the one I've already edited and then in the authorize.net and linkpoint gateways, which are not enabled and so I haven't edited them.

I don't really know PHP, but I'm going to see if putting '' around the -1 value in swguy's fix will make any difference. I noticed that the same line of code very nearby in orders.php has quotes around the value.

		  if ($customer_notified === '') { 
		  $customer_notified = '-1';
		  }

I'll see what happens.
Regards
ROb

[RodG]

The refunds do correspond to a refund made by the store operator through the ZC admin.

<phew>
This *is* what I was expecting to be the case though.

What I'm seeing with the repeated records in the debug logs are IPNs from PayPal telling the cart to record the refund. And it will likely send the IPN for a limited number of times, same as the IPN for payment fail/success is done.

The refund is not recorded in the order in Zen cart,

The refund not being recorded and the repeated attempts are probably both the result of the fatal PHP error.

I've searched the files for all instances of "TABLE_ORDERS_STATUS_HISTORY" and then looked for any instances associated with inserts into the table. This only exists in the orders.php which is the one I've already edited and then in the authorize.net and linkpoint gateways, which are not enabled and so I haven't edited them.

There are others.
/ipn_main_handler.phpline #344

        zen_db_perform(TABLE_ORDERS_STATUS_HISTORY, $sql_data_array);
        if (MODULE_PAYMENT_PAYPAL_ADDRESS_OVERRIDE == '1') {
          $sql_data_array['comments'] = '**** ADDRESS OVERRIDE ALERT!!! **** CHECK PAYPAL ORDER DETAILS FOR ACTUAL ADDRESS SELECTED BY CUSTOMER!!';
          $sql_data_array['customer_notified'] = -1;
          zen_db_perform(TABLE_ORDERS_STATUS_HISTORY, $sql_data_array);

/includes/modules/payment/paypal/paypal_functions.php
line#643

$sql_data_array = array('orders_id' => (int)$ordersID,
                            'orders_status_id' => (int)$new_status,
                            'date_added' => 'now()',
                            'comments' => 'PayPal status: ' . $_POST['payment_status'] . ' ' . ' @ ' . $_POST['payment_date'] . (($_POST['parent_txn_id'] !='') ? "\n" . ' Parent Trans ID:' . $_POST['parent_txn_id'] : '') . "\n" . ' Trans ID:' . $_POST['txn_id'] . "\n" . ' Amount: ' . $_POST['mc_gross'] . ' ' . $_POST['mc_currency'],
                            'customer_notified' => 0
                           );
    zen_db_perform(TABLE_ORDERS_STATUS_HISTORY, $sql_data_array);

/includes/modules/payment/paypaldp.php
line# 1344

$sql_data_array = array('orders_id' => (int)$oID,
                                'orders_status_id' => (int)$new_order_status,
                                'date_added' => 'now()',
                                'comments' => 'VOIDED. Trans ID: ' . urldecode($response['AUTHORIZATIONID']). $response['PNREF'] . (isset($response['PPREF']) ? "\nPPRef: " . $response['PPREF'] : '') . "\n" . $voidNote,
                                'customer_notified' => 0
                             );
        zen_db_perform(TABLE_ORDERS_STATUS_HISTORY, $sql_data_array);

/includes/modules/payment/paypalwpp.php
line#813

 $sql_data_array = array('orders_id' => $oID,
                                'orders_status_id' => (int)$new_order_status,
                                'date_added' => 'now()',
                                'comments' => 'REFUND INITIATED. Trans ID:' . $response['REFUNDTRANSACTIONID'] . $response['PNREF']. "\n" . /*' Net Refund Amt:' . urldecode($response['NETREFUNDAMT']) . "\n" . ' Fee Refund Amt: ' . urldecode($response['FEEREFUNDAMT']) . "\n" . */' Gross Refund Amt: ' . urldecode($response['GROSSREFUNDAMT']) . (isset($response['PPREF']) ? "\nPPRef: " . $response['PPREF'] : '') . "\n" . $refundNote,
                                'customer_notified' => 0 
                             );
        zen_db_perform(TABLE_ORDERS_STATUS_HISTORY, $sql_data_array);

I've bolded Two lines in the codes above because I happened to spot that this was different in the code from two different sites. I don't know if this was a change made by the zencart team, or whether its the change I made to resolve the same issue that you are having. In any case, the change was making the '0' into a 'false' (in the 1st instance) and the '0' to a '-1' (in the second instance).
As far as PHP in concerned a 'false' and a -1 are the same value.

I don't really know PHP, but I'm going to see if putting '' around the -1 value in swguy's fix will make any difference. I noticed that the same line of code very nearby in orders.php has quotes around the value.

          if ($customer_notified === '') { 
          $customer_notified = '-1';
          }

I'll see what happens.
Regards
ROb

Because the database defines the customer_notified field as being an integer then it is best/safer to NOT enclose this data with quotes. In *most* cases it won't make a difference either way.

I am a little bit concerned about the if ($customer_notified === '') check though, because the triple === is explicitly checking for an empty string '', which may or may not match if the $customer_notified variable is undefined or a NULL string.
Since you probably wish to match either/all of these, then a double == would probably be a better option.

Anyway, based on the error log that you provided earlier, the only place that I can see that would cause this exact error would be via the /includes/modules/payment/paypal/paypal_functions.php file.
line#647 'customer_notified' => 0
change to 'customer_notified' => false

I'm not convinced that this *will* fix your problem (because a 0 should be an acceptable value), but this change has apparently been made (either by myself, or the zencart team, for a reason) and it seems a little bit too coincidental that this is right around the area that you are having a problem.

Cheers
RodG