neekfenwick::blog

Stuff that seemed important at the time.

Httpd and Seg Fault or Similar Nasty Error Detected in the Parent Process

Following a regular update of our cPanel installation on a Centos 5.8 VPS, we encountered regular crashes of httpd. I thought I’d blog about the symptoms and a solution, though this may not be optimal as I don’t know much about the whys and wherefores of cPanel updates.

cpup is the daily cPanel update script that updates the software on our server. We found the following crash in our httpd logs:

1
2
3
[Thu Apr 26 16:09:24 2012] [notice] Graceful restart requested, doing restart
[Thu Apr 26 16:09:26 2012] [warn] RSA server certificate CommonName (CN) `www.premierrange.co.uk' does NOT match server name!?
[Thu Apr 26 16:09:26 2012] [notice] seg fault or similar nasty error detected in the parent process

This blog entry discusses a way of investigating and fixing this problem, relating to entries in php.ini that don’t exist.

Grepping the log showed that, since April 17, the errors have only been happening on this one day:

1
2
3
4
5
6
7
8
9
10
11
12
13
root@vps [/usr/local/apache/logs]# grep 'seg fault or similar nasty' error_log
[Thu Apr 26 02:17:26 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 04:08:53 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 05:08:44 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 06:07:09 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 08:05:10 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 10:02:07 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 12:15:39 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 12:26:15 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 12:26:41 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 12:27:14 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 14:12:32 2012] [notice] seg fault or similar nasty error detected in the parent process
[Thu Apr 26 16:09:26 2012] [notice] seg fault or similar nasty error detected in the parent process

I did a fair bit of googling and found various ways one could encounter this ‘seg fault or similar nasty error’ error message. The reasons were of many types, including linkage to incompatible binaries, linkage to non existant binaries, and duplicate entries of .so modules in php.ini. The problem I found was none of these.. we had .so modules named as extensions in our php.ini that simply didn’t exist.

I found the problem by using strace to watch httpd activity during failure. I had found that a /etc/init.d/httpd stop and /etc/init.d/httpd start worked fine, but /etc/init.d/httpd graceful or apachectl graceful brought the system down. So, I knew how to trigger the error.

So, we find the parent process to all other httpd processes, the one with ‘1’ as the parent process, and strace it to watch activity:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
root@vps [/usr/local/apache/logs]# ps -aef | grep httpd
root      8021     1  0 16:48 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8023  8021  0 16:48 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8025  8021  0 16:48 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8027  8021  0 16:48 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8038  8021  0 16:48 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8042  8021  0 16:48 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8043  8021  0 16:48 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8109  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8110  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8111  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8112  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8181  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8182  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8183  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8184  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
nobody    8186  8021  0 16:49 ?        00:00:00 [httpd] <defunct>
nobody    8187  8021  0 16:49 ?        00:00:00 /usr/local/apache/bin/httpd -k start -DSSL
root      8189 28644  0 16:49 pts/0    00:00:00 grep httpd
root@vps [/usr/local/apache/logs]# strace -aef -p 8021 2>&1 | tee /tmp/strace.out
Process 8021 attached - interrupt to quit

Output is then being echoed to stdout and copied to /tmp/strace.out.

Then we issue a apachectl graceful command and see what we see. After a great deal of output, the strace ends with:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
open("/usr/local/IonCube/ioncube_loader_lin_5.3.so", O_RDONLY) = 20
read(20, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0@\367\2\0004\0\0\0"..., 512) = 512
fstat64(20, {st_mode=S_IFREG|0755, st_size=850616, ...}) = 0
mmap2(NULL, 850320, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 20, 0) = 0xb6788000
mmap2(0xb6852000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 20, 0xc9) = 0xb6852000
close(20) = 0
mprotect(0xb6788000, 827392, PROT_READ|PROT_WRITE) = 0
mprotect(0xb6788000, 827392, PROT_READ|PROT_EXEC) = 0
open("/usr/local/lib/php/extensions/no-debug-non-zts-20090626/ffmpeg.so", O_RDONLY) = -1 ENOENT (No such file or directory)
open("error_log", O_WRONLY|O_CREAT|O_APPEND, 0644) = 20
time(NULL) = 1335455415
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
chdir("/usr/local/apache") = 0
rt_sigaction(SIGSEGV, {SIG_DFL, [], SA_RESTORER|SA_INTERRUPT, 0xb7c86038}, {SIG_DFL, [], SA_RESTORER|SA_RESETHAND, 0xb7c86038}, 8) = 0
gettimeofday({1335455415, 149945}, NULL) = 0
write(2, "[Thu Apr 26 16:50:15 2012] [noti"..., 100) = 100
kill(8021, SIGSEGV) = 0
sigreturn() = ? (mask now [])
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
Process 8021 detached

We see access for ioncube_loader_lin_5.3.so, which succeeds with a file handle (20), and access for an ffmpeg.so module, which fails with ENOENT (-1). The process then logs to the error log, and a segfault occurs.

Looking in our php.ini, there are a bunch of extension so’s named, including ffmpeg.so:

1
2
3
4
5
6
7
root@vps [~]# grep '^\s*extension' /usr/local/lib/php.ini |sort
extension_dir = "/usr/local/lib/php/extensions/no-debug-non-zts-20090626"
extension = "eaccelerator.so"
extension = "ffmpeg.so"
extension = "rar.so"
extension = "suhosin.so"
extension=timezonedb.so

Commenting out the ffmpeg.so line (insert a semicolon at the beginning of the line) and re-running the test gave another seg fault, but this time on rar.so. So, out that goes too, comment that out and start httpd and gracefully restart it and… no error! The server stays up, strace output continues and operation is uninterrupted.

The question remains why our php.ini was left in a broken condition, and indeed, what installed the ffmpeg and rar module dependencies in the first place.

If you have a similar failure condition, I’d suggest using strace to watch what file access or other activity occurs just before the crash, and trace your own system to figure out what is there, what isn’t there, and what you should do in your case to resolve the problem.