Bug#609886: Fwd: Bug#609886: libapache2-mod-jk: After upgrade from 1.2.26 to 1.2.30 mod_jk no longer connects to tomcats

Miguel Landaeta miguel at miguel.cc
Fri Jan 21 22:14:03 UTC 2011


---------- Forwarded message ----------
From: Vamegh Hedayati <vamegh at gmail.com>
Date: Fri, Jan 21, 2011 at 8:03 AM
Subject: Re: Bug#609886: libapache2-mod-jk: After upgrade from 1.2.26
to 1.2.30 mod_jk no longer connects to tomcats
To: Miguel Landaeta <miguel at miguel.cc>


Hi Miguel,

I guess the best way I can replicate this is to switch back to the
mod_jk from debian and show you what happens.

My setup is completely default. I am using openjdk and apache2.2 from
debian unstable, the server is
just my own play server and as far as web is concerned it is basically
a completely fresh install.

my website is www.vamegh.co.uk

I have the following in /etc/apache2/conf.d/jk.conf

<ifmodule mod_jk.c>
 # Where to find workers.properties
 # Update this path to match your conf directory location (put
workers.properties next to httpd.conf)
 JkWorkersFile /etc/apache2/workers.properties
 # Where to put jk shared memory
 # Update this path to match your local state directory or logs directory
 # JkShmFile     /var/log/apache2/mod_jk.shm
 # Where to put jk logs
 # Update this path to match your logs directory location (put
mod_jk.log next to access_log)
 JkLogFile     /var/log/apache2/mod_jk.log
 # Set the jk log level [debug/error/info]
 JkLogLevel    debug
 # Select the timestamp log format
 # JkLogStampFormat "[%a %b %d %H:%M:%S %Y] "
 # Send everything for context /examples to worker named worker1 (ajp13)
 # JkMount  /examples/* worker1
</ifmodule>


I downloaded the binary mod_jk from apache as I already mentioned and
put it into:

ls -al /usr/lib/apache2/modules/|grep mod_jk
-rw-r--r-- 1 root root 394007 Nov  1 05:42 mod_jk-1.2.31-httpd-2.2.x.so
lrwxrwxrwx 1 root root     28 Jan 20 19:24 mod_jk2.so ->
mod_jk-1.2.31-httpd-2.2.x.so
-rw-r--r-- 1 root root 421760 Jul 24 01:08 mod_jk.so

and in

cat /etc/apache2/mods-enabled/jk.load
LoadModule jk_module /usr/lib/apache2/modules/mod_jk.so

All I do is switch mod_jk.so to mod_jk2.so to run the apache
pre-compiled binary vs the debian provided binary.. So if everything
else is equal we know that the only changing thing is this jk
connector.

Now, just to test I have switched it back to mod_jk.so and I get the
following when trying to visit www.vamegh.co.uk/test.jsp

tail -f /var/log/apache2/mod_jk.log
[Fri Jan 21 13:14:43.761 2011] [19849:140364869056320] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (186): NEXT (1) map #0:
uri=/*.jsp worker=default context=/*.jsp source=JkMount type=Wildchar
len=6
[Fri Jan 21 13:14:43.761 2011] [19849:140364869056320] [debug]
uri_worker_map_switch::jk_uri_worker_map.c (482): Switching uri worker
map from index 0 to index 1
[Fri Jan 21 13:14:43.762 2011] [19851:140364869056320] [debug]
do_shm_open::jk_shm.c (550): Attached shared memory
/var/log/apache2/jk-runtime-status.19849 [2] size=448 free=0
addr=0x7fa93e295000
[Fri Jan 21 13:14:43.763 2011] [19851:140364869056320] [debug]
do_shm_open::jk_shm.c (564): Resetting the shared memory for child 2
[Fri Jan 21 13:14:43.763 2011] [19851:140364869056320] [debug]
do_shm_open_lock::jk_shm.c (353): Duplicated shared memory lock
/var/log/apache2/jk-runtime-status.19849.lock
[Fri Jan 21 13:14:43.763 2011] [19851:140364869056320] [debug]
jk_child_init::mod_jk.c (3073): Initialized mod_jk/1.2.30
[Fri Jan 21 13:14:43.765 2011] [19856:140364869056320] [debug]
do_shm_open::jk_shm.c (550): Attached shared memory
/var/log/apache2/jk-runtime-status.19849 [3] size=448 free=320
addr=0x7fa93e295000
[Fri Jan 21 13:14:43.765 2011] [19856:140364869056320] [debug]
do_shm_open::jk_shm.c (564): Resetting the shared memory for child 3
[Fri Jan 21 13:14:43.765 2011] [19856:140364869056320] [debug]
do_shm_open_lock::jk_shm.c (353): Duplicated shared memory lock
/var/log/apache2/jk-runtime-status.19849.lock
[Fri Jan 21 13:14:43.765 2011] [19856:140364869056320] [debug]
jk_child_init::mod_jk.c (3073): Initialized mod_jk/1.2.30










[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
map_uri_to_worker_ext::jk_uri_worker_map.c (1036): Attempting to map
URI '/test.jsp' from 1 maps
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
find_match::jk_uri_worker_map.c (850): Attempting to map context URI
'/*.jsp=default' source 'JkMount'
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
find_match::jk_uri_worker_map.c (863): Found a wildchar match
'/*.jsp=default'
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
jk_handler::mod_jk.c (2462): Into handler jakarta-servlet
worker=default r->proxyreq=0
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
wc_get_worker_for_name::jk_worker.c (116): found a worker default
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
wc_maintain::jk_worker.c (339): Maintaining worker default
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
wc_get_name_for_type::jk_worker.c (293): Found worker type 'ajp13'
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
init_ws_service::mod_jk.c (978): Service protocol=HTTP/1.1 method=GET
ssl=false host=(null) addr=92.7.95.44 name=www.vamegh.co.uk port=80
auth=(null) user=(null) laddr=188.40.198.20 raddr=92.7.95.44
uri=/test.jsp
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
ajp_get_endpoint::jk_ajp_common.c (3093): acquired connection pool
slot=0 after 0 retries
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
ajp_marshal_into_msgb::jk_ajp_common.c (605): ajp marshaling done
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
ajp_service::jk_ajp_common.c (2376): processing default with 2 retries
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
ajp_send_request::jk_ajp_common.c (1579): (default) all endpoints are
disconnected.
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [error]
jk_open_socket::jk_connect.c (444): socket() failed (errno=22)
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [info]
ajp_connect_to_endpoint::jk_ajp_common.c (959): Failed opening socket
to (127.0.0.1:8009) (errno=22)
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [error]
ajp_send_request::jk_ajp_common.c (1585): (default) connecting to
backend failed. Tomcat is probably not started or is listening on the
wrong port (errno=22)
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [info]
ajp_service::jk_ajp_common.c (2540): (default) sending request to
tomcat failed (recoverable), because of error during request sending
(attempt=1)
[Fri Jan 21 13:15:17.954 2011] [19851:140364785633040] [debug]
ajp_service::jk_ajp_common.c (2397): retry 1, sleeping for 100 ms
before retrying
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [debug]
ajp_send_request::jk_ajp_common.c (1579): (default) all endpoints are
disconnected.
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [error]
jk_open_socket::jk_connect.c (444): socket() failed (errno=22)
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [info]
ajp_connect_to_endpoint::jk_ajp_common.c (959): Failed opening socket
to (127.0.0.1:8009) (errno=22)
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [error]
ajp_send_request::jk_ajp_common.c (1585): (default) connecting to
backend failed. Tomcat is probably not started or is listening on the
wrong port (errno=22)
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [info]
ajp_service::jk_ajp_common.c (2540): (default) sending request to
tomcat failed (recoverable), because of error during request sending
(attempt=2)
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [error]
ajp_service::jk_ajp_common.c (2559): (default) connecting to tomcat
failed.
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [debug]
ajp_reset_endpoint::jk_ajp_common.c (757): (default) resetting
endpoint with sd = 4294967295 (socket shutdown)
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [debug]
ajp_done::jk_ajp_common.c (3010): recycling connection pool slot=0 for
worker default
[Fri Jan 21 13:15:18.055 2011] [19851:140364785633040] [info]
jk_handler::mod_jk.c (2618): Service error=-3 for worker=default
^C



On the actual website I get  an error 503

Service Temporarily Unavailable.

The server is temporarily unable to service your request due to
maintenance downtime or capacity problems. Please try again later.


As  further demonstration, I will just change mod_jk.so to mod_jk2.so
in the jk.load file and the following happens:


# vi jk.load
web01:/etc/apache2/mods-enabled# /etc/init.d/apache2 restart
Restarting web server: apache2 ... waiting .
web01:/etc/apache2/mods-enabled# tail -f /var/log/apache2/mod_jk.log
[Fri Jan 21 13:27:37.460 2011] [19963:140417008375616] [debug]
wc_get_worker_for_name::jk_worker.c (116): found a worker default
[Fri Jan 21 13:27:37.460 2011] [19963:140417008375616] [debug]
wc_get_name_for_type::jk_worker.c (293): Found worker type 'ajp13'
[Fri Jan 21 13:27:37.460 2011] [19963:140417008375616] [debug]
uri_worker_map_ext::jk_uri_worker_map.c (512): Checking extension for
worker 0: default of type ajp13 (2)
[Fri Jan 21 13:27:37.460 2011] [19963:140417008375616] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (171): uri map dump after
extension stripping: index=0 file='(null)' reject_unsafe=0 reload=60
modified=0 checked=0
[Fri Jan 21 13:27:37.460 2011] [19963:140417008375616] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (176): generation 0: size=0
nosize=0 capacity=0
[Fri Jan 21 13:27:37.460 2011] [19963:140417008375616] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (176): generation 1: size=1
nosize=0 capacity=4
[Fri Jan 21 13:27:37.460 2011] [19963:140417008375616] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (186): NEXT (1) map #0:
uri=/*.jsp worker=default context=/*.jsp source=JkMount type=Wildchar
len=6
[Fri Jan 21 13:27:37.460 2011] [19963:140417008375616] [debug]
uri_worker_map_switch::jk_uri_worker_map.c (482): Switching uri worker
map from index 0 to index 1
[Fri Jan 21 13:27:37.462 2011] [19965:140417008375616] [debug]
jk_child_init::mod_jk.c (3082): Initialized mod_jk/1.2.31 (1026297)
[Fri Jan 21 13:27:37.464 2011] [19970:140417008375616] [debug]
jk_child_init::mod_jk.c (3082): Initialized mod_jk/1.2.31 (1026297)




[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
map_uri_to_worker_ext::jk_uri_worker_map.c (1036): Attempting to map
URI '/test.jsp' from 1 maps
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
find_match::jk_uri_worker_map.c (850): Attempting to map context URI
'/*.jsp=default' source 'JkMount'
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
find_match::jk_uri_worker_map.c (863): Found a wildchar match
'/*.jsp=default'
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
jk_handler::mod_jk.c (2471): Into handler jakarta-servlet
worker=default r->proxyreq=0
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
wc_get_worker_for_name::jk_worker.c (116): found a worker default
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
wc_maintain::jk_worker.c (339): Maintaining worker default
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
wc_get_name_for_type::jk_worker.c (293): Found worker type 'ajp13'
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
init_ws_service::mod_jk.c (987): Service protocol=HTTP/1.1 method=GET
ssl=false host=(null) addr=92.7.95.44 name=www.vamegh.co.uk port=80
auth=(null) user=(null) laddr=188.40.198.20 raddr=92.7.95.44
uri=/test.jsp
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_get_endpoint::jk_ajp_common.c (3096): acquired connection pool
slot=0 after 0 retries
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_marshal_into_msgb::jk_ajp_common.c (605): ajp marshaling done
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_service::jk_ajp_common.c (2379): processing default with 2 retries
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_send_request::jk_ajp_common.c (1572): (default) all endpoints are
disconnected.
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
jk_open_socket::jk_connect.c (484): socket TCP_NODELAY set to On
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
jk_open_socket::jk_connect.c (608): trying to connect socket 14 to
127.0.0.1:8009
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
jk_open_socket::jk_connect.c (634): socket 14 [127.0.0.1:45441 ->
127.0.0.1:8009] connected
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): sending to
ajp13 pos=4 len=509 max=8192
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0000    12 34
01 F9 02 02 00 08 48 54 54 50 2F 31 2E 31  - .4......HTTP/1.1
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0010    00 00
09 2F 74 65 73 74 2E 6A 73 70 00 00 0A 39  - .../test.jsp...9
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0020    32 2E
37 2E 39 35 2E 34 34 00 FF FF 00 10 77 77  - 2.7.95.44.....ww
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0030    77 2E
76 61 6D 65 67 68 2E 63 6F 2E 75 6B 00 00  - w.vamegh.co.uk..
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0040    50 00
00 09 A0 0B 00 10 77 77 77 2E 76 61 6D 65  - P.......www.vame
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0050    67 68
2E 63 6F 2E 75 6B 00 A0 06 00 0A 6B 65 65  - gh.co.uk.....kee
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0060    70 2D
61 6C 69 76 65 00 00 0D 43 61 63 68 65 2D  - p-alive...Cache-
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0070    43 6F
6E 74 72 6F 6C 00 00 09 6D 61 78 2D 61 67  - Control...max-ag
[Fri Jan 21 13:27:54.822 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0080    65 3D
30 00 A0 01 00 5A 61 70 70 6C 69 63 61 74  - e=0....Zapplicat
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0090    69 6F
6E 2F 78 6D 6C 2C 61 70 70 6C 69 63 61 74  - ion/xml,applicat
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 00a0    69 6F
6E 2F 78 68 74 6D 6C 2B 78 6D 6C 2C 74 65  - ion/xhtml+xml,te
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 00b0    78 74
2F 68 74 6D 6C 3B 71 3D 30 2E 39 2C 74 65  - xt/html;q=0.9,te
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 00c0    78 74
2F 70 6C 61 69 6E 3B 71 3D 30 2E 38 2C 69  - xt/plain;q=0.8,i
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 00d0    6D 61
67 65 2F 70 6E 67 2C 2A 2F 2A 3B 71 3D 30  - mage/png,*/*;q=0
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 00e0    2E 35
00 A0 0E 00 93 4D 6F 7A 69 6C 6C 61 2F 35  - .5.....Mozilla/5
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 00f0    2E 30
20 28 58 31 31 3B 20 55 3B 20 4C 69 6E 75  - .0.(X11;.U;.Linu
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0100    78 20
78 38 36 5F 36 34 3B 20 65 6E 2D 55 53 29  - x.x86_64;.en-US)
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0110    20 41
70 70 6C 65 57 65 62 4B 69 74 2F 35 33 34  - .AppleWebKit/534
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0120    2E 31
30 20 28 4B 48 54 4D 4C 2C 20 6C 69 6B 65  - .10.(KHTML,.like
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0130    20 47
65 63 6B 6F 29 20 55 62 75 6E 74 75 2F 31  - .Gecko).Ubuntu/1
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0140    30 2E
31 30 20 43 68 72 6F 6D 69 75 6D 2F 38 2E  - 0.10.Chromium/8.
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0150    30 2E
35 35 32 2E 32 33 37 20 43 68 72 6F 6D 65  - 0.552.237.Chrome
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0160    2F 38
2E 30 2E 35 35 32 2E 32 33 37 20 53 61 66  - /8.0.552.237.Saf
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0170    61 72
69 2F 35 33 34 2E 31 30 00 00 0F 41 63 63  - ari/534.10...Acc
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0180    65 70
74 2D 45 6E 63 6F 64 69 6E 67 00 00 11 67  - ept-Encoding...g
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 0190    7A 69
70 2C 64 65 66 6C 61 74 65 2C 73 64 63 68  - zip,deflate,sdch
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 01a0    00 00
0F 41 63 63 65 70 74 2D 4C 61 6E 67 75 61  - ...Accept-Langua
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 01b0    67 65
00 00 0E 65 6E 2D 55 53 2C 65 6E 3B 71 3D  - ge...en-US,en;q=
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 01c0    30 2E
38 00 00 0E 41 63 63 65 70 74 2D 43 68 61  - 0.8...Accept-Cha
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 01d0    72 73
65 74 00 00 1E 49 53 4F 2D 38 38 35 39 2D  - rset...ISO-8859-
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 01e0    31 2C
75 74 66 2D 38 3B 71 3D 30 2E 37 2C 2A 3B  - 1,utf-8;q=0.7,*;
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1145): 01f0    71 3D
30 2E 33 00 A0 08 00 01 30 00 FF 00 00 00  - q=0.3.....0.....
[Fri Jan 21 13:27:54.823 2011] [19965:140416925001488] [debug]
ajp_send_request::jk_ajp_common.c (1632): (default) request body to
send 0 - request body to resend 0
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from
ajp13 pos=0 len=109 max=8192
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    04 00
C8 00 02 4F 4B 00 00 02 A0 07 00 3D 4A 53  - .....OK......=JS
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0010    45 53
53 49 4F 4E 49 44 3D 46 46 32 32 31 31 42  - ESSIONID=FF2211B
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0020    44 38
41 33 46 36 45 39 34 46 41 31 44 46 44 32  - D8A3F6E94FA1DFD2
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0030    35 34
44 30 36 42 30 33 30 3B 20 50 61 74 68 3D  - 54D06B030;.Path=
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0040    2F 3B
20 48 74 74 70 4F 6E 6C 79 00 A0 01 00 1C  - /;.HttpOnly.....
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0050    74 65
78 74 2F 68 74 6D 6C 3B 63 68 61 72 73 65  - text/html;charse
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0060    74 3D
49 53 4F 2D 38 38 35 39 2D 31 00 00 00 00  - t=ISO-8859-1....
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_unmarshal_response::jk_ajp_common.c (660): status = 200
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_unmarshal_response::jk_ajp_common.c (667): Number of headers is =
2
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_unmarshal_response::jk_ajp_common.c (723): Header[0] [Set-Cookie]
= [JSESSIONID=FF2211BD8A3F6E94FA1DFD254D06B030; Path=/; HttpOnly]
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_unmarshal_response::jk_ajp_common.c (723): Header[1]
[Content-Type] = [text/html;charset=ISO-8859-1]
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from
ajp13 pos=0 len=4 max=8192
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    03 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00  - ................
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from
ajp13 pos=0 len=176 max=8192
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    03 00
AC 3C 68 74 6D 6C 3E 0A 20 20 20 20 3C 68  - ...<html>.....<h
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0010    65 61
64 3E 0A 20 20 20 20 20 20 20 20 3C 74 69  - ead>.........<ti
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0020    74 6C
65 3E 48 65 6C 6C 6F 20 57 6F 72 6C 64 3C  - tle>Hello.World<
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0030    2F 74
69 74 6C 65 3E 0A 20 20 20 20 3C 2F 68 65  - /title>.....</he
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0040    61 64
3E 0A 20 20 20 20 3C 62 6F 64 79 3E 0A 20  - ad>.....<body>..
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0050    20 20
20 20 20 20 20 3C 68 31 3E 48 65 6C 6C 6F  - .......<h1>Hello
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0060    20 57
6F 72 6C 64 3C 2F 68 31 3E 0A 20 20 20 20  - .World</h1>.....
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0070    20 20
20 20 54 6F 64 61 79 20 69 73 3A 20 46 72  - ....Today.is:.Fr
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0080    69 20
4A 61 6E 20 32 31 20 31 33 3A 32 37 3A 35  - i.Jan.21.13:27:5
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0090    34 20
43 45 54 20 32 30 31 31 0A 20 20 20 20 3C  - 4.CET.2011.....<
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 00a0    2F 62
6F 64 79 3E 0A 3C 2F 68 74 6D 6C 3E 0A 00  - /body>.</html>..
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ws_write::mod_jk.c (508): written 172 out of 172
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from
ajp13 pos=0 len=4 max=8192
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    03 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00  - ................
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from
ajp13 pos=0 len=4 max=8192
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    03 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00  - ................
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from
ajp13 pos=0 len=2 max=8192
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    05 01
00 00 00 00 00 00 00 00 00 00 00 00 00 00  - ................
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_process_callback::jk_ajp_common.c (1943): AJP13 protocol: Reuse is
OK
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_reset_endpoint::jk_ajp_common.c (757): (default) resetting
endpoint with socket 14
[Fri Jan 21 13:27:54.826 2011] [19965:140416925001488] [debug]
ajp_done::jk_ajp_common.c (3013): recycling connection pool slot=0 for
worker default
[Fri Jan 21 13:27:54.827 2011] [19965:140416925001488] [debug]
jk_handler::mod_jk.c (2611): Service finished with status=200 for
worker=default
^C


The test page loads without a problem. I can provide further configs
or any further tests you need, please let me know, but I think this
definitely does show some sort of issue with the debian mod_jk binary.

Kind Regards,

Vamegh







On 21 January 2011 01:09, Miguel Landaeta <miguel at miguel.cc> wrote:
> Hi Vamegh,
> (I'm posting this to 609886 at bugs.debian.org).
>
> On Thu, Jan 20, 2011 at 6:33 PM, Vamegh Hedayati <vamegh at gmail.com> wrote:
>> Hi Miguel,
>>
>> This I think is a definite bug, sorry I replied to the thread, but it
>> hasnt shown up, sorry if you already have seen this.
>>
>> I had this exact same issue over the last 2 days, I upgraded my server
>> to Debian unstable and it would constantly give me the same error as
>> eyck.
>>
>> I did also notice that the following line:
>>
>> <Connector port="8009" protocol="AJP/1.3" redirectPort="8443" />
>>
>> Had been commented out and re-enabled it, checked using lsof saw the
>> port running verified it, but would still get the same error in mod_jk
>> log file.
>>
>> I then installed tomcat7 and still had the same issue and was
>> searching for the problem and came across this bug report.
>>
>> To test if this was in fact the issue, I downloaded the binary
>> mod_jk.so from apache website directly, from:
>>
>> wget http://www.apache.org/dist/tomcat/tomcat-connectors/jk/binaries/linux/jk-1.2.31/x86_64/mod_jk-1.2.31-httpd-2.2.x.so
>>
>> Using this all of my problems are now solved and it works.
>>
>> The mod_jk I was using is as follows:
>>
>> apt-cache show libapache2-mod-jk
>> Package: libapache2-mod-jk
>> Priority: optional
>> Section: net
>> Installed-Size: 380
>> Maintainer: Debian Java Maintainers <pkg-java-
>> maintainers at lists.alioth.debian.org>
>> Architecture: amd64
>> Source: libapache-mod-jk
>> Version: 1:1.2.26-2+lenny1
>> Replaces: libapache2-mod-jk2
>> Depends: libc6 (>= 2.7-1), apache2.2-common, apache2
>> Suggests: tomcat5.5, libapache-mod-jk-doc
>> Conflicts: libapache2-mod-jk2
>> Filename: pool/main/liba/libapache-mod-jk/libapache2-mod-
>> jk_1.2.26-2+lenny1_amd64.deb
>> Size: 127806
>> MD5sum: 84fe833769ac2a4cda17fb6f48b3ca6d
>> SHA1: a71b97b35d5b1fb5c1fd075bba64b01481baf16e
>> SHA256:
>> 1729cd1f48e633830bacea9a2fdc8e57bd7b635aed133f5dbcb683b8cf634b8e
>> Description: Apache 2 connector for the Tomcat Java servlet engine
>>  Apache Tomcat is the reference implementation for the Java Servlet
>> and
>>  JavaServer Pages (JSP) specification from the Apache Jakarta project.
>>  .
>>  This package contains an Apache 2 module (mod_jk) to forward requests
>>  from Apache to Tomcat using the AJP 1.3 or 1.4 protocol. It can
>> either
>>  talk to Tomcat on the local machine or to a remote engine using TCP.
>> Homepage: http://tomcat.apache.org/
>> Tag: role::shared-lib, suite::apache
>>
>> Package: libapache2-mod-jk
>> Priority: optional
>> Section: httpd
>> Installed-Size: 508
>> Maintainer: Debian Java Maintainers <pkg-java-
>> maintainers at lists.alioth.debian.org>
>> Architecture: amd64
>> Source: libapache-mod-jk
>> Version: 1:1.2.30-1
>> Replaces: libapache2-mod-jk2
>> Depends: libc6 (>= 2.3), apache2.2-common, apache2
>> Suggests: tomcat6, libapache-mod-jk-doc
>> Conflicts: libapache2-mod-jk2
>> Filename: pool/main/liba/libapache-mod-jk/libapache2-mod-
>> jk_1.2.30-1_amd64.deb
>> Size: 148966
>> MD5sum: 49b4fa9b59f3a6df6441c19cb3345e13
>> SHA1: b8d396d5be2189c0e45ce0a394625f332fc8c69d
>> SHA256:
>> 38479b41a41e7c436b90b240ccf15819fee8215d2bc37f6b8d5e0e684a580b8c
>> Description: Apache 2 connector for the Tomcat Java servlet engine
>>  Apache Tomcat is the reference implementation for the Java Servlet
>> and
>>  JavaServer Pages (JSP) specification from the Apache Jakarta project.
>>  .
>>  This package contains an Apache 2 module (mod_jk) to forward requests
>>  from Apache to Tomcat using the AJP 1.3 or 1.4 protocol. It can
>> either
>>  talk to Tomcat on the local machine or to a remote engine using TCP.
>> Homepage: http://tomcat.apache.org/
>> Tag: role::shared-lib, suite::apache
>>
>> I hope this helps, but I definitely think there is an issue with the
>> current unstable version of mod_jk it has communication issues, I
>> tried several tests over the last couple of days, so I am pretty
>> confident there is a bug with it.
>>
>> If you need anything else from me please let me know, I can forward
>> you all of my logs or anything else you need.
>>
>> All the best,
>
> It would be very useful if you can include logs and
> a more detailed description of how reproduce this.
> Please describe if you have an unusual configuration.
>
> I'm going to take another look at this, but as
> I said previously I only could reproduce the reported
> situation due to a issue with default tomcat6 configuration
> that is not well documented.
>
> I'm going to try also with jetty and tomcat7, if this is really
> a problem with libapache2-mod-jk, it should not be that
> hard to reproduce it.
>
> Cheers,
>
> --
> Miguel Landaeta, miguel at miguel.cc
> secure email with PGP 0x7D8967E9 available at http://keyserver.pgp.com/
> "Faith means not wanting to know what is true." -- Nietzsche
>



-- 
Miguel Landaeta, miguel at miguel.cc
secure email with PGP 0x7D8967E9 available at http://keyserver.pgp.com/
"Faith means not wanting to know what is true." -- Nietzsche





More information about the pkg-java-maintainers mailing list