tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From André Warnier ...@ice-sa.com>
Subject Re: 404 with mod_jk
Date Wed, 14 Jul 2010 10:13:11 GMT
Mmmm. Taking into account all previous communications, this looks really strange.  It 
looks as if mod_jk is being called, is finding a match with its URI map, but then is not 
even making any attempt at contacting the Tomcat worker...

On the other hand, assuming that your IBM webserver is some clone of Apache (which is what

the configuration looks like), then I find your <VirtualHost> section rather strange.
One would normally expect something like

Listen 80
NameVirtualHosts *:80
...
<VirtualHost *:80>
   ServerName localhost
...
</VirtualHost>

I don't know if this could interfere with mod_jk, but maybe it does.


Michael Powe wrote:
> Hello,
> 
> Thanks again for looking at this.  Here are the log entries
> corresponding to a jsp page request.
> 
> [Wed Jul 14 05:42:57 2010] [15992:48036720] [trace] map_uri_to_worker_ext::jk_uri_worker_map.c
(951): enter
> [Wed Jul 14 05:42:57 2010] [15992:48036720] [debug] map_uri_to_worker_ext::jk_uri_worker_map.c
(1036): Attempting to map URI '/TlTaggerTest/target.jsp' from 1 maps 
> [Wed Jul 14 05:42:57 2010] [15992:48036720] [trace] find_match::jk_uri_worker_map.c (839):
enter
> [Wed Jul 14 05:42:57 2010] [15992:48036720] [debug] find_match::jk_uri_worker_map.c (850):
Attempting to map context URI '/TlTaggerTest/*.jsp=worker1' source 'JkMount' 
> [Wed Jul 14 05:42:57 2010] [15992:48036720] [debug] find_match::jk_uri_worker_map.c (863):
Found a wildchar match '/TlTaggerTest/*.jsp=worker1'
> [Wed Jul 14 05:42:57 2010] [15992:48036720] [trace] find_match::jk_uri_worker_map.c (866):
exit
> [Wed Jul 14 05:42:57 2010] [15992:48036720] [trace] map_uri_to_worker_ext::jk_uri_worker_map.c
(1065): exit
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [trace] map_uri_to_worker_ext::jk_uri_worker_map.c
(951): enter
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [debug] map_uri_to_worker_ext::jk_uri_worker_map.c
(1036): Attempting to map URI '/favicon.ico' from 1 maps
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [trace] find_match::jk_uri_worker_map.c (839):
enter
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [debug] find_match::jk_uri_worker_map.c (850):
Attempting to map context URI '/TlTaggerTest/*.jsp=worker1' source 'JkMount'
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [trace] find_match::jk_uri_worker_map.c (882):
exit
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [trace] map_uri_to_worker_ext::jk_uri_worker_map.c
(1068): exit
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [debug] jk_translate::mod_jk.c (3542): no
match for /favicon.ico found
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [trace] map_uri_to_worker_ext::jk_uri_worker_map.c
(951): enter
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [debug] map_uri_to_worker_ext::jk_uri_worker_map.c
(1036): Attempting to map URI '/favicon.ico' from 1 maps
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [trace] find_match::jk_uri_worker_map.c (839):
enter
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [debug] find_match::jk_uri_worker_map.c (850):
Attempting to map context URI '/TlTaggerTest/*.jsp=worker1' source 'JkMount'
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [trace] find_match::jk_uri_worker_map.c (882):
exit
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [trace] map_uri_to_worker_ext::jk_uri_worker_map.c
(1068): exit
> [Wed Jul 14 05:43:00 2010] [15992:48036720] [debug] jk_map_to_storage::mod_jk.c (3609):
no match for /favicon.ico found
> 
> I hate top-posting but these log entries have made this email
> ridiculously long; plus, I'm ssh'ed into a terminal window and some
> emacs key strokes are intercepted locally, so editing is somewhat
> limited. 
> 
> Thanks again.
> 
> mp
> 
> On Wed, Jul 14, 2010 at 11:09:19AM +0200, Rainer Jung wrote:
>> On 14.07.2010 04:57, Michael Powe wrote:
>>> Hello,
>>>
>>> Thank you for the reply.
>>>
>>> See below for comments.
>>>
>>> On Wed, Jul 14, 2010 at 12:37:05AM +0200, Rainer Jung wrote:
>>>
>>>> On 13.07.2010 23:17, Michael Powe wrote:
>>>>> Hello,
>>>>>
>>>>> I asked this question in the httpd list but no joy.
>>>>>
>>>>> I have set up tomcat 6 and IBM httpd server to proxy requests using
>>>>> mod_jk.
>>>>>
>>>>> IBM_HTTP_Server/6.0.2 Apache/2.0.47 (Unix) mod_jk/1.2.30 Server at
>>>>> localhost Port 80
>>>>>
>>>>> I have followed all instructions as nearly as I can make
>>>>> out.
>>>>>
>>>> Since you already have trace logging enabled:
>>>>
>>>> - is this all that gets logged in the jk log file for the request?
>>> I rotated the mod_jk log and restarted the server.  I get a huge trace
>>> log, 33K.  It appears to me to be initializing correctly, in the sense
>>> that there are no error messages.
>>>
>>>> - can you see your worker "worker1" getting configured during startup
>>>> (debug log messages)?
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> uri_worker_map_dump::jk_uri_worker_map.c (195): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> uri_worker_map_open::jk_uri_worker_map.c (830): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> uri_worker_map_alloc::jk_uri_worker_map.c (240): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] init_jk::mod_jk.c 
>>> (3112): Using fcntl() for locking.
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] init_jk::mod_jk.c 
>>> (3128): Setting default connection pool max size to 25
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> jk_map_read_property::jk_map.c (491): Adding property 'worker.list' with 
>>> value 'worker1' to map.
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> jk_map_read_property::jk_map.c (491): Adding property 
>>> 'worker.worker1.type' with value 'ajp13' to map.
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> jk_map_read_property::jk_map.c (491): Adding property 
>>> 'worker.worker1.host' with value 'localhost' to map.
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> jk_map_read_property::jk_map.c (491): Adding property 
>>> 'worker.worker1.port' with value '8009' to map.
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> jk_map_resolve_references::jk_map.c (766): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> jk_map_resolve_references::jk_map.c (774): Checking for references with 
>>> prefix worker. with wildcard (recursion 1)
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> jk_map_resolve_references::jk_map.c (830): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> jk_shm_calculate_size::jk_shm.c (97): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> jk_shm_calculate_size::jk_shm.c (132): shared memory will contain 1 ajp 
>>> workers of size 256 and 0 lb workers of size 320 with 0 members of size 
>>> 320+256
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> jk_shm_calculate_size::jk_shm.c (139): exit
>>>
>>> [ ... ]
>>>
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] wc_open::jk_worker.c 
>>> (50): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] jk_map_dump::jk_map.c 
>>> (589): Dump of map: 'ServerRoot' ->  '/opt/IBMIHS'
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] jk_map_dump::jk_map.c 
>>> (589): Dump of map: 'worker.list' ->  'worker1'
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] jk_map_dump::jk_map.c 
>>> (589): Dump of map: 'worker.worker1.type' ->  'ajp13'
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] jk_map_dump::jk_map.c 
>>> (589): Dump of map: 'worker.worker1.host' ->  'localhost'
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] jk_map_dump::jk_map.c 
>>> (589): Dump of map: 'worker.worker1.port' ->  '8009'
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> build_worker_map::jk_worker.c (236): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> build_worker_map::jk_worker.c (242): creating worker worker1
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> wc_create_worker::jk_worker.c (126): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> wc_create_worker::jk_worker.c (146): about to create instance worker1 of 
>>> ajp13
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp13_worker_factory::jk_ajp13_worker.c (80): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp_worker_factory::jk_ajp_common.c (2892): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp_worker_factory::jk_ajp_common.c (2934): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp13_worker_factory::jk_ajp13_worker.c (92): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> wc_create_worker::jk_worker.c (159): about to validate and init worker1
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> validate::jk_ajp13_worker.c (35): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp_validate::jk_ajp_common.c (2579): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_validate::jk_ajp_common.c (2605): worker worker1 contact is 
>>> 'localhost:8009'
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> jk_resolve::jk_connect.c (329): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> jk_resolve::jk_connect.c (406): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp_validate::jk_ajp_common.c (2616): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> validate::jk_ajp13_worker.c (37): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] init::jk_ajp13_worker.c 
>>> (47): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp_init::jk_ajp_common.c (2700): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2800): setting endpoint options:
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2803): keepalive:              0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2807): socket timeout:         0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2811): socket connect timeout: 0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2815): buffer size:            0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2819): pool timeout:           0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2823): ping timeout:           10000
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2827): connect timeout:        0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2831): reply timeout:          0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2835): prepost timeout:        0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2839): recovery options:       0
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2843): retries:                2
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2847): max packet size:        8192
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_init::jk_ajp_common.c (2851): retry interval:         100
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp_create_endpoint_cache::jk_ajp_common.c (2653): enter
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [debug] 
>>> ajp_create_endpoint_cache::jk_ajp_common.c (2662): setting connection pool 
>>> size to 25 with min 13 and acquire timeout 200
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp_create_endpoint_cache::jk_ajp_common.c (2688): exit
>>> [Tue Jul 13 22:21:00 2010] [12002:3987136] [trace] 
>>> ajp_init::jk_ajp_common.c (2883): exit
>>>
>>>> - anything in the httpd error log? Maybe your mod_jk module file is not
>>>> really compatible with your web server binary and you get process crashes?
>>> After the server restart, the following:
>>>
>>> [Tue Jul 13 22:21:00 2010] [notice] suEXEC mechanism enabled (wrapper: 
>>> /opt/IBMIHS/bin/suexec)
>>> [Tue Jul 13 22:21:02 2010] [notice] IBM_HTTP_Server/6.0.2 Apache/2.0.47 
>>> (Unix) mod_jk/1.2.30 configured -- resuming normal operations
>>> [Tue Jul 13 22:21:02 2010] [notice] Core file limit is 0; core dumps will 
>>> be not be written for server crashes
>>>
>>> Attempt to reach URL http://localhost/TlTaggerTest/target.jsp:
>>>
>>> [Tue Jul 13 22:39:46 2010] [error] [client 127.0.0.1] File does not exist: 
>>> target.jsp
>>>
>>>> If those remarks do not help, we will need your configuration and more
>>>> complete logs.
>>> From httpd.conf:
>>>
>>> <VirtualHost localhost>
>>>     ServerName localhost
>>>     DocumentRoot "/opt/IBMIHS/htdocs/en_US"
>>>     CustomLog logs/vhost_local_access_log combined
>>>
>>> #    JkMount /manager ajp13
>>> #    JkMount /manager/* ajp13
>>> #
>>> #    JkMount /helloworld ajp13
>>> #    JkMount /helloworld/* ajp13
>>> #
>>> #    JkMount /docs ajp13
>>> #    JkMount /docs/* ajp13
>>> #
>>> #    JkMount /host-manager ajp13
>>> #    JkMount /host-manager/* ajp13
>>>
>>>     JkMount /TlTaggerTest/*.jsp worker1
>>> </VirtualHost>
>>>
>>> Your help is really appreciated.
>> Thanks for the info, the startup looks good assuming that there were no 
>> non-debug non-trace lines.
>>
>> One piece is missing, namely the full log lines from the time sending 
>> the test request to the return of the 404. My first question aimed at 
>> asking, whether the few log lines you provided contained really 
>> everything that gets logged by mod_jk during handling the test request 
>> (excluding startup).
>>
>> Regards,
>>
>> Rainer
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
> 


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


Mime
View raw message