Dear Users,
I noticed something strange lately, I have had 2 payments this week with paypal that did not complete. (but they are transfered correctly to my business paypal account, so the user payed correct.) I checked the log and i see the following message:
Type uc_paypal
Date Wednesday, January 2, 2013 - 22:54
User Anonymous
Location https://www.mydomainhere.com/uc_paypal/ipn/70150
Referrer
Message IPN failed with HTTP error , code 0.
Severity error
Hostname 173.0.81.1
I never had this before.. any idee? This happend suddenly, normally all paypal payments go well, i normally have around 10-20 payments with paypal a day, i didn't change anything on my VPS and i checked my firewall and can't find any issues.
(to make it clear, all payments go still well... but this error happends ±1 time a day, because it happend in 2 days 2 times.)
Comments
Comment #1
longwave"IPN failed with HTTP error , code 0." means that drupal_http_request() reported an error, and the error code was 0 - which isn't a valid HTTP error code. This shouldn't happen in normal operation, and I am not sure why it happened here, nor why it works for you most of the time. Are there any other errors recorded in the log around the same time?
Comment #2
JamesOakleyI just had this happen to me once.
@janton - what version of PHP are you using? The only server configuration change that I made recently is to upgrade from PHP 5.3 to PHP 5.4. Any explanation still leaves the erratic nature of the error in need of explanation, but it's the only change I can think of.
Comment #3
longwaveIf anyone can reproduce this, please reopen with more information - but I am not sure what we can do about it, it would appear to be either server specific or an issue at PayPal's end.
Comment #4
jamestombs CreditAttribution: jamestombs commentedWe get this occasionally too. We've had it twice in the last two days but have had hundreds of other transactions go through without a problem.
HTTP Access log has the following:
173.0.81.1 - - [06/Mar/2013:17:39:33 +0000] "POST /uc_paypal/ipn/127203 HTTP/1.0" 200 -
No errors reported from PHP/Apache.
PayPal IPN history shows the below:
So as far as PHP/Apache and PayPal are concerned the payment went through fine and there were no HTTP errors.
Comment #5
longwaveAre you also on 6.x-2.x? Can you post the watchdog entry as well? Is there anything else in the watchdog around the same time that looks relevant? I am guessing this is a (very) intermittent connection failure back to PayPal that will be practically impossible to reproduce, I wonder if we can do anything to mitigate against it in code though.
Comment #6
jamestombs CreditAttribution: jamestombs commentedInitial entry
Error
Nothing else in watchdog around that time nor anything in HTTP access log.
We are using 2.x-dev although it is an old version (26 Aug 2011). A few minor changes had to be made to various Ubercart modules including PayPal to save additional data which is just adding the following below the $order being loaded.
Then that data is processed elsewhere. I can probably update our dev site with the latest dev version but that won't really help with such an intermittent issues.
I have updated the PayPal module to have the following:
I will update the issue when the next one comes through.
Comment #7
longwaveThank you for helping debug this, I'm interested to know what the actual problem is here.
Comment #8
jamestombs CreditAttribution: jamestombs commentedJust had two in quick succession (within 1 min of each other).
Watchdog entry (same for both):
I have put some extra code in to record $req which is passed through as the data variable in drupal_http_request(). Any other places where you would think debug code could be useful?
Comment #9
jamestombs CreditAttribution: jamestombs commentedHave added the following to drupal_http_request() within if (!$fp) {}. I suspect for whatever reason the socket isn't being opened.
watchdog('debug', 'fsockopen - failed to open the socket<br /><pre>'. print_r($uri, TRUE) .'</pre>', array(), WATCHDOG_ERROR);
Comment #10
jamestombs CreditAttribution: jamestombs commentedThat was quick, just had another one. fsockopen isn't working (although there are still other transactions going through between the errors).
Watchdog:
The request that is passed through looks fine.
Comment #11
longwavefsockopen() documentation says "If the value returned in errno is 0 and the function returned FALSE, it is an indication that the error occurred before the connect() call. This is most likely due to a problem initializing the socket."
So I wonder if this is a specific configuration issue with the server or network stack? Not sure what else we can do, except somehow add retry code around drupal_http_request() - but it feels like drupal_http_request() should handle this for us.
Comment #12
longwave#193073: drupal_http_request - socket not initialized also appears related to this, but won't directly deal with the problem you are seeing here.
Comment #13
jamestombs CreditAttribution: jamestombs commenteddrupal_http_request won't retry if the socket isn't opened. So I have updated the PayPal module to do a retry, but I'm not holding out much hope.
I guess the alternative would be to try using CURL (although the 6.x backport hasn't been recoded from the D7 version) rather than fsockopen.
Comment #14
jamestombs CreditAttribution: jamestombs commentedHad quite a few yesterday and they always fail on the second attempt too.
Have put some more code in to check to make sure that fsockopen is getting the right parameters.
Comment #15
jamestombs CreditAttribution: jamestombs commentedFinally got some more errors.
The data that fsockopen() is being passed is always the same whether it fails or completes so there is likely to be an underlying issue with PHP or a configuration issue, so I would suggest closing this issue as it doesn't appear to be an issue with the Ubercart code.
The alternative would be to use cURL or provide an option to use different services for the resending IPN data.
Comment #16
jamestombs CreditAttribution: jamestombs commentedRackspace have replied and think it may be down a soft-limit on Apache's file descriptor limit which we were close to when the last couple of errors occurred.
We will wait to see if that has stopped it, but it may be worth anyone else having the same issues to look in to increasing it.
Comment #17
jamestombs CreditAttribution: jamestombs commentedScrap that, still happening.
Comment #18
TR CreditAttribution: TR commentedcURL has to use fsockopen() as well, so that's nota solution. I was going to suggest looking at your server resource limits - file descriptors are just one of the things aside from memory that are limited.
Comment #19
jamestombs CreditAttribution: jamestombs commentedRackspace have increased the limits again as apparently we were hitting the new limits even though they had been doubled from the default.
Comment #20
DanZ CreditAttribution: DanZ commentedWhat's causing all the open file descriptors? Just ordinary incoming connections? Are the connections closing promptly (and freeing up the descriptors)? Lsof might tell you something.
If you double the available descriptors and still use them up, it makes me think that they aren't getting freed up quickly enough.
This sounds like it's not directly related to Ubercart, but it's certainly interesting. I get rare customers randomly complaining that they get bumped back to the cart page after hitting the "Review order" button. They succeed when they try later. So, I wonder if a similar issue (but with Authorize.net) could be the culprit.
Comment #21
jamestombs CreditAttribution: jamestombs commentedWe've had another since so Rackspace have run some tests in a separate script using fsockopen() and have found that SSL addresses occasionally fail whereas non-SSL don't appear to have a problem.
They are going to update the server to see if an update to openSSL will solve the issue.
Comment #22
jamestombs CreditAttribution: jamestombs commentedUpdate of openSSL packages didn't work. Still investigating.
Comment #23
longwaveThanks for keeping us updated on this, I hope you eventually get to the bottom of it.
Comment #24
jamestombs CreditAttribution: jamestombs commentedMay have jumped the gun on the last one.
openSSL may have been the problem, not 100% sure yet. There was a single error the day after the update was done although there is no error in watchdog which is strange (I got notification through a custom script to email the error through).
Rackspace have run a test script through 5,000 then 10,000 iterations which was previously failing which is now working fine.
We will just have to wait to see if any more come in.
It's not a bad idea to make sure the OS is up to date anyway as I am sure there will be security fixes available for a lot of the software and an update to openSSL may (hopefully) have solved it.
Comment #25
jamestombs CreditAttribution: jamestombs commentedMarking this as fixed. We've had no problems for the last two weeks since openSSL has been updated.
Comment #26
longwaveThanks for the update, hopefully this will be a pointer for anyone else with the same issue. Out of interest, if you know the versions you upgraded from and to, that information might be helpful for anyone else.
Comment #27
jamestombs CreditAttribution: jamestombs commentedServer was updated from RHEL 5.6 to RHEL 5.8.
Current openSSL version is reported as 'OpenSSL 0.9.8e-fips-rhel5 01 Jul 2008'
Comment #28
jamestombs CreditAttribution: jamestombs commentedTypical. Spoke too soon, had another one at 21:32 last night.
Back to the start...
Comment #29
JamesOakleyI would have been surprised if updating OpenSSL had fixed this for every configuration, as I had it happen on a site that does not use SSL at all, so the IPN would not be sent over https. I'm no nearer to any explanation - but I'll keep following this thread in case the diagnostics move in a direction I can help with.
Comment #30
longwave@JamesOakley: The error is caused when Ubercart tries to acknowledge the IPN, which is always done over HTTPS, so it appears to be either a TCP socket or SSL client issue. The code in question:
Comment #31
JamesOakleyOK - that makes more sense now.
I've not had this for a while, but it's a very quiet store so that may not mean much. Is jamestamr's OpenSSL the most up to date for his version of RHEL?
As you can see, I'm on Centos 6.4, so the environment is not exactly the same, but it seem's there's a 1.0 release of OpenSSL, which is more recent than 0.9.8. It's worth a shot.
Comment #32
jamestombs CreditAttribution: jamestombs commentedRackspace have done another test of 10,000 iterations without issue. They have replied with the following:
Any thoughts on what can be done to try and get more verbose errors? The website is fairly busy so doing anything to PHP/Apache is likely to be a no-go.
Comment #33
longwaveYou have already added all the debugging code that is possible earlier in this issue, as far as I can tell. In #10 and #11 we tracked down the failure to somewhere inside PHP when fsockopen() is being called; it is returning FALSE or NULL instead of a valid pointer, but is not setting the error code or string, which suggests there was an error initialising the socket - however I have no idea how you would debug this further from within PHP, especially when it is intermittent.
Comment #34
longwaveIf this is OpenSSL related, perhaps #1879970: drupal_http_request fails when remote server is using openssl v1.0.0 is relevant?
Comment #35
jamestombs CreditAttribution: jamestombs commentedYou would have thought that it would fail every time, not sporadically.
We haven't had one since my last post.
Comment #36
longwaveStill not sure what caused this except a failure deep inside PHP or the network stack somewhere, and at this point I am pretty certain there is nothing we can do to prevent it in Ubercart, unfortunately.
Comment #37
jamestombs CreditAttribution: jamestombs commentedWe had two more shortly after my last post but none since then. There haven't been any server changes in that time nor updates to the PayPal/Ubercart code.
Comment #37.0
jamestombs CreditAttribution: jamestombs commentedspelling wrong
Comment #38
Anonymous (not verified) CreditAttribution: Anonymous commentedI started to have this same issue couple of days ago on 2 different sites on same hosting environment. Some orders goes trough but some will stay in state "in checkout" or "pending" in Ubercart, and "Completed" in Paypal.
What I get in Drupal logs are:
IPN failed with HTTP error Connection timed out, code -110.
Server ip: 173.0.81.1
Also this came today:
IPN failed with HTTP error error opening connection ssl://www.paypal.com:443, code 0.
What should I do? Can this be a problem in Paypal end or in my end? I think no server configuration settings have been done lately, atleast my hosting provider didnt inform any.
Settings are:
Drupal 7.26 Ubercart 7.x-3.6
Php 5.4.27
Apache/2.2.22 (Debian) DAV/2 mod_fcgid/2.3.9 mod_jk/1.2.37 mod_python/3.3.1 Python/2.7.3 mod_ssl/2.2.22 OpenSSL/1.0.1e mod_perl/2.0.7 Perl/v5.14.2
Comment #39
Anonymous (not verified) CreditAttribution: Anonymous commentedAgain after one week same error log from uc_paypal:
IPN failed with HTTP error .... ssl://www.paypal.com:443, code 0.
ip: 173.0.81.1
In paypal the payment is completed, but order is "pending" and user new role is not activated.
Can this be a hosting issue? I have Drupal on shared hosting.
Please somebody help..
Comment #40
daften CreditAttribution: daften at Picabit commentedWhat I got from my hosting provider (ubercart 7.x):
PayPal disabled SSLv3 in response to the "POODLE" vunerability. You'll have to switch the cURL request to use TLS 1.2 in order to use the PayPal sandbox. You can read more about this change at https://devblog.paypal.com/upcoming-security-changes-notice/
You can force the SSLVERSION to TLS 1.2 with the following command before any PayPal calls:
curl_setopt($curl, CURLOPT_SSLVERSION, 6);
Comment #41
JamesOakleyThat's true, @daften.
Although, as I understand it, that change from PayPal affects calls made from your website to PayPal.
The IPN problem is the other way - it affects calls that PayPal makes back to your website. So this change should not affect you.
... Except: They now only call IPN on SSL sites, so you'd need to make sure that your site can accept IPN calls over https. That said, if your site wasn't able to receive https traffic, PayPal IPNs would always fail, so that still wouldn't account for the problem in this issue whereby IPN can sometimes fail.