XF 1.1 PayPal IPNs returning 500

Mopquill

Active member
I've gone through the whole setup, and I've read tons of threads on here, including this one. I'm trying to set things up to work with the PayPal sandbox so I can test an addon I'm developing for a client, and I've made and remade the paypal sandbox accounts, to no avail. I've also seen Jake's post regarding having debug mode on (I do), and I've tried allowing IPNs to be used based on the URI submitted, as well as filling it out manually (http://example.com/forum/payment_callback.php). I've disabled all httpd.conf / .htaccess rules (except the standard rules I use for security). I'm completely at a loss here. It might be some weird extenuating circumstance, or it might be something incredibly stupid that I'm overlooking, but, I'll take whatever I can get at this point.

At present, I have IPNs enabled in the seller's account, and pointed to http://example.com/forum/payment_callback.php . I again, have debug mode enabled, and the paypal email is properly set to the seller's paypal email in both the User Upgrades section, and the Debug Options section (though I believe those are the same setting). All addons are off- I'm trying to get this to work with vanilla XenForo before I even try enabling and debugging my add-on. Oh, and I'm on XenForo 1.1.2 on Apache 2

relevant portion of httpd.conf, personal info expunged:
Code:
<VirtualHost IP:80>
    ServerName example.com
    ServerAdmin example@example.com
    DocumentRoot /path/to/public_html
    UseCanonicalName OFF
    CustomLog /path/to/logs/example.com.log combined
    ErrorLog /path/to/logs/example.com.error.log
    <Directory /path/to/public_html>
        AllowOverride All
        Order Deny,Allow
        Allow from all
        Options IncludesNOEXEC -Indexes +SymLinksIfOwnerMatch
        php_admin_flag engine ON
        php_admin_value sendmail_path '/usr/sbin/sendmail -t -i -f example@example.com'
        php_admin_value open_basedir /path/to/one/dir/above/public_html/:/tmp:/usr/local/lib/php/
    </Directory>
</VirtualHost>

/path/to/public_html/.htaccess:
Code:
php_flag display_startup_errors on
php_flag display_errors 8191
php_flag html_errors on

/path/to/public_html/forums/.htaccess:
Code:
<IfModule mod_rewrite.c>
    RewriteEngine On
# Default XenForo Stuff
    #    If you are having problems with the rewrite rules, remove the "#" from the
    #    line that begins "RewriteBase" below. You will also have to change the path
    #    of the rewrite to reflect the path to your XenForo installation.
    RewriteBase /forums

    #    This line may be needed to enable WebDAV editing with PHP as a CGI.
    #RewriteRule .* - [E=HTTP_AUTHORIZATION:%{HTTP:Authorization}]

    RewriteCond %{REQUEST_FILENAME} -f [OR]
    RewriteCond %{REQUEST_FILENAME} -l [OR]
    RewriteCond %{REQUEST_FILENAME} -d
    RewriteRule ^.*$ - [NC,L]
    RewriteRule ^(data/|js/|styles/|install/|favicon\.ico|crossdomain\.xml|robots\.txt) - [NC,L]
    RewriteRule ^.*$ index.php [NC,L]
</IfModule>

/path/to/public_html/forums/library/config.php
Code:
<?php

$config['db']['host'] = 'localhost';
$config['db']['port'] = '3306';
$config['db']['username'] = 'dbuser';
$config['db']['password'] = 'dbpass';
$config['db']['dbname'] = 'dbname';

$config['superAdmins'] = '1';

//Other Settings
$config['debug'] = true;
$config['enableListeners'] = false;

?>

Linux System Info:
Code:
user@hostname:~$ uname -a
Linux hostname 2.6.32-5-amd64 #1 SMP Sun May 6 04:00:17 UTC 2012 x86_64 GNU/Linux

user@hostname:~$ cat /etc/issue
Debian GNU/Linux 6.0 \n \l

user@hostname:~$ cat /etc/debian_version
6.0.5
 
root@hostname:~# apache2 -v
Server version: Apache/2.2.16 (Debian)
Server built:   Apr  1 2012 07:14:38
 
user@hostname:~$ php -v
PHP 5.3.3-7+squeeze9 with Suhosin-Patch (cli) (built: May  8 2012 10:41:34)
Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2010 Zend Technologies
    with Suhosin v0.9.32.1, Copyright (c) 2007-2010, by SektionEins GmbH
 
user@hostname:~$ cat /etc/apt/sources.list
###### Debian CD Repos
# deb cdrom:[Debian GNU/Linux 6.0.2.1 _Squeeze_ - Official amd64 DVD Binary-1 20110626-16:33]/ squeeze contrib main
# deb cdrom:[Debian GNU/Linux 6.0.2.1 _Squeeze_ - Official amd64 DVD Binary-1 20110626-16:33]/ squeeze contrib main

###### Debian Main Repos
deb http://ftp.us.debian.org/debian/ squeeze main contrib non-free
deb-src http://ftp.us.debian.org/debian/ squeeze main contrib non-free

###### Debian Update Repos
deb http://security.debian.org/ squeeze/updates main contrib non-free
deb-src http://security.debian.org/ squeeze/updates main contrib non-free
 
 
root@host:~# apt-get update && apt-get upgrade
Hit http://security.debian.org squeeze/updates Release.gpg
Ign http://security.debian.org/ squeeze/updates/contrib Translation-en
Ign http://security.debian.org/ squeeze/updates/main Translation-en
Hit http://ftp.us.debian.org squeeze Release.gpg
Ign http://ftp.us.debian.org/debian/ squeeze/contrib Translation-en
Ign http://ftp.us.debian.org/debian/ squeeze/main Translation-en
Ign http://security.debian.org/ squeeze/updates/non-free Translation-en
Hit http://security.debian.org squeeze/updates Release
Ign http://ftp.us.debian.org/debian/ squeeze/non-free Translation-en
Hit http://ftp.us.debian.org squeeze Release
Hit http://security.debian.org squeeze/updates/main Sources
Hit http://ftp.us.debian.org squeeze/main Sources
Hit http://security.debian.org squeeze/updates/contrib Sources
Hit http://security.debian.org squeeze/updates/non-free Sources
Hit http://security.debian.org squeeze/updates/main amd64 Packages
Hit http://security.debian.org squeeze/updates/contrib amd64 Packages
Hit http://security.debian.org squeeze/updates/non-free amd64 Packages
Hit http://ftp.us.debian.org squeeze/contrib Sources
Hit http://ftp.us.debian.org squeeze/non-free Sources
Hit http://ftp.us.debian.org squeeze/main amd64 Packages
Hit http://ftp.us.debian.org squeeze/contrib amd64 Packages
Hit http://ftp.us.debian.org squeeze/non-free amd64 Packages
Reading package lists... Done
Reading package lists... Done
Building dependency tree
Reading state information... Done
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.

Relevant Screenshots:
Checkout Phases:
http://mpql.net/i/p/ss/2012-05-17_QhB1e.png
http://mpql.net/i/p/ss/2012-05-17_Hdj6O.png
http://mpql.net/i/p/ss/2012-05-17_0TXgO.png
http://mpql.net/i/p/ss/2012-05-17_PuVhh.png

Upgrade Not Purchased:
http://mpql.net/i/p/ss/2012-05-17_V7IDL.png

Seller's Account After Purchase:
http://mpql.net/i/p/ss/2012-05-17_ZYIZV.png

IPN History:
http://mpql.net/i/p/ss/2012-05-17_0Ue6n.png

IPN Transactions:
http://mpql.net/i/p/ss/2012-05-17_VsBX0.png
http://mpql.net/i/p/ss/2012-05-17_O7XZ4.png

Actual IPN Transaction Content, personal info expunged:
Code:
00L196348C014412U:

txn_type=subscr_signup&subscr_id=I-05P0C5APD5PA&last_name=<snip>&residence_country=US&mc_currency=USD&item_name=Account Upgrade: <snip> (test)&business=<snip>&amount3=5.00&recurring=1&verify_sign=AXYbT.lWLgPZR0lEvhnvoFTmTiUZAbB0oia6A1ZAkLAQs6iO08ngCpO-&payer_status=verified&test_ipn=1&payer_email=<snip>&first_name=<snip>&receiver_email=<snip>&payer_id=GARQ69JL8RHH2&reattempt=1&subscr_date=19:43:58 May 17, 2012 PDT&custom=566,1,token,566,1337308843,36217818bb30fddefe206d2b950d982764245512&charset=windows-1252&notify_version=3.4&period3=1 M&mc_amount3=5.00&ipn_track_id=283ecca77aeb4



2EL40658RU816481Y:

transaction_subject=Account Upgrade: <snip> (test)&payment_date=19:44:02 May 17, 2012 PDT&txn_type=subscr_payment&subscr_id=I-05P0C5APD5PA&last_name=<snip>&residence_country=US&item_name=Account Upgrade: <snip> (test)&payment_gross=5.00&mc_currency=USD&business=<snip>&payment_type=instant&protection_eligibility=Ineligible&verify_sign=A.tcY6aABwfLy8tpJodDr2s6vp3VAc6-XiAQEEpUuLewx016wj2OOgg3&payer_status=verified&test_ipn=1&payer_email=<snip>&txn_id=75G19719N0893740C&receiver_email=<snip>&first_name=<snip>&payer_id=GARQ69JL8RHH2&receiver_id=SHDKJGX9T3ME4&payment_status=Completed&payment_fee=0.45&mc_fee=0.45&mc_gross=5.00&custom=566,1,token,566,1337308843,36217818bb30fddefe206d2b950d982764245512&charset=windows-1252&notify_version=3.4&ipn_track_id=30e99f9453d7

I apologize in advance if I've left out any important or useful information; I've tried to be as thorough as possible. If any information I've left out is needed to diagnose this, please let me know, and I'll get it to you when I next respond. I appreciate any help or insight any of you guys out there can offer. Thanks.
 
HTTP 500 is a generic server error that doesn't tell us much. Ideally there will be a log file on the server with more information. My guess would be mod_security. Overly restrictive mod_security rules have been responsible for many a 500 error. Either that or .htaccess rules. I don't see any offensive rules among those that you listed, but I would try temporarily removing all .htaccess files just to eliminate that possibility.

But definitely look for a log file with more information. A specific error will save us having to guess.
 
D'oh. I knew I'd forgotten something. I meant to include my Apache logs for this domain in my last post- I even thought about not forgetting when I was going over my httpd.conf. The error in these logs seems like it might elucidate the problem to someone other than me, but, I don't know what's causing it. I can still try removing all .htaccess files and testing again if you still think it's worth a shot after reading these. I can provide more lines if necessary, but, I think this should be enough. I appreciate the speedy response, by the way. =]

Code:
user@hostname:~$ tail ~/log/example.com.error.log
[Fri May 18 00:57:39 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/scripts, referer: http://example.com/forums/account/upgrade-purchase?auth=v9JBnbLEB3Sfl9CR6wnSR3LRMC7r2SUysNs82Yc22lfRLVr7E6eFjqqsdMM4cXJSKsHdZB0egZIfNxR9K18azf__Vz5IUOVqgMIw-Ooj19VGkAHP695MOid3NwLJ5jUywDudn_rcE4yBZjQZlPxtVAQ4yAS_WzNZKv7qrwNBfrTFbptDeBCNqMFLHHeKCIrLRSQ48Xz6UAR3nHG9I0fQ70_K92zIl6DtFblM8z5ofzA-2yA0Bvqxp3P1x-S&form_charset=UTF-8
[Fri May 18 00:57:40 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/favicon.ico
[Fri May 18 00:57:43 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/scripts, referer: http://example.com/forums/account/upgrades
[Fri May 18 00:57:43 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/favicon.ico
[Fri May 18 02:40:44 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/scripts, referer: http://example.com/forums/account/upgrades
[Fri May 18 02:40:44 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/favicon.ico
[Fri May 18 02:49:29 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/scripts, referer: http://example.com/forums/account/upgrade-purchase?auth=DuVzL4AetyUzaxV1RKGqWDdJwqLG8ojtmtuM61Q_LqZcuVEYQnn4UytmHZwfs9AmFt3J4tTtI4H3PaHLMcRKTolCSSHjA6a1HXFkK2DGBDywlOVIlzwJVytOPWetttN6IrJI9lScpoWYAXBV4ojc2uNoNNPALxgEuM-9EM3jpwvj4jBvTBjkNvI3MmI21og1nZxff7cnkOea5cc6X8cdvBHmdU7urAHZpsYIuOcQycel1jFFv96hTH4EOOu&form_charset=UTF-8
[Fri May 18 02:49:30 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/favicon.ico
[Fri May 18 02:50:15 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/scripts, referer: http://example.com/forums/account/upgrades
[Fri May 18 02:50:15 2012] [error] [client my.home.ip.address] File does not exist: /path/to/public_html/favicon.ico



user@hostname:~$ tail ~/log/example.com.log
173.0.82.126 - - [18/May/2012:02:55:55 +0000] "POST /forums/payment_callback.php HTTP/1.0" 500 235 "-" "-"
173.0.82.126 - - [18/May/2012:02:55:55 +0000] "POST /forums/payment_callback.php HTTP/1.0" 500 235 "-" "-"
my.home.ip.address - - [18/May/2012:02:58:04 +0000] "POST /forums/admin.php?login/csrf-token-refresh HTTP/1.1" 200 486 "http://example.com/forums/admin.php?users/" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:12.0) Gecko/20100101 Firefox/12.0"
my.home.ip.address - - [18/May/2012:02:58:04 +0000] "POST /forums/admin.php?login/csrf-token-refresh HTTP/1.1" 200 485 "http://example.com/forums/admin.php?users/search&last_user_id=566" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:12.0) Gecko/20100101 Firefox/12.0"
173.0.82.126 - - [18/May/2012:03:06:39 +0000] "POST /forums/payment_callback.php HTTP/1.0" 500 235 "-" "-"
173.0.82.126 - - [18/May/2012:03:06:39 +0000] "POST /forums/payment_callback.php HTTP/1.0" 500 235 "-" "-"
my.home.ip.address - - [18/May/2012:03:08:42 +0000] "POST /forums/admin.php?login/csrf-token-refresh HTTP/1.1" 200 486 "http://example.com/forums/admin.php?users/" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:12.0) Gecko/20100101 Firefox/12.0"
my.home.ip.address - - [18/May/2012:03:08:43 +0000] "POST /forums/admin.php?login/csrf-token-refresh HTTP/1.1" 200 485 "http://example.com/forums/admin.php?options/list/debug" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:12.0) Gecko/20100101 Firefox/12.0"
173.0.82.126 - - [18/May/2012:03:28:03 +0000] "POST /forums/payment_callback.php HTTP/1.0" 500 235 "-" "-"
173.0.82.126 - - [18/May/2012:03:28:03 +0000] "POST /forums/payment_callback.php HTTP/1.0" 500 235 "-" "-"
 

You are using friendly URLs which requires the .htaccess file. You can always disable friendly URLs temporarily:

Admin CP -> Home -> Options -> Search Engine Optimisation (SEO) -> Use Full Friendly URLs
 
I don't appear to have mod_security:

Code:
root@hostname:#$ a2dismod mod_security
ERROR: Module mod_security does not exist!
root@hostname:~# ls /etc/apache2/mods-enabled
alias.conf      auth_digest.load    authz_groupfile.load  autoindex.conf  deflate.conf  dir.load      mime.conf        negotiation.load  reqtimeout.conf  setenvif.conf  ssl.load    vhost_alias.load
alias.load      authn_file.load    authz_host.load      autoindex.load  deflate.load  env.load      mime.load        php5.conf        reqtimeout.load  setenvif.load  status.conf
auth_basic.load  authz_default.load  authz_user.load      cgi.load        dir.conf      headers.load  negotiation.conf  php5.load        rewrite.load    ssl.conf      status.load
root@hostname:~# updatedb
root@hostname:~# locate mod_security
root@hostname:~#

I forgot about the Friendly URLs setting, however, I disabled that, and retried, and I'm getting similar errors: http://mpql.net/t/2012-05-17_lkFBX.txt (It's too long to paste into this post)

Is it possible that missing JavaScript file/favorite icon are somehow causing the callback to 500? Because I'll fix those if they matter, though I'd be of the opinion that such behavior in the callback handler would be a bug.
 
Sorry, this command is taking a while to run, and it's outputting a whole bunch of errors like:

Code:
grep: /sys/block/xvda2/device/driver/uevent: Permission denied
grep: /sys/block/xvda2/device/driver/unbind: Permission denied
grep: /sys/block/xvda2/device/driver/bind: Permission denied
grep: warning: /sys/block/xvda2/device/block/xvda2: recursive directory loop

grep: warning: /sys/block/xvda2/bdi/subsystem/default/subsystem: recursive direc

grep: warning: /sys/block/xvda2/bdi/subsystem/202:1/subsystem: recursive directo

grep: warning: /sys/block/xvda2/bdi/subsystem/202:2: recursive directory loop

grep: /lib/modules/2.6.18-194.32.1.el5xen/source: No such file or directory
grep: /lib/modules/2.6.18-194.32.1.el5xen/build: No such file or directory
grep: /dev/log: No such device or address

even though I ran it as root. It also very quickly outputs more lines than my history, so, I have it outputting to a text file.
 
This still hasn't exited. I don't know how long this should take; I guess I'll just keep waiting. In the meantime, I'm considering doing a fresh install of XenForo.
 
It can take a while unless you give it a specific directory to search, such as a directory containing log files.

I don't know where your log files are stored. This just does a blanket search of all files within the specified directory.
 
/var/log , except for domain-specific Apache logs, which I've already pasted. :P

Should I re-run this with /var/log as the location instead of / ? It's still searching. XD
 
Nothing unusual seems to be coming up. Just the greps themselves, and the same logs I pasted earlier. I did a complete reinstall of XenForo from scratch (both file system and database), and I'm still getting this error, which confirms it's likely something with my setup. I'm not sure why though. :-/

Here's the grep file: http://mpql.net/t/2012-05-18_gLmmg.txt It's worth nothing that the 401 and 403s I was getting were before I realized I couldn't password protect the directory and give it credentials, e.g. http://user:password@example.com/forums/payment_callback.php . I found one of your posts on here though and made it public.

Here's the last 30 lines from the past couple of minutes, to show it's still 500ing: http://mpql.net/t/2012-05-18_QNoxk.txt

Near as I can tell, none of this is making anything any clearer. If it would help, I can give you root access to my box and administrative access to my test install, as well as the sandbox paypals I made, and you can look around yourself- though I don't know if you want to do that, nor if it would help. For what it's worth, though, I appreciate all the help you've given me thus far.
 
I was also developing an add-on and encounter a problem with the sandbox. I never really looked to see what error was being thrown as I quickly figured out that for some reason when you send the request to paypal sandbox to verify the purchase it must be done with ssl, while I believe xf defaults the paypal ipn to non-ssl.

Hope this helps.
 
I was also developing an add-on and encounter a problem with the sandbox. I never really looked to see what error was being thrown as I quickly figured out that for some reason when you send the request to paypal sandbox to verify the purchase it must be done with ssl, while I believe xf defaults the paypal ipn to non-ssl.

Hope this helps.

The outgoing request that is sent to Paypal? Or the IPN where Paypal sends a request back to the forum?

The 500 error is a server error.
 
Sure I can take a look if you send me logins. Basically I'm just looking for a detailed error.
PMed you. Thanks. =]

I was also developing an add-on and encounter a problem with the sandbox. I never really looked to see what error was being thrown as I quickly figured out that for some reason when you send the request to paypal sandbox to verify the purchase it must be done with ssl, while I believe xf defaults the paypal ipn to non-ssl.

Hope this helps.
Why would the *server* respond with a 500 error, then? PayPal is receiving the information, verifiying it's been paid for, sending an IPN, and then XenForo is rejecting it. Besides all that, though, I only currently have one IP Address, so, SSL isn't an option. Thanks, though. =]
 
The outgoing request that is sent to Paypal? Or the IPN where Paypal sends a request back to the forum?

The 500 error is a server error.
Outgoing.

Why would the *server* respond with a 500 error, then? PayPal is receiving the information, verifiying it's been paid for, sending an IPN, and then XenForo is rejecting it. Besides all that, though, I only currently have one IP Address, so, SSL isn't an option. Thanks, though. =]

XenForo sets the HTTP response to 500 if it does not pass validation

payment_callback.php

Code:
if (!$processor->validateRequest($logMessage))
{
$logType = 'error';
 
$response->setHttpResponseCode(500);
}
 
XenForo sets the HTTP response to 500 if it does not pass validation

payment_callback.php

Code:
if (!$processor->validateRequest($logMessage))
{
$logType = 'error';
 
$response->setHttpResponseCode(500);
}

Oh hello there... I didn't know about you. That gives me another avenue to explore. Thank you.
 
Top Bottom