[peruser] Post problem

[Karsten Schmidt]

Sean Gabriel Heacock wrote:
> On Wed, 2005-07-13 at 20:18 +0200, Karsten Schmidt wrote:
> 
> ouch!  is this the latest version (0.1.6)?

Yes

> Uncomment #define MPM_PERUSER_DEBUG at the top of
> server/mpm/experimental/peruser.c and recompile.  That will spew a ton
> of debug info to your error log... then reproduce the problem and send
> the log to me.
> 
> I'm thinking the request-passing stuff is breaking on freebsd :(
> 

heres what i get in the errorlog when i post a page

[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
child_main(): input available ... resetting socket.
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
child_main(): marked jmpbuffer
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
child_main(): calling process_socket()
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
process_socket(): child_num=0 sock=136220752 sock_fd=30\n
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
process_socket(): type=MULTIPLEXER 0
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
peruser_process_connection(): function entered
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
peruser_process_connection(): leaving (DECLINED)
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
peruser_post_read(): MULTIPLEXER => Determining if request should be 
passed. Child Num: 0, dest-child: 2, hostname from server: gugge.dlx.dk 
r->hostname=gugge.dlx.dk r->the_request="POST /test.html HTTP/1.1"
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
peruser_post_read(): Passing request.
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): passing request to another child.  Vhost: gugge.dlx.dk, 
child 0 13
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): r->the_request="POST /test.html HTTP/1.1" len=24
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): Scanning the brigade
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): HEAP BUCKET is found, length=5
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): NON-HEAP BUCKET is found, extracting the part of brigade 
before it
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): Brigade is flattened as body (body_len=5)
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): Scanning is finished
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): Writing message to 13, passing sock_fd:  30
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): header_len=518 headers="POST /test.html 
HTTP/1.1\r\nHost: gugge.dlx.dk\r\nUser-Agent: Mozilla/5.0 (Windows; U; 
Windows NT 5.1; en-US; rv:1.7.8) Gecko/20050511 Firefox/1.0.4\r\nAccept: 
text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5\r\nAccept-Language: 
da,en-us;q=0.7,en;q=0.3\r\nAccept-Encoding: 
gzip,deflate\r\nAccept-Charset: 
ISO-8859-1,utf-8;q=0.7,*;q=0.7\r\nKeep-Alive: 300\r\nConnection: 
keep-alive\r\nReferer: http://gugge.dlx.dk/\r\nContent-Type: 
application/x-www-form-urlencoded\r\nContent-Length: 5\r\n\r\n"
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): body_len=5 body="test="
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): Writing message succeeded 532
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
receive_from_multiplexer(): recvmsg returned 532
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
receive_from_multiplexer(): trans_sock=136220816 fdx=29 sock_fd=29
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
receive_from_multiplexer(): header_len=518 headers="POST /test.html 
HTTP/1.1\r\nHost: gugge.dlx.dk\r\nUser-Agent: Mozilla/5.0 (Windows; U; 
Windows NT 5.1; en-US; rv:1.7.8) Gecko/20050511 Firefox/1.0.4\r\nAccept: 
text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5\r\nAccept-Language: 
da,en-us;q=0.7,en;q=0.3\r\nAccept-Encoding: 
gzip,deflate\r\nAccept-Charset: 
ISO-8859-1,utf-8;q=0.7,*;q=0.7\r\nKeep-Alive: 300\r\nConnection: 
keep-alive\r\nReferer: http://gugge.dlx.dk/\r\nContent-Type: 
application/x-www-form-urlencoded\r\nContent-Length: 5\r\n\r\n"
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
pass_request(): closing socket 30 on our side
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
peruser_post_read(): doing longjmp
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73237 uid=80 child=0) 
child_main(): landed from longjmp
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
receive_from_multiplexer(): body_len=5 body="test="
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
receive_from_multiplexer(): returning 0
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
child_main(): CHECKING IF WE SHOULD CLONE A CHILD...
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
child_main(): total_processors = 3, max_processors = 10
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
child_main(): idle_processors = 3, min_free_processors = 2
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
child_main(): marked jmpbuffer
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
child_main(): calling process_socket()
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
process_socket(): child_num=5 sock=136220816 sock_fd=29\n
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
process_socket(): type=WORKER 5
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
peruser_process_connection(): function entered
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
peruser_process_connection(): leaving (DECLINED)
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
peruser_post_read(): WORKER 5
[Wed Jul 13 20:28:42 2005] [warn] (peruser: pid=73246 uid=1001 child=5) 
peruser_post_read(): request for gugge.dlx.dk / (server gugge.dlx.dk) 
seems to be for us
[Wed Jul 13 20:28:43 2005] [notice] child pid 73246 exit signal 
Segmentation fault (11)
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73236 uid=0 child=0) 
ap_mpm_run(): child #5 has died ...
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73236 uid=0 child=0) 
ap_mpm_run(): calling ap_update_child_status_from_indexes
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73236 uid=0 child=0) 
ap_mpm_run(): returned from ap_update_child_status_from_indexes
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73236 uid=0 child=0) 
ap_mpm_run(): replacing by new child ...
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73236 uid=0 child=0) 
make_child(): function entered
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73253 uid=0 child=5) 
child_main(): sock_fd_in=12 sock_fd_out=13
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73253 uid=0 child=5) 
child_main(): WORKER 5
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73253 uid=0 child=5) 
listen_clear(): function entered
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73253 uid=0 child=5) 
listen_add(): function entered
[Wed Jul 13 20:28:43 2005] [warn] (peruser: pid=73253 uid=0 child=5) 
listen_add(): function entered