Bug 39914

Summary: crash in ap_log_rerror() from jk_log_to_file()
Product: Tomcat Connectors Reporter: Steve Alexander <sca>
Component: CommonAssignee: Tomcat Developers Mailing List <dev>
Status: CLOSED DUPLICATE    
Severity: normal    
Priority: P2    
Version: unspecified   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Attachments: apr.h

Description Steve Alexander 2006-06-27 18:25:19 UTC
mod_jk-1.2.15, httpd-2.0.52 with RH ES4 patches applied running on RH ES4 
update 3.

I haven't figured out what the root cause of this is:
  jk_log_lock doesn't appear to get initialized, so both the lock and the
  unlock fail with EINVAL (presumably coming from pthread_mutex_{lock,unlock}
()).
  The unlock error case calls ap_log_rerror() with a NULL request pointer, but
  this routine dereferences the pointer immediately to pick up the server
  information, causing a core dump.  I changed it to ap_log_error() and that
  fixes the crash.

  I still don't know why the mutex is not initialized; I can only assume that
  the post config hook is not being called or is failing for some reason.

Let me know if any further information is needed.
Comment 1 Rainer Jung 2006-06-27 19:58:40 UTC
Generally this works.

I assume you are using the worker MPM and a 32Bit Linux?

If the lock could not be initialized correctly, we would expect at least one of
the following messages with levels:

mod_jk: could not init JK log lock in child (ERROR)
mod_jk: could not create jk_log_lock (CRITICAL)
mod_jk: Could not set permissions on jk_log_lock; check User and Group
directives (CRITICAL)

Any of these in you mod_jk-Log?

Just to make sure, could you also give the exact messages from the failed
lock/unlock.

Concerning ap_log_rerror: you are right, I will correct to ap_log_error for the
upcoming 1.2.16.

As always: any chance to test with 2.0.58 and Subversion HEAD of mod_jk?

Finally: Could you provide the following things form inside your Apache home:

bin/httpd -V
include/apr.h
include/apr.h
Comment 2 Steve Alexander 2006-06-27 20:31:10 UTC
Created attachment 18541 [details]
apr.h
Comment 3 Steve Alexander 2006-06-27 20:48:15 UTC
What I have realized now is that these messages are only coming out in between
   "graceful restart requested, doing restart" 
and
   "Apache configured -- resuming normal operations"
and only if a request is in progress during the graceful restart.  A normal
'apachectl graceful' does not produce this.

My ignorance of APR is vast since I only got sucked into this yesterday,
but since jk_log_lock is a global mutex, perhaps it is being cleaned up
during the restart by global_mutex_cleanup()?

I do not see any of the errors you list in the log.
[Tue Jun 27 13:19:41 2006] [notice] Graceful restart requested, doing restart
[Tue Jun 27 13:19:41 2006] [error] (22)Invalid argument:
apr_global_mutex_lock(jk_log_lock) failed
[Tue Jun 27 13:19:41 2006] [error] (22)Invalid argument:
apr_global_mutex_lock(jk_log_lock) failed
[Tue Jun 27 13:19:41 2006] [error] (22)Invalid argument:
apr_global_mutex_lock(jk_log_lock) failed
[Tue Jun 27 13:19:41 2006] [error] (22)Invalid argument:
apr_global_mutex_lock(jk_log_lock) failed
[Tue Jun 27 13:19:41 2006] [error] (22)Invalid argument:
apr_global_mutex_lock(jk_log_lock) failed
...
...
[Tue Jun 27 13:19:42 2006] [notice] Apache configured -- resuming normal operations

############ httpd -V ############
[root@zm9 logs]# /usr/sbin/httpd -V
Server version: Apache/2.0.52
Server built:   Dec 15 2005 04:09:14
Server's Module Magic Number: 20020903:9
Architecture:   32-bit
Server compiled with....
 -D APACHE_MPM_DIR="server/mpm/prefork"
 -D APR_HAS_SENDFILE
 -D APR_HAS_MMAP
 -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
 -D APR_USE_SYSVSEM_SERIALIZE
 -D APR_USE_PTHREAD_SERIALIZE
 -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
 -D APR_HAS_OTHER_CHILD
 -D AP_HAVE_RELIABLE_PIPED_LOGS
 -D HTTPD_ROOT="/etc/httpd"
 -D SUEXEC_BIN="/usr/sbin/suexec"
 -D DEFAULT_PIDLOG="logs/httpd.pid"
 -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
 -D DEFAULT_LOCKFILE="logs/accept.lock"
 -D DEFAULT_ERRORLOG="logs/error_log"
 -D AP_TYPES_CONFIG_FILE="conf/mime.types"
 -D SERVER_CONFIG_FILE="conf/httpd.conf"


apr.h added as an attachment.
Comment 4 Rainer Jung 2006-06-27 20:56:03 UTC
If the problem is only occuring during graceful restart it's most likely BZ
39834. I noticed a mutex error when reproducing 39834 to. Should be fixed by
Mladen in Subversion HEAD and in the soon to come 1.2.16. 

*** This bug has been marked as a duplicate of 39834 ***
Comment 5 Rainer Jung 2008-01-01 17:03:43 UTC
Move a couple of fixed JK issues from resolved to closed.