tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Sebastian Szuber <madpe...@gmail.com>
Subject IIS6 not forwarding requests to Tomcat 5.5
Date Fri, 11 Feb 2011 06:07:57 GMT
Hi!

I have configuration consisting of:
IIS6 on MS Windows Server 2003 R2 Standard Edition SP2
Java 6u23
Tomcat 5.5.32
isapi_redirect 1.2.31

The problem is that each thing separately seems to work but all together not :-(

I've configured context analytics on Tomcat and it works. When I
request static file from this using HTTP connector it works fine.

Also isapi_redirect seems to work fine but when I try to invoke the
same file through IIS it seems that this request somehow is not
received by Tomcat and IIS return 404. It is recorded in isapi log but
no trace of it in Tomcat logs (I have RequestDumperValve and
AccessLogValve configured).
Any ideas what may be wrong? How to debug it?

Please see logs and config files below.

Regards,
Sebastian.

1. AJP Connector is starting
Feb 11, 2011 4:55:25 AM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
Feb 11, 2011 4:55:25 AM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/15  config=null
Feb 11, 2011 4:55:25 AM org.apache.catalina.storeconfig.StoreLoader load
INFO: Find registry server-registry.xml at classpath resource
Feb 11, 2011 4:55:25 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 1813 ms

2. RequestDumperValve is logging HTTP Connector request
Feb 11, 2011 4:55:37 AM org.apache.catalina.valves.RequestDumperValve invoke
INFO: REQUEST URI       =/analytics/res/Salsa_Glossary_en.htm
...

3. AccessLogValve is logging HTTP Connector request
127.0.0.1 - - [11/Feb/2011:04:55:37 +0000] "GET
/analytics/res/Salsa_Glossary_en.htm HTTP/1.1" 304 -

4. isapi_redirector registry config is
[HKEY_LOCAL_MACHINE\SOFTWARE\Apache Software Foundation\Jakarta Isapi
Redirector\1.0]
"extension_uri"="/jakarta/isapi_redirect.dll"
"log_file"="E:\\tomcat-connector\\isapi.log"
"log_level"="debug"
"worker_file"="E:\\tomcat-connector\\workers.properties"
"worker_mount_file"="E:\\tomcat-connector\\uriworkermap.properties"

5. workers.properties content
# Define 1 worker
worker.list=worker2
# Set properties for worker2 (ajp13)
worker.worker2.type=ajp13
worker.worker2.host=localhost
worker.worker2.port=8009
worker.worker2.lbfactor=1
worker.worker2.connection_pool_timeout=600
worker.worker2.socket_keepalive=1
worker.worker2.socket_timeout=60

6. uriworkermap.properties content
/analytics/*=worker2

7. isapi_redirector is starting fine
[Fri Feb 11 04:56:27.783 2011] [5716:6760] [debug]
jk_set_time_fmt::jk_util.c (459): Pre-processed log time stamp format
is '[%a %b %d %H:%M:%S.000 %Y] '
[Fri Feb 11 04:56:27.799 2011] [5716:6760] [info]
init_jk::jk_isapi_plugin.c (2562): Starting
Jakarta/ISAPI/isapi_redirector/1.2.31 (1026297)

[Fri Feb 11 04:56:27.799 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2580): Detected IIS version 6.0

[Fri Feb 11 04:56:27.815 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2585): Using registry.

[Fri Feb 11 04:56:27.815 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2588): Using log file
E:\tomcat-connector\isapi.log.

[Fri Feb 11 04:56:27.815 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2589): Using log level 1.

[Fri Feb 11 04:56:27.815 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2590): Using log rotation time 0 seconds.

[Fri Feb 11 04:56:27.815 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2591): Using log file size 0 bytes.

[Fri Feb 11 04:56:27.830 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2593): Using extension uri
/jakarta/isapi_redirect.dll.

[Fri Feb 11 04:56:27.830 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2594): Using worker file
E:\tomcat-connector\workers.properties.

[Fri Feb 11 04:56:27.830 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2595): Using worker mount file
E:\tomcat-connector\uriworkermap.properties.

[Fri Feb 11 04:56:27.830 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2597): Using rewrite rule file .

[Fri Feb 11 04:56:27.830 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2599): Using uri select 3.

[Fri Feb 11 04:56:27.846 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2600): Using no chunked encoding.

[Fri Feb 11 04:56:27.846 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2602): Using notification event
SF_NOTIFY_AUTH_COMPLETE (0x04000000)

[Fri Feb 11 04:56:27.846 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2612): Using uri header
TOMCATURI6A6B0000:.

[Fri Feb 11 04:56:27.846 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2613): Using query header
TOMCATQUERY6A6B0000:.

[Fri Feb 11 04:56:27.861 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2614): Using worker header
TOMCATWORKER6A6B0000:.

[Fri Feb 11 04:56:27.861 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2615): Using worker index
TOMCATWORKERIDX6A6B0000:.

[Fri Feb 11 04:56:27.861 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2616): Using translate header
TOMCATTRANSLATE6A6B0000:.

[Fri Feb 11 04:56:27.861 2011] [5716:6760] [debug]
init_jk::jk_isapi_plugin.c (2617): Using a default of 250 connections
per pool.

[Fri Feb 11 04:56:27.877 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property '/analytics/*'
with value 'worker2' to map.

[Fri Feb 11 04:56:27.877 2011] [5716:6760] [debug]
uri_worker_map_load::jk_uri_worker_map.c (1102): Loading urimaps from
E:\tomcat-connector\uriworkermap.properties with reload check interval
60 seconds

[Fri Feb 11 04:56:27.877 2011] [5716:6760] [debug]
uri_worker_map_add::jk_uri_worker_map.c (720): wildchar rule
'/analytics/*=worker2' source 'uriworkermap' was added

[Fri Feb 11 04:56:27.877 2011] [5716:6760] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (171): uri map dump after
file load: index=0 file='E:\tomcat-connector\uriworkermap.properties'
reject_unsafe=0 reload=60 modified=1296949945 checked=1297400187

[Fri Feb 11 04:56:27.877 2011] [5716:6760] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (176): generation 0: size=0
nosize=0 capacity=0

[Fri Feb 11 04:56:27.893 2011] [5716:6760] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (176): generation 1: size=1
nosize=0 capacity=4

[Fri Feb 11 04:56:27.893 2011] [5716:6760] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (186): NEXT (1) map #0:
uri=/analytics/* worker=worker2 context=/analytics/*
source=uriworkermap type=Wildchar len=12

[Fri Feb 11 04:56:27.893 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property 'worker.list'
with value 'worker2' to map.

[Fri Feb 11 04:56:27.893 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property
'worker.worker2.type' with value 'ajp13' to map.

[Fri Feb 11 04:56:27.908 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property
'worker.worker2.host' with value 'localhost' to map.

[Fri Feb 11 04:56:27.908 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property
'worker.worker2.port' with value '8009' to map.

[Fri Feb 11 04:56:27.908 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property
'worker.worker2.lbfactor' with value '1' to map.

[Fri Feb 11 04:56:27.908 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property
'worker.worker2.connection_pool_timeout' with value '600' to map.

[Fri Feb 11 04:56:27.908 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property
'worker.worker2.socket_keepalive' with value '1' to map.

[Fri Feb 11 04:56:27.924 2011] [5716:6760] [debug]
jk_map_read_property::jk_map.c (491): Adding property
'worker.worker2.socket_timeout' with value '60' to map.

[Fri Feb 11 04:56:27.924 2011] [5716:6760] [debug]
jk_map_resolve_references::jk_map.c (777): Checking for references
with prefix worker. with wildcard (recursion 1)

[Fri Feb 11 04:56:27.924 2011] [5716:6760] [debug]
jk_shm_calculate_size::jk_shm.c (132): shared memory will contain 1
ajp workers of size 320 and 0 lb workers of size 320 with 0 members of
size 384+320

[Fri Feb 11 04:56:27.924 2011] [5716:6760] [debug]
jk_shm_open::jk_shm.c (254): Initialized shared memory
JKISAPISHMEM_LOCALHOST_1 size=448 free=320 addr=0x1b50000

[Fri Feb 11 04:56:27.940 2011] [5716:6760] [debug]
jk_map_dump::jk_map.c (589): Dump of map: 'worker.list' -> 'worker2'

[Fri Feb 11 04:56:27.940 2011] [5716:6760] [debug]
jk_map_dump::jk_map.c (589): Dump of map: 'worker.worker2.type' ->
'ajp13'

[Fri Feb 11 04:56:27.940 2011] [5716:6760] [debug]
jk_map_dump::jk_map.c (589): Dump of map: 'worker.worker2.host' ->
'localhost'

[Fri Feb 11 04:56:27.955 2011] [5716:6760] [debug]
jk_map_dump::jk_map.c (589): Dump of map: 'worker.worker2.port' ->
'8009'

[Fri Feb 11 04:56:27.955 2011] [5716:6760] [debug]
jk_map_dump::jk_map.c (589): Dump of map: 'worker.worker2.lbfactor' ->
'1'

[Fri Feb 11 04:56:27.955 2011] [5716:6760] [debug]
jk_map_dump::jk_map.c (589): Dump of map:
'worker.worker2.connection_pool_timeout' -> '600'

[Fri Feb 11 04:56:27.955 2011] [5716:6760] [debug]
jk_map_dump::jk_map.c (589): Dump of map:
'worker.worker2.socket_keepalive' -> '1'

[Fri Feb 11 04:56:27.971 2011] [5716:6760] [debug]
jk_map_dump::jk_map.c (589): Dump of map:
'worker.worker2.socket_timeout' -> '60'

[Fri Feb 11 04:56:27.971 2011] [5716:6760] [debug]
build_worker_map::jk_worker.c (242): creating worker worker2

[Fri Feb 11 04:56:27.971 2011] [5716:6760] [debug]
wc_create_worker::jk_worker.c (146): about to create instance worker2
of ajp13

[Fri Feb 11 04:56:27.971 2011] [5716:6760] [debug]
wc_create_worker::jk_worker.c (159): about to validate and init
worker2

[Fri Feb 11 04:56:27.971 2011] [5716:6760] [debug]
ajp_validate::jk_ajp_common.c (2608): worker worker2 contact is
'localhost:8009'

[Fri Feb 11 04:56:27.986 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2803): setting endpoint options:

[Fri Feb 11 04:56:27.986 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2806): keepalive:              1

[Fri Feb 11 04:56:27.986 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2810): socket timeout:         60

[Fri Feb 11 04:56:27.986 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2814): socket connect timeout: 60000

[Fri Feb 11 04:56:28.002 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2818): buffer size:            0

[Fri Feb 11 04:56:28.002 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2822): pool timeout:           600

[Fri Feb 11 04:56:28.002 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2826): ping timeout:           10000

[Fri Feb 11 04:56:28.002 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2830): connect timeout:        0

[Fri Feb 11 04:56:28.002 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2834): reply timeout:          0

[Fri Feb 11 04:56:28.002 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2838): prepost timeout:        0

[Fri Feb 11 04:56:28.018 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2842): recovery options:       0

[Fri Feb 11 04:56:28.018 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2846): retries:                2

[Fri Feb 11 04:56:28.018 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2850): max packet size:        8192

[Fri Feb 11 04:56:28.018 2011] [5716:6760] [debug]
ajp_init::jk_ajp_common.c (2854): retry interval:         100

[Fri Feb 11 04:56:28.018 2011] [5716:6760] [debug]
ajp_create_endpoint_cache::jk_ajp_common.c (2665): setting connection
pool size to 250 with min 125 and acquire timeout 200

[Fri Feb 11 04:56:28.033 2011] [5716:6760] [debug]
wc_get_worker_for_name::jk_worker.c (116): found a worker worker2

[Fri Feb 11 04:56:28.033 2011] [5716:6760] [debug]
wc_get_name_for_type::jk_worker.c (293): Found worker type 'ajp13'

[Fri Feb 11 04:56:28.033 2011] [5716:6760] [debug]
uri_worker_map_ext::jk_uri_worker_map.c (512): Checking extension for
worker 0: worker2 of type ajp13 (2)

[Fri Feb 11 04:56:28.033 2011] [5716:6760] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (171): uri map dump after
extension stripping: index=0
file='E:\tomcat-connector\uriworkermap.properties' reject_unsafe=0
reload=60 modified=1296949945 checked=1297400187

[Fri Feb 11 04:56:28.049 2011] [5716:6760] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (176): generation 0: size=0
nosize=0 capacity=0

[Fri Feb 11 04:56:28.049 2011] [5716:6760] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (176): generation 1: size=1
nosize=0 capacity=4

[Fri Feb 11 04:56:28.049 2011] [5716:6760] [debug]
uri_worker_map_dump::jk_uri_worker_map.c (186): NEXT (1) map #0:
uri=/analytics/* worker=worker2 context=/analytics/*
source=uriworkermap type=Wildchar len=12

[Fri Feb 11 04:56:28.049 2011] [5716:6760] [debug]
uri_worker_map_switch::jk_uri_worker_map.c (482): Switching uri worker
map from index 0 to index 1

[Fri Feb 11 04:56:28.049 2011] [5716:6760] [info]
init_jk::jk_isapi_plugin.c (2741):
Jakarta/ISAPI/isapi_redirector/1.2.31 (1026297) initialized

[Fri Feb 11 04:56:28.065 2011] [5716:6760] [debug]
HttpFilterProc::jk_isapi_plugin.c (1851): Filter started

8. isapi_redirector is processing request
[Fri Feb 11 04:56:28.065 2011] [5716:6760] [debug]
map_uri_to_worker_ext::jk_uri_worker_map.c (1036): Attempting to map
URI '/localhost/analytics/res/Salsa_Glossary_en.htm' from 1 maps

[Fri Feb 11 04:56:28.065 2011] [5716:6760] [debug]
find_match::jk_uri_worker_map.c (850): Attempting to map context URI
'/analytics/*=worker2' source 'uriworkermap'

[Fri Feb 11 04:56:28.065 2011] [5716:6760] [debug]
find_match::jk_uri_worker_map.c (850): Attempting to map context URI
'/analytics/*=worker2' source 'uriworkermap'

[Fri Feb 11 04:56:28.065 2011] [5716:6760] [debug]
find_match::jk_uri_worker_map.c (863): Found a wildchar match
'/analytics/*=worker2'

[Fri Feb 11 04:56:28.065 2011] [5716:6760] [debug]
HttpFilterProc::jk_isapi_plugin.c (1938): check if
[/analytics/res/Salsa_Glossary_en.htm] points to the web-inf directory

[Fri Feb 11 04:56:28.065 2011] [5716:6760] [debug]
HttpFilterProc::jk_isapi_plugin.c (1954):
[/analytics/res/Salsa_Glossary_en.htm] is a servlet url - should
redirect to worker2

[Fri Feb 11 04:56:28.080 2011] [5716:6760] [debug]
HttpFilterProc::jk_isapi_plugin.c (1994): fowarding escaped URI
[/analytics/res/Salsa_Glossary_en.htm]


9. but then
- IIS returns 404 error page
- no trace of this request in Tomcat logs of RequestDumperValve and
AccessLogValve
- no any errors recorded in isapi log nor tomcat log

???

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Mime
View raw message