Cesar Chew at 17:48, 24 November 2014

2014-11-24T17:48:05Z

New page

{{Cat|Apache|07}}

<slideshow style="nobleprog" headingmark="⌘" incmark="…" scaled="true" font="Trebuchet MS" >
;title: Logging and troubleshooting
;author: Sam Bashton (NobleProg Ltd)

</slideshow>
=== Apache log format ⌘===
* **common** log format - NCSA format
* Understood by many (old) programs
:* AWstats
:* Webalizer

127.0.0.1 user-identifier frank [10/Oct/2000:13:55:36 +0100] "GET /apache_pb.gif HTTP/1.0" 200 2326

:* A "-" in a field indicates missing data.
:* 127.0.0.1 is the IP address of the client (remote host) which made the request to the server.
:* user-identifier is the RFC 1413 identity of the client.
:* frank is the username of the person requesting the document.
:* [10/Oct/2000:13:55:36 +0100] is the date, time, and time zone when the server finished processing the request, by default in strftime format %d/%b/%Y:%H:%M:%S %z
:* "GET /apache_pb.gif HTTP/1.0" is the request line from the client.
:* 200 is the HTTP status code returned to the client.
:* 2326 is the size of the object returned to the client, measured in bytes.

=== CustomLog format ⌘===
* Commonly you would set your own log format
* Two parts to this:
:* Define the format
:* Set it as the log output type

=== Example: `vhost_combined` format ⌘===
LogFormat "%v:%p %h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" vhost_combined`

* `%v` - Canonical ServerName (VirtualHost)
* `%p` - Server Port
* `%h` - Remote Host. Use `%{X-Forwarded-For}i` if behind a proxy
* `%l` - Remote log name (ignore, identd, unused)
* `%u` - User name
* `%r` - Request
* `%>s` - Final status (eg 200, 404)
* `%0` - requested server name
* `%{Referer}i` - URL user visited to find this page
* `%{User-Agent}i` - web browser of the remote user

=== Other log variables ⌘===
* See http://httpd.apache.org/docs/current/mod/mod_log_config.html

=== Setting the Log Format ⌘===
CustomLog /var/log/httpd/example-access.log vhost_combined

=== Troubleshooting Apache: Backtrace ⌘===
:* Apache crashing?
:* Messages like this in the log:

child pid 1256 exit signal Segmentation fault (11)

=== Obtaining a coredump ⌘===
:* On >=EL6 - /var/spool/abrt will contain it
:* On <= EL5 - enable CoreDump directive in Apache config

CoreDumpDirectory /var/spool/coredumps

* Create `/var/spool/coredumps`
* Wait for it to crash again

=== Backtracing the coredump ⌘===
* We can use gdb to obtain a backtrace
* Should at least give us some hints as to what it going wrong
:* and/or a file to give to Red Hat support
* We need to enable debugnfo yum repo which contains debugging symbols
:* Can be done via RHN or from the command line:
rhn-channel -a -c rhel-`uname -i`-Server-5-debuginfo -u <Your RHN ID> -p <Your Password>

* Also need to install the `yum-utils` package if not installed

=== Performing the backtrace ===
* All relevant debugging symbols need to be installed
* gdb will tell you which ones need to be installed and how
* Run `gdb /usr/bin/httpd corefile`
* At the gdb prompt, type `bt`

=== Sample gdb output: ⌘===
(gdb) bt
#0 0x080ca21b in _efree (ptr=0xbfffdb9b) at zend_alloc.c:240
#1 0x080d691a in _zval_dtor (zvalue=0x8186b94) at zend_variables.c:44
#2 0x080cfab3 in _zval_ptr_dtor (zval_ptr=0xbfffdbfc) at zend_execute_API.c:274
#3 0x080f1cc4 in execute (op_array=0x816c670) at ./zend_execute.c:1605
#4 0x080f1e06 in execute (op_array=0x816c530) at ./zend_execute.c:1638
#5 0x080f1e06 in execute (op_array=0x816c278) at ./zend_execute.c:1638
#6 0x080f1e06 in execute (op_array=0x8166eec) at ./zend_execute.c:1638
#7 0x080d7b93 in zend_execute_scripts (type=8, retval=0x0, file_count=3) at zend.c:810
#8 0x0805ea75 in php_execute_script (primary_file=0xbffff650) at main.c:1310
#9 0x0805cdb3 in main (argc=2, argv=0xbffff6fc) at cgi_main.c:753
#10 0x400c91be in __libc_start_main (main=0x805c580
, argc=2, ubp_av=0xbffff6fc,
init=0x805b080 <_init>, fini=0x80f67b4 <_fini>, rtld_fini=0x4000ddd0 <_dl_fini>,
stack_end=0xbffff6ec) at ../sysdeps/generic/libc-start.c:129
(gdb) frame 3
#3 0x080f1cc4 in execute (op_array=0x816c670) at ./zend_execute.c:1605
(gdb) print (char *)(executor_globals.function_state_ptr->function)->common.function_name
$14 = 0x80fa6fa "pg_result_error"
(gdb) print (char *)executor_globals.active_op_array->function_name
$15 = 0x816cfc4 "result_error"
(gdb) print (char *)executor_globals.active_op_array->filename
$16 = 0x816afbc "/home/yohgaki/php/DEV/segfault.php"
(gdb)

* In this session, frame 3 is the last execute() call. The frame 3 command moves the current working stack to the proper frame.
* In the sample gdb session, the pg_result_error() call is causing the segfault.

Logging and troubleshooting - Revision history

Cesar Chew at 17:48, 24 November 2014