Hello,
I've always used mod_jk2, but since I'm now using a 64
bit web server with Apache, I figured now would be a
good time to make the switch to mod_jk.
However, I'm having a problem where after some time,
mod_jk seems to get stuck serving CERTAIN requests.
As an example, I have a form (index.jsp) that POSTs
back to itself. Then after processing the POST, it
redirects back to itself for a GET to display the
results:
request.sendredirect(response.encodeURL("/index.jsp"));
return;
That works perfectly almost all the time. In fact, it
does work ALL the time in tomcat standalone. But in
production, we are using Apache 2.0.55 and mod_jk
1.2.15, and though it works fine for a while after
startup, it eventually starts having problems.
At some point, the POST keeps working (users can POST
to index.jsp), but the redirect back to itself gets
held up. It seems to get the GET request after the
redirect, but it just seems to freeze on it, as you'll
see below.
First, here's an example of how it normally works just
fine from the mod_jk logs.
I snipped the DEBUG output to the end of the POST,
where it gives the redirect:
#################################################
<snip>
76 65 64 20 54 65 6D 70 6F - .....Moved.Tempo
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0010 72 61 72 69 6C 79 00 00 03 00 08 4C 6F
63 61 74 - rarily.....Locat
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0020 69 6F 6E 00 00 24 68 74 74 70 3A 2F 2F
77 77 77 - ion..$http://www
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0030 2E 67 69 72 6C 6D 61 64 6E 65 73 73 2E
63 6F 6D - .mysite.com
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0040 2F 69 6E 64 65 78 2E 6A 73 70 00 00 0C
43 6F 6E - /index.jsp...Con
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0050 74 65 6E 74 2D 54 79 70 65 00 00 1C 74
65 78 74 - tent-Type...text
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0060 2F 68 74 6D 6C 3B 63 68 61 72 73 65 74
3D 49 53 - /html;charset=IS
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0070 4F 2D 38 38 35 39 2D 31 00 00 0E 43 6F
6E 74 65 - O-8859-1...Conte
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0080 6E 74 2D 4C 65 6E 67 74 68 00 00 01 30
00 00 00 - nt-Length...0...
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_unmarshal_response::jk_ajp_common.c (621): status
= 302
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_unmarshal_response::jk_ajp_common.c (628): Number
of headers is = 3
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_unmarshal_response::jk_ajp_common.c (684):
Header[0] [Location] =
[http://www.mysite.com/index.jsp]
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_unmarshal_response::jk_ajp_common.c (684):
Header[1] [Content-Type] =
[text/html;charset=ISO-8859-1]
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_unmarshal_response::jk_ajp_common.c (684):
Header[2] [Content-Length] = [0]
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): received from ajp13 pos=0 len=2 max=8192
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0000 05 01 00 00 00 00 00 00 00 00 00 00 00
00 00 00 - ................
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
ajp_done::jk_ajp_common.c (2074): recycling connection
cache slot=0 for worker app01
[Wed Feb 22 00:17:00 2006] [8892:31072] app01
www.mysite.com 0.005564 POST /index.jsp
[Wed Feb 22 00:17:00 2006] [8892:31072] [debug]
jk_handler::mod_jk.c (1969): Service finished with
status=302 for worker=app01
#################################################
Everything is great at that point. Then it
redirects... and the subsequent GET works fine, too.
#################################################
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
map_uri_to_worker::jk_uri_worker_map.c (449):
Attempting to map URI '/index.jsp' from 3 maps
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/services/*'
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/servlet/*'
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/*.jsp'
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
map_uri_to_worker::jk_uri_worker_map.c (475): Found a
wildchar match app01 -> /*.jsp
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
jk_handler::mod_jk.c (1839): Into handler
jakarta-servlet worker=app01 r->proxyreq=0
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
wc_get_worker_for_name::jk_worker.c (111): found a
worker app01
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
init_ws_service::mod_jk.c (531): Service
protocol=HTTP/1.1 method=GET host=(null)
addrr=68.125.192.58 name=www.mysite.com port=80
auth=(null) user=(null) laddr=64.62.122.45
raddr=68.125.192.58
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
ajp_get_endpoint::jk_ajp_common.c (2131): acquired
connection cache slot=0
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
ajp_marshal_into_msgb::jk_ajp_common.c (566): ajp
marshaling done
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
ajp_service::jk_ajp_common.c (1670): processing with 3
retries
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): sending to ajp13 pos=4 len=578 max=8192
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0000 12 34 02 3E 02 02 00 08 48 54 54 50 2F
31 2E 31 - .4.>....HTTP/1.1
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0010 00 00 0A 2F 69 6E 64 65 78 2E 6A 73 70
00 00 0D - .../index.jsp...
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0020 36 38 2E 31 32 35 2E 31 39 33 2E 36 39
00 FF FF - 68.125.192.58...
[Wed Feb 22 00:17:00 2006] [8890:22880] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0030 00 13 77 77 77 2E 67
<snip>
#################################################
So that's how it should work, and it does continue to
work this way for a while.
However, at some point later, the POST goes through
just like above, but the subsequent GET after the
redirect seems to get hung up:
First, here's the end of the POST for when it gets
stuck:
#################################################
<snip>
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0070 4F 2D 38 38 35 39 2D 31 00 00 0E 43 6F
6E 74 65 - O-8859-1...Conte
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0080 6E 74 2D 4C 65 6E 67 74 68 00 00 01 30
00 00 00 - nt-Length...0...
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_unmarshal_response::jk_ajp_common.c (621): status
= 302
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_unmarshal_response::jk_ajp_common.c (628): Number
of headers is = 3
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_unmarshal_response::jk_ajp_common.c (684):
Header[0] [Location] =
[http://www.mysite.com/index.jsp]
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_unmarshal_response::jk_ajp_common.c (684):
Header[1] [Content-Type] =
[text/html;charset=ISO-8859-1]
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_unmarshal_response::jk_ajp_common.c (684):
Header[2] [Content-Length] = [0]
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): received from ajp13 pos=0 len=2 max=8192
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0000 05 01 00 00 00 00 00 00 00 00 00 00 00
00 00 00 - ................
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
ajp_done::jk_ajp_common.c (2074): recycling connection
cache slot=0 for worker app01
[Wed Feb 22 00:30:10 2006] [8892:6496] app01
www.mysite.com 0.010245 POST /index.jsp
[Wed Feb 22 00:30:10 2006] [8892:6496] [debug]
jk_handler::mod_jk.c (1969): Service finished with
status=302 for worker=app01
#################################################
Ok, so far so good, right? But now look at what
happens when it tries to redirect:
#################################################
[Wed Feb 22 00:30:10 2006] [8890:6496] [debug]
map_uri_to_worker::jk_uri_worker_map.c (449):
Attempting to map URI '/index.jsp' from 3 maps
[Wed Feb 22 00:30:10 2006] [8890:6496] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/services/*'
[Wed Feb 22 00:30:10 2006] [8890:6496] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/servlet/*'
[Wed Feb 22 00:30:10 2006] [8890:6496] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/*.jsp'
[Wed Feb 22 00:30:10 2006] [8890:6496] [debug]
map_uri_to_worker::jk_uri_worker_map.c (475): Found a
wildchar match app01 -> /*.jsp
[Wed Feb 22 00:30:10 2006] [8890:6496] [debug]
jk_handler::mod_jk.c (1839): Into handler
jakarta-servlet worker=app01 r->proxyreq=0
[Wed Feb 22 00:30:10 2006] [8890:6496] [debug]
wc_get_worker_for_name::jk_worker.c (111): found a
worker app01
[Wed Feb 22 00:30:10 2006] [8890:6496] [debug]
wc_maintain::jk_worker.c (301): Maintaining worker
app01
#################################################
And that's it. Nothing else. It's just stuck.
If I retry the POST, the same thing keeps happening.
The POST goes through, it gets the redirect, it tries
to GET after the redirect, and it just get stuck.
If I restart Apache, everything works again. But,
after time, it eventually starts getting stuck.
I originally started with Apache 2.0.52. Upgraded to
2.0.55. Compiled mod-jk 1.2.15 from scratch.
Upgraded Tomcat to the newest version. All of this
has been no help.
And some more weirdness. Even when it's locked up
like above, some pages do get through just fine!
Here's an example. I'm able to successfully retrieve
/faq.jsp, even though before and after the retrieval,
I still have problems with the redirects from that
POST:
#################################################
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
map_uri_to_worker::jk_uri_worker_map.c (449):
Attempting to map URI '/faq.jsp' from 3 maps
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/services/*'
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/servlet/*'
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
map_uri_to_worker::jk_uri_worker_map.c (461):
Attempting to map context URI '/*.jsp'
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
map_uri_to_worker::jk_uri_worker_map.c (475): Found a
wildchar match app01 -> /*.jsp
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
jk_handler::mod_jk.c (1839): Into handler
jakarta-servlet worker=app01 r->proxyreq=0
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
wc_get_worker_for_name::jk_worker.c (111): found a
worker app01
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
init_ws_service::mod_jk.c (531): Service
protocol=HTTP/1.1 method=GET host=(null)
addrr=68.125.192.58 name=www.mysite.com port=80
auth=(null) user=(null) laddr=64.62.122.45
raddr=68.125.192.58
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_get_endpoint::jk_ajp_common.c (2131): acquired
connection cache slot=0
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_marshal_into_msgb::jk_ajp_common.c (566): ajp
marshaling done
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_service::jk_ajp_common.c (1670): processing with 3
retries
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): sending to ajp13 pos=4 len=561 max=8192
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0000 12 34 02 2D 02 02 00 08 48 54 54 50 2F
31 2E 31 - .4.-....HTTP/1.1
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0010 00 00 08 2F 66 61 71 2E 6A 73 70 00 00
0D 36 38 - .../faq.jsp...68
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0020 2E 31 32 35 2E 31 39 33 2E 36 39 00 FF
FF 00 13 - .125.192.58.....
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0030 77 77 77 2E 67 69 72 6C 6D 61 64 6E 65
73 73 2E - www.mysite.
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c
(909): 0040 63 6F 6D 00
<snip>
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 03d0 69 6E 67 3D 22 30 22 20 63 65 6C 6C 70
61 64 64 - ing="0".cellpadd
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 03e0 69 6E 67 3D 22 37 22 20 62 6F 72 64 65
72 3D 22 - ing="7".border="
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 03f0 30 22 3E 0A 20 20 20 20 20 20 20 20 3C
74 72 3E - 0">.........<tr>
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ws_write::mod_jk.c (412): written 5925 out of 5925
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): received from ajp13 pos=0 len=2 max=8192
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c
(1037): 0000 05 01 00 00 00 00 00 00 00 00 00 00 00
00 00 00 - ................
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
ajp_done::jk_ajp_common.c (2074): recycling connection
cache slot=0 for worker app01
[Wed Feb 22 00:30:22 2006] [8892:18784] app01
www.mysite.com 0.005947 GET /faq.jsp
[Wed Feb 22 00:30:22 2006] [8892:18784] [debug]
jk_handler::mod_jk.c (1969): Service finished with
status=200 for worker=app01
#################################################
I am really stuck here, and would appreciate any
assistance anyone can provide.
Here's my JK settings:
JkWorkersFile
"/usr/local/apache2/conf/workers.properties"
JkRequestLogFormat "%w %V %T %m %U%q"
JkLogFile "/usr/local/apache2/logs/access/mod_jk.log"
JkLogLevel debug
JkShmFile jk.shm
JkMount /*.jsp app01
JkMount /servlet/* app01
JkMount /services/* app01
Here's my worker settings:
(I was originally putting app01 under the lb, but it
had problems. So I tried having jk talk to it
directly as app01.)
# Define 1 real worker using ajp13
worker.list=app01, lb
# Set properties for app01 (ajp13)
worker.app01.type=ajp13
worker.app01.host=10.0.0.9
worker.app01.port=8009
worker.app01.lbfactor=50
worker.app01.socket_keepalive=1
worker.app01.recycle_timeout=300
worker.app01.socket_timeout=2 # if no response in 2
seconds, generate an error and retry again
worker.lb.type=lb
worker.lb.balanced_workers=app01
I appreciate any help anyone can give.
Thanks,
-Michael
__________________________________________________
Do You Yahoo!?
Tired of spam? Yahoo! Mail has the best spam
protection around
http://mail.yahoo.com
__________________________________________________
Do You Yahoo!?
Tired of spam? Yahoo! Mail has the best spam protection around
http://mail.yahoo.com
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
