Bug 8143 - RewriteLogLevel other than 0 prevents http request completion.
Summary: RewriteLogLevel other than 0 prevents http request completion.
Status: CLOSED FIXED
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: mod_rewrite (show other bugs)
Version: 2.0.35
Hardware: PC Linux
: P3 normal with 6 votes (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2002-04-16 04:10 UTC by rthomas-contrib
Modified: 2004-11-16 19:05 UTC (History)
3 users (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description rthomas-contrib 2002-04-16 04:10:28 UTC
The rewrite engine seems to work okay until the RewriteLogLevel is set to 
something other than 0.  If RewriteLogLevel is set to anything from 1 to 9, the 
server stops responding to requests.  Other circumstances that may be relevant 
are: 1) a dozen or so rewrite rules using regular expression matching are 
configured, 2) the rewrite engine was enabled within a virtual host, and 3) the 
rewrite log files get created but remain 0 size (so it is unlikely related to 
FS permissions).  Netscape and IE were both tested on a 100Mb LAN connection.  
Once RewriteLogLevel was set back to 0, the responses from the same virtual 
host went back to instantaneous in the same environment.  BTW, the Linux 
distribution is RedHat 7.1.
Comment 1 James Tait 2002-04-19 14:06:28 UTC
Reproduced here too.  We do get the "init rewrite engine with requested uri"
message, but no more.  I tried adding an extra call to rewritelog on the next
line, but it never got executed (or at least the output never appears in the log).

RedHat 7.1, uname -mrsp: Linux 2.4.2-2 i686 unknown

Incidentally, I haven't been able to repoduce this on Solaris 8.
Comment 2 Cliff Woolley 2002-04-20 05:57:36 UTC
I wonder if this is specific to RH71?  The httpd-test suite uses 
RewriteLogLevel 9 for the mod_rewrite tests, and the test suite has never given 
me (or any of the other developers that I know of) trouble on the mod_rewrite 
tests.  I personally use slackware-current (Linux 2.4.18) and have no trouble...

The best would be if you could provide us a backtrace of one of the hung 
processes.  Attach to the process with gdb and interrupt it with Ctrl-C, then 
type "bt" at the (gdb) prompt and attach the output to this PR.  See 
http://httpd.apache.org/dev/debugging.html for more tips on getting a backtrace.

Thanks for using Apache!
Comment 3 Jerome 2002-04-20 12:17:18 UTC
Can't run my 1.3.19 mod_rewrite config (Debian Potatoe) on apache 2.035 on
Windows XP (my dev machine): this does generate a 400 status, without reporting
anything in the error log. Have not test on linux yet.

Here are my conds (ruling on  with apache 1.3.19)
<VirtualHost *>
	DocumentRoot E:/home/pagesweb/odontop7
	ServerName localhost

	ErrorDocument 404 /erreur.php
	ErrorDocument 500 /erreur.php

	RewriteEngine	on
	RewriteRule		^/$		/index.php?url_section=ufr&url_rubrique=1	[L]
	RewriteRule		^/ufr/?$		/index.php?url_section=ufr&url_rubrique=1	[L]
	RewriteRule		^/centredesoins/?$		/index.php?url_section=centredesoins&url_rubrique=2
[L]
	RewriteRule		^/(ufr|centredesoins)/([0-9]+)/?$		/index.php?url_section=$1&url_rubrique=$2
[L]
</VirtualHost>
Comment 4 Frank Vance 2002-05-04 03:10:37 UTC
Seeing same behavior....
Redhat 7.1 

# gdb ./httpd
GNU gdb Red Hat Linux (5.1-0.71)
Copyright 2001 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-redhat-linux"...
(gdb) run -X
Starting program: /usr/local/apache2/bin/./httpd -X
[New Thread 1024 (LWP 17814)]

Program received signal SIGINT, Interrupt.
[Switching to Thread 1024 (LWP 17814)]
0x4019aba5 in __sigsuspend (set=0xbfffbf70)
    at ../sysdeps/unix/sysv/linux/sigsuspend.c:45
45      ../sysdeps/unix/sysv/linux/sigsuspend.c: No such file or directory.
        in ../sysdeps/unix/sysv/linux/sigsuspend.c
(gdb) bt
#0  0x4019aba5 in __sigsuspend (set=0xbfffbf70)
    at ../sysdeps/unix/sysv/linux/sigsuspend.c:45
#1  0x401601d9 in __pthread_wait_for_restart_signal (self=0x40168f80)
    at pthread.c:969
#2  0x40161f49 in __pthread_alt_lock (lock=0x80ed854, self=0x0) at restart.h:34
#3  0x4015ed26 in __pthread_mutex_lock (mutex=0x80ed844) at mutex.c:120
#4  0x4003e610 in apr_thread_mutex_lock (mutex=0x80ed840) at thread_mutex.c:148
#5  0x4003cfe4 in apr_global_mutex_lock (mutex=0x80ed7b0) at global_mutex.c:130
#6  0x402afb30 in rewritelog (r=0x8146e10, level=3,
    text=0x402b2260 "applying pattern '%s' to uri '%s'") at mod_rewrite.c:3232
#7  0x402ad8b3 in apply_rewrite_rule (r=0x8146e10, p=0x8103d50, perdir=0x0)
    at mod_rewrite.c:1826
#8  0x402ad56f in apply_rewrite_list (r=0x8146e10, rewriterules=0x8103d38,
    perdir=0x0) at mod_rewrite.c:1666
#9  0x402ac872 in hook_uri2file (r=0x8146e10) at mod_rewrite.c:1112
#10 0x0809214c in ap_run_translate_name (r=0x8146e10) at request.c:107
#11 0x08092b8d in ap_process_request_internal (r=0x8146e10) at request.c:167
#12 0x0806d73e in ap_process_request (r=0x8146e10) at http_request.c:259
#13 0x080693a1 in ap_process_http_connection (c=0x8140ab8) at http_core.c:291
#14 0x08088094 in ap_run_process_connection (c=0x8140ab8) at connection.c:85
#15 0x0808837f in ap_process_connection (c=0x8140ab8, csd=0x81409e8)
    at connection.c:207
#16 0x0807d28f in child_main (child_num_arg=0) at prefork.c:671
#17 0x0807d351 in make_child (s=0x813c560, slot=0) at prefork.c:711
#18 0x0807d45f in startup_children (number_to_start=5) at prefork.c:783
#19 0x0807d835 in ap_mpm_run (_pconf=0x80b8020, plog=0x80f0100, s=0x813c560)
    at prefork.c:998
#20 0x08082ff8 in main (argc=2, argv=0xbffff004) at main.c:622
#21 0x40188647 in __libc_start_main (main=0x80827cc <main>, argc=2,
    ubp_av=0xbffff004, init=0x805ed3c <_init>, fini=0x809c240 <_fini>,
    rtld_fini=0x4000dcd4 <_dl_fini>, stack_end=0xbfffeffc)
    at ../sysdeps/generic/libc-start.c:129
(gdb)



Comment 5 Cliff Woolley 2002-05-04 03:31:51 UTC
Hmmm interesting.  What do you have RewriteLock set to?  What does httpd -V say? 
Comment 6 Frank Vance 2002-05-04 04:06:57 UTC
RewriteLock is not set.  The docs suggest it is unnecessary, since I am not
using a rewriting-map program.

Here are the Rewrite directives I currently use:
RewriteEngine On
RewriteLog   logs/rewrite.log
RewriteLogLevel 0
RewriteMap   lower              int:tolower
RewriteMap   goto               txt:/usr/local/apache2/conf/GOTO.conf
RewriteRule  ^/go/+(.*)$      ${goto:${lower:$1}|GoToMatch.html} [R=permanent,L,NC]

# ./httpd -V
Server version: Apache/2.0.35
Server built:   May  2 2002 11:30:37
Server's Module Magic Number: 20020329:0
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
 -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="/usr/local/apache2"
 -D SUEXEC_BIN="/usr/local/apache2/bin/suexec"
 -D DEFAULT_ERRORLOG="logs/error_log"
 -D SERVER_CONFIG_FILE="conf/httpd.conf"

Comment 7 Cliff Woolley 2002-05-06 01:29:53 UTC
AHA... I finally managed to reproduce this problem.  The only difference is 
that I'm running with mod_rewrite built statically this time and I usually run 
it as a DSO.  As a DSO, it works, static, no go.  Does that match with what you 
guys are seeing?
Comment 8 Frank Vance 2002-05-06 01:52:56 UTC
I started out static, but rebuilt dynamic.  I have the problem both ways.... 
Comment 9 Aaron Bannert 2002-05-06 02:27:27 UTC
Could someone who is having the problem please run this
`grep SERIALIZE srclib/apr/include/apr.h` and attach the output
here?
Comment 10 Frank Vance 2002-05-06 02:30:03 UTC
$ grep SERIALIZE srclib/apr/include/apr.h
#define APR_USE_FLOCK_SERIALIZE           0
#define APR_USE_SYSVSEM_SERIALIZE         1
#define APR_USE_POSIXSEM_SERIALIZE        0
#define APR_USE_FCNTL_SERIALIZE           0
#define APR_USE_PROC_PTHREAD_SERIALIZE    0
#define APR_USE_PTHREAD_SERIALIZE         1
#define APR_HAS_FLOCK_SERIALIZE           1
#define APR_HAS_SYSVSEM_SERIALIZE         1
#define APR_HAS_POSIXSEM_SERIALIZE        0
#define APR_HAS_FCNTL_SERIALIZE           1
#define APR_HAS_PROC_PTHREAD_SERIALIZE    0
#define APR_HAS_RWLOCK_SERIALIZE          1

Comment 11 Cliff Woolley 2002-05-06 02:32:45 UTC
[same as the last one reported on my end]

#define APR_USE_FLOCK_SERIALIZE           0 
#define APR_USE_SYSVSEM_SERIALIZE         1
#define APR_USE_POSIXSEM_SERIALIZE        0
#define APR_USE_FCNTL_SERIALIZE           0
#define APR_USE_PROC_PTHREAD_SERIALIZE    0 
#define APR_USE_PTHREAD_SERIALIZE         1 
#define APR_HAS_FLOCK_SERIALIZE           1
#define APR_HAS_SYSVSEM_SERIALIZE         1
#define APR_HAS_POSIXSEM_SERIALIZE        0
#define APR_HAS_FCNTL_SERIALIZE           1
#define APR_HAS_PROC_PTHREAD_SERIALIZE    0
#define APR_HAS_RWLOCK_SERIALIZE          1
Comment 12 rthomas-contrib 2002-05-06 02:58:35 UTC
grep SERIALIZE srclib/apr/include/apr.h
#define APR_USE_FLOCK_SERIALIZE           0
#define APR_USE_SYSVSEM_SERIALIZE         1
#define APR_USE_POSIXSEM_SERIALIZE        0
#define APR_USE_FCNTL_SERIALIZE           0
#define APR_USE_PROC_PTHREAD_SERIALIZE    0
#define APR_USE_PTHREAD_SERIALIZE         1
#define APR_HAS_FLOCK_SERIALIZE           1
#define APR_HAS_SYSVSEM_SERIALIZE         1
#define APR_HAS_POSIXSEM_SERIALIZE        0
#define APR_HAS_FCNTL_SERIALIZE           1
#define APR_HAS_PROC_PTHREAD_SERIALIZE    0
#define APR_HAS_RWLOCK_SERIALIZE          1
Comment 13 Aaron Bannert 2002-05-06 03:37:34 UTC
OK, next questions: does this happen when the server is run as non-root?
Does semop() fail in an strace (with EACCES)? What is the minimum
configuration I should need to reproduce this bug (I'm lazy today,
it's Sunday.)?
Comment 14 Cliff Woolley 2002-05-06 03:51:11 UTC
Bingo!

brk(0x824c000)                          = 0x824c000
gettimeofday({1020656912, 937141}, NULL) = 0
semop(8781875, 0x40042960, 1)           = -1 EACCES (Permission denied)
write(21, "127.0.0.1 - - [05/May/2002:23:48"..., 265) = 265
semop(8781875, 0x40042966, 1)           = -1 EACCES (Permission denied)
gettimeofday({1020656912, 937444}, NULL) = 0
rt_sigprocmask(SIG_SETMASK, NULL, [RT_0], 8) = 0
rt_sigsuspend([] <unfinished ...>
Comment 15 Cliff Woolley 2002-05-06 03:57:52 UTC
Oh, and as if you couldn't have guessed, from ipcs, the corresponding semaphore:

0x00000000 8781875    root      600        1         

The minimum config seems to be: run Apache as root with User set to some guy 
(jcw5q in my case ;), you *might* need to be in -X mode, and have RewriteLog 
set up and RewriteEngine on and RewriteLogLevel set > 0 with at least one 
RewriteRule, I imagine.  httpd-test's config is sufficient.
Comment 16 Aaron Bannert 2002-05-06 04:08:09 UTC
I'm going to leave this as new for now. A fix has already been pointed out
(while investigating another bug) and we will mark this as fixed once it
has been committed. For those of you who need a workaround now, here is a
completely untested and unofficial patch that should disable the use of
SysV Semaphores. Apply it like this:

 cd srclib/apr ; patch -p0 < thispatch.foo ; cd ../../ ; ./buildconf

Index: configure.in
===================================================================
RCS file: /home/cvs/apr/configure.in,v
retrieving revision 1.425
diff -u -u -r1.425 configure.in
--- configure.in	4 Apr 2002 21:35:43 -0000	1.425
+++ configure.in	6 May 2002 04:00:46 -0000
@@ -1374,8 +1374,6 @@
             APR_DECIDE(USE_FLOCK_SERIALIZE, [4.2BSD-style flock()]))
 APR_IFALLYES(header:fcntl.h define:F_SETLK,
             APR_DECIDE(USE_FCNTL_SERIALIZE, [SVR4-style fcntl()]))
-APR_IFALLYES(func:semget func:semctl define:SEM_UNDO,
-            APR_DECIDE(USE_SYSVSEM_SERIALIZE, [SysV IPC semget()]))
 APR_IFALLYES(header:semaphore.h func:sem_open func_sem_close dnl
              func_sem_unlink func:sem_post func_sem_wait,
              APR_DECIDE(USE_POSIXSEM_SERIALIZE, [Posix sem_open()]))
@@ -1401,9 +1399,6 @@
         ;;
     USE_FCNTL_SERIALIZE )
         fcntlser="1"
-        ;;
-    USE_SYSVSEM_SERIALIZE )
-        sysvser="1"
         ;;
     USE_POSIXSEM_SERIALIZE )
         posixser="1"
Comment 17 Cliff Woolley 2002-05-06 16:56:02 UTC
Note: see also PR8124, which is the same problem except in mod_ssl and not mod_rewrite. 
Comment 18 Aaron Bannert 2002-05-06 18:25:02 UTC
This has now been fixed in CVS, but unfortunately won't be part of 2.0.36.