Bug #4913
closed
XMLRPC sync craches PHP-fpm
0%
Description
Hi!
Having a problem that XMLRPC gets "Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 500 Internal Server Error)" and then crashes PHP-fpm on both master and slave on our HA-setup
it can be fixed by loggin in using SSH as admin to both routers and first restart php-fpm on the master node then on the slave.
This happens every time a change is made, and it's often make that the change you have done is not saved so its more or less impossible to change anything.
The hardware is two identical Dell R210 ver.2 with a Intel Xeon E3122, 4GB ram and 4 Broadcom 1Gbe NIC (2 onboard, 2 on PCI-e) running pfsense 2.2.4
If requested i can send configs for the pair privatly. also, two crashreports have been sent from ip ending on **8.197
its looks related to bug #1226
Hope it can be a fast and easy fix.
//Ola
Here is som info from the log file. (Newest lines on top)
Aug 2 11:27:53 rc.php-fpm_restart80612: >>> Restarting php-fpm
Aug 2 11:27:53 lighttpd59920: (mod_fastcgi.c.2848) fcgi-server re-enabled: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3587) all handlers for /widgets/widgets/thermal_sensors.widget.php?getThermalSensorsData=11438507554518 on .php are down.
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3021) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.1754) connect failed: No such file or directory on unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 785 on socket: unix:/var/run/php-fpm.socket for /getstats.php?, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 948 on socket: unix:/var/run/php-fpm.socket for /widgets/widgets/thermal_sensors.widget.php?getThermalSensorsData=11438507573568, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 785 on socket: unix:/var/run/php-fpm.socket for /getstats.php?, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 957 on socket: unix:/var/run/php-fpm.socket for /widgets/widgets/thermal_sensors.widget.php?getThermalSensorsData=11438507543506, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 794 on socket: unix:/var/run/php-fpm.socket for /getstats.php?, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 948 on socket: unix:/var/run/php-fpm.socket for /widgets/widgets/thermal_sensors.widget.php?getThermalSensorsData=11438507562567, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 785 on socket: unix:/var/run/php-fpm.socket for /getstats.php?, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 948 on socket: unix:/var/run/php-fpm.socket for /widgets/widgets/thermal_sensors.widget.php?getThermalSensorsData=11438507551570, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 957 on socket: unix:/var/run/php-fpm.socket for /widgets/widgets/thermal_sensors.widget.php?getThermalSensorsData=11438507532492, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 957 on socket: unix:/var/run/php-fpm.socket for /widgets/widgets/thermal_sensors.widget.php?getThermalSensorsData=11438507510461, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 860 on socket: unix:/var/run/php-fpm.socket for /index.php?, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 957 on socket: unix:/var/run/php-fpm.socket for /widgets/widgets/thermal_sensors.widget.php?getThermalSensorsData=11438507521476, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.3346) response not received, request sent: 794 on socket: unix:/var/run/php-fpm.socket for /getstats.php?, closing connection
Aug 2 11:27:50 lighttpd59920: (mod_fastcgi.c.2562) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/var/run/php-fpm.socket
Aug 2 11:27:38 check_reload_status: Syncing firewall
Aug 2 11:26:23 php-fpm34453: /rc.filter_synchronize: Beginning XMLRPC sync to https://192.168.222.2:443.
Aug 2 11:26:23 php-fpm80757: /rc.filter_synchronize: New alert found: An error code was received while attempting XMLRPC sync with username admin https://192.168.222.2:443 - Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 500 Internal Server Error)
Aug 2 11:26:23 php-fpm80757: /rc.filter_synchronize: An error code was received while attempting XMLRPC sync with username admin https://192.168.222.2:443 - Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 500 Internal Server Error)
Aug 2 11:26:23 php-fpm34453: /rc.filter_synchronize: New alert found: An error code was received while attempting XMLRPC sync with username admin https://192.168.222.2:443 - Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 503 Service Not Available)
Aug 2 11:26:23 php-fpm34453: /rc.filter_synchronize: An error code was received while attempting XMLRPC sync with username admin https://192.168.222.2:443 - Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 503 Service Not Available)
Aug 2 11:26:23 php-fpm95406: /rc.filter_synchronize: Beginning XMLRPC sync to https://192.168.222.2:443.
Aug 2 11:26:23 php-fpm8795: /rc.filter_synchronize: Beginning XMLRPC sync to https://192.168.222.2:443.
Aug 2 11:26:23 php-fpm95406: /rc.filter_synchronize: New alert found: An error code was received while attempting XMLRPC sync with username admin https://192.168.222.2:443 - Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 500 Internal Server Error)
Aug 2 11:26:23 php-fpm8795: /rc.filter_synchronize: New alert found: An error code was received while attempting XMLRPC sync with username admin https://192.168.222.2:443 - Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 500 Internal Server Error)
Aug 2 11:26:23 php-fpm95406: /rc.filter_synchronize: An error code was received while attempting XMLRPC sync with username admin https://192.168.222.2:443 - Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 500 Internal Server Error)
Aug 2 11:26:23 php-fpm8795: /rc.filter_synchronize: An error code was received while attempting XMLRPC sync with username admin https://192.168.222.2:443 - Code 5: Didn't receive 200 OK from remote server. (HTTP/1.0 500 Internal Server Error)
Aug 2 11:24:42 check_reload_status: Syncing firewall
Updated by Kill Bill
Updated by Ola Ekegren over 9 years ago
Sorry for that, Where should it be filed?
//Ola
Updated by Chris Buechler over 9 years ago
- Project changed from pfSense Packages to pfSense
- Category set to 62
- Status changed from New to Feedback
- Priority changed from Very High to Normal
moved to the right project.
Going to need more than this to be able to track down anything. Not a replicable issue as described.
Updated by Ola Ekegren over 9 years ago
HI Chris!
One thing that maybe can help a bit is that is started after upgrade from 2.1.5. At 2.1.5 we had no issues at all but lacked some stuff that took us to the 2.2.x upgrade
do you have a safe way to transfer the configs to you? or do you want to have a look at the router themself?
i can give you access to them if you get on a skype-call or something like that with me and we can try to figure it out :)
Thanks for looking in to this!
BR.
Ola
Updated by Ola Ekegren over 9 years ago
Noted that on the primary router we are running at 25-30% CPU without any load at all (less then 100Kbit/s throughput ) so it something that uses alot of power too do nothing
Updated by Ola Ekegren over 9 years ago
last pid: 23516; load averages: 1.11, 1.05, 1.02 up 38+04:30:41 17:54:22
133 processes: 6 running, 105 sleeping, 22 waiting
Mem: 39M Active, 1246M Inact, 262M Wired, 884K Cache, 732M Buf, 2352M Free
Swap:
PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU COMMAND
299 root 123 20 19024K 2588K CPU3 3 914.8H 100.00% /usr/local/sbin/check_reload_status
11 root 155 ki31 0K 64K RUN 2 755.8H 97.27% [idle{idle: cpu2}]
11 root 155 ki31 0K 64K CPU0 0 757.7H 75.39% [idle{idle: cpu0}]
11 root 155 ki31 0K 64K CPU1 1 624.7H 75.39% [idle{idle: cpu1}]
11 root 155 ki31 0K 64K RUN 3 561.7H 56.69% [idle{idle: cpu3}]
16455 root 22 0 223M 35636K piperd 2 0:00 0.20% php-fpm: pool lighty (php-fpm)
12 root -92 - 0K 352K WAIT 0 20.4H 0.00% [intr{irq266: bce2}]
12 root -92 - 0K 352K WAIT 2 333:07 0.00% [intr{irq264: bce0}]
12 root -60 - 0K 352K WAIT 0 11:37 0.00% [intr{swi4: clock}]
37695 root 20 0 14656K 2444K select 0 4:43 0.00% /usr/sbin/syslogd -s -c -c -l /var/dhcp
5 root -16 - 0K 16K pftm 0 4:35 0.00% [pf purge]
25685 root 20 0 16804K 2280K bpf 1 4:00 0.00% /usr/local/sbin/filterlog -i pflog0 -p
12 root -72 - 0K 352K WAIT 2 2:56 0.00% [intr{swi1: pfsync}]
15 root -16 - 0K 16K - 0 2:48 0.00% [rand_harvestq]
26151 root 20 0 62848K 17752K select 0 2:38 0.00% /usr/sbin/bsnmpd -c /var/etc/snmpd.conf
32979 root 20 0 12456K 2092K select 1 2:32 0.00% /usr/local/sbin/apinger -c /var/etc/api
2156 root 20 0 21728K 6488K select 0 2:14 0.00% /usr/local/sbin/openvpn --config /var/e
12 root -92 - 0K 352K WAIT 1 2:10 0.00% [intr{irq267: bce3}]
Updated by Ola Ekegren over 9 years ago
The issue can have been solved, i will monitor our gateways and update in a couple of days
//Ola
Updated by Ola Ekegren over 9 years ago
Problem is what i think solved, The thing i found is that the gateway monitor by some reason says that the ISP gateways goes up and down and thats whats makes the check_reload_status to crash and get stuck at 100% cpu on one core.
So, this issue can be closed i think.
Updated by Chris Buechler over 9 years ago
- Status changed from Feedback to Duplicate
- Affected Version deleted (
2.2.4)
Thanks for the follow up, Ola. That's attributable to apinger issues which are covered in several other tickets.
Updated by