Logging and troubleshooting

From Training Material
Jump to navigation Jump to search
Logging and troubleshooting
Sam Bashton (NobleProg Ltd)

Apache log format ⌘

  • **common** log format - NCSA format
  • Understood by many (old) programs
  • AWstats
  • Webalizer 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.
  • 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 ⌘

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"
  • 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.