[FreeBSD] httpd/apache22 will not start “core dumped”

I ran into a finicky situation after upgrading apache22 from ports on one of my FreeBSD servers, only find that the httpd daemon would not properly start. I had to venture out as far as using gdb in order to get to the root cause to figure out why.

# /opt/etc/rc.d/apache22 configtest
Performing sanity check on apache22 configuration:
Syntax OK
# /opt/etc/rc.d/apache22 start
Performing sanity check on apache22 configuration:
Syntax OK
Starting apache22.
# /opt/etc/rc.d/apache22 status
apache22 is not running.

Obviously something is not right. To see what is going on in the background when starting apache the -e debug option will allow httpd to be a bit more verbose.

# httpd -e debug -f /opt/etc/apache22/httpd.conf
...edited...
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module cgi_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module dav_fs_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module vhost_alias_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module negotiation_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module dir_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module imagemap_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module actions_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module speling_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module userdir_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module alias_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module rewrite_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module ruby_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module dav_svn_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authz_svn_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module php5_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module ntlm_module

It appeared the httpd daemon started without issues, but a “ps -auxwww | grep http” showed nothing. It seems all modules where successfully loaded without problems. The output from dmesg showed:

...edited...
pid 14086 (httpd), uid 0: exited on signal 11 (core dumped)
pid 14408 (httpd), uid 0: exited on signal 11 (core dumped)
pid 27487 (httpd), uid 0: exited on signal 11 (core dumped)

that httpd dumped core, but there was no core file found. I later realized that I did not have the following in my httpd.conf to save apache cores: “CoreDumpDirectory /var/tmp/apache22/“.

But, a search on google for ‘debugging httpd’ suggested using gdb for helping solve httpd problems.

# gdb httpd

GNU gdb 6.1.1 [FreeBSD]
...edited...
This GDB was configured as "amd64-marcel-freebsd"...

At the gdb prompt, it is preferred to set a breakpoint at ap_process_request:

(gdb) b ap_process_request
Breakpoint 1 at 0x4434a5: file http_request.c, line 259.

then perpend : run -X -d before httpd like so:

(gdb) run -X -d httpd -e debug -f /opt/etc/apache22/httpd.conf
Starting program: /usr/local/sbin/httpd -X -d httpd -e debug -f /opt/etc/apache22/httpd.conf
[New LWP 100330]
[New Thread 0x801d020b0 (LWP 100330)]
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authn_file_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authn_dbm_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authn_anon_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authn_default_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authn_alias_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authz_host_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authz_groupfile_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authz_user_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authz_dbm_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authz_owner_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authz_default_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module auth_basic_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module auth_digest_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module file_cache_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module cache_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module disk_cache_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module include_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module filter_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module charset_lite_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module deflate_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module ldap_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module log_config_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module logio_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module env_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module mime_magic_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module cern_meta_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module expires_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module headers_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module usertrack_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module unique_id_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module setenvif_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module version_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module proxy_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module proxy_ftp_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module proxy_http_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module proxy_ajp_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module proxy_balancer_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module ssl_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module mime_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module dav_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module status_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module autoindex_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module asis_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module info_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module cgi_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module dav_fs_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module vhost_alias_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module negotiation_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module dir_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module imagemap_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module actions_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module speling_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module userdir_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module alias_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module rewrite_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module ruby_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module dav_svn_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module authz_svn_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module php5_module
[Mon Jan 31 16:01:52 2011] [debug] mod_so.c(246): loaded module ntlm_module

At this stage, open a http request to the webserver and see if gdb spits out anything else. In my case I got this:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x801d020b0 (LWP 100330)]
0x00000008058fa8a8 in onigenc_ascii_mbc_to_lower () from /usr/local/lib/libruby18.so.18
(gdb) s
Single stepping until exit from function onigenc_ascii_mbc_to_lower,
which has no line number information.

Program terminated with signal SIGSEGV, Segmentation fault.
The program no longer exists.

From the output of gdb it appeared the library, libruby18.so.18, from “ruby+oniguruma-1.8.7.302,1” might have something to do with the crash? My guess was, the “oniguruma regular expression library” probably has something to do with httpd not starting properly. Let’s remove it and see if it fixes the problem.

# pkg_delete -f ruby+oniguruma-1.8.7.302,1
pkg_delete: package 'ruby+oniguruma-1.8.7.302,1' is required by these other packages
and may not be deinstalled (but I'll delete it anyway):
rrdtool-1.4.4
ap22-mod_ruby-1.3.0_1
ruby18-eruby-1.0.5_2
ruby18-deplate-0.8.5
pkg_delete: unable to completely remove directory '/usr/local/lib/ruby/site_ruby/1.8/amd64-freebsd7'
pkg_delete: unable to completely remove directory '/usr/local/lib/ruby/site_ruby/1.8'
pkg_delete: unable to completely remove directory '/usr/local/lib/ruby/site_ruby'
pkg_delete: unable to completely remove directory '/usr/local/lib/ruby'
pkg_delete: couldn't entirely delete package (perhaps the packing list is
incorrectly specified?)

# cd /usr/ports/lang/ruby18
# make config

From the make options screen, I un-checked:
[ ] ONIGURUMA Build with oniguruma regular expressions lib.
Then reinstalled ruby without oniguruma:

# make reinstall clean
...edited...

      For more information, and contact details about the security
      status of this software, see the following webpage:
http://www.ruby-lang.org/en/
===>  Cleaning for ruby-1.8.7.302,1

Did that solve the problem? Yep, my guess was right. Looking at the logs, after:

# /opt/etc/rc.d/apache22 start
Performing sanity check on apache22 configuration:
Syntax OK
Starting apache22.
# /opt/etc/rc.d/apache22 status
apache22 is running as pid 43427.
#

I saw:

[Mon Jan 31 17:20:52 2011] [notice] Digest: generating secret for digest authentication ...
[Mon Jan 31 17:20:52 2011] [notice] Digest: done
[Mon Jan 31 17:20:52 2011] [warn] pid file /var/run/httpd.pid overwritten -- Unclean shutdown of previous Apache run?
[Mon Jan 31 17:20:52 2011] [notice] Apache/2.2.17 (FreeBSD) mod_ssl/2.2.17 OpenSSL/0.9.8e DAV/2 mod_ruby/1.3.0 Ruby/1.8.7(2010-08-16) SVN/1.6.12 PHP/5.3.5 with Suhosin-Patch configured -- resuming normal operations
Advertisements
This entry was posted in Uncategorized. Bookmark the permalink.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s