3 Replies Latest reply on Jan 12, 2006 2:36 PM by blindmen

Apache2 to JBoss 4.0.3SP1 mod_jk problem

blindmen Jan 11, 2006 9:22 AM

I'm trying to redirect url form apache to jboss (tomcat5.5)

My apache config file for this

------------
LoadModule jk_module /usr/lib/apache2/modules/mod_jk.so

JkWorkersFile /etc/apache2/workers.properties

JkLogFile /var/log/apache2/mod_jk.log

JkLogLevel debug

JkLogStampFormat "[%a %b %d %H:%M:%S %Y]"

JkOptions +ForwardKeySize +ForwardURICompat -ForwardDirectories

JkRequestLogFormat "%w %V %T"

JkMount /doctore/* node1

#JkMountFile /etc/apache2/uriworkermap.properties

JkShmFile /var/log/apache2/jk.shm

#<Location /jkstatus/>
#JkMount status
#Order deny,allow
#Deny from all
#Allow from all
#</Location>
------------------

workers file

------------------
worker.list=node1

worker.node1.port=8009
worker.node1.host=82.119.104.134
worker.node1.type=ajp13
worker.node1.cachesize=10
------------------

I changed tomcat configs

server.xml file like this

------
<Engine name="jboss.web" defaultHost="localhost" jvmRoute="node1">
------

and jboss-service.xml

UseJk
-----
true
-----

when i try to access /web-console i get this error message from apache

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

and next log

----------------------
-----------------------
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] map_uri_to_worker::jk_uri_worker_map.c (449): Attempting to map URI '/web-console' from 2 maps
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] map_uri_to_worker::jk_uri_worker_map.c (461): Attempting to map context URI '/web-console/*'
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] map_uri_to_worker::jk_uri_worker_map.c (461): Attempting to map context URI '/web-console'
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] map_uri_to_worker::jk_uri_worker_map.c (486): Found an exact match node1 -> /web-console
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] jk_handler::mod_jk.c (1839): Into handler jakarta-servlet worker=node1 r->proxyreq=0
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] wc_get_worker_for_name::jk_worker.c (111): found a worker node1
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] wc_maintain::jk_worker.c (301): Maintaining worker node1
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] init_ws_service::mod_jk.c (531): Service protocol=HTTP/1.0 method=GET host=(null) addrr=147.175.167.8 name=82.119.104.134 port=80 auth=(null) user=(null) laddr=82.119.104.134 raddr=147.175.167.8
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] ajp_get_endpoint::jk_ajp_common.c (2131): acquired connection cache slot=0
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] ajp_marshal_into_msgb::jk_ajp_common.c (566): ajp marshaling done
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] ajp_service::jk_ajp_common.c (1670): processing with 3 retries
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] jk_open_socket::jk_connect.c (328): socket TCP_NODELAY set to On
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] jk_open_socket::jk_connect.c (426): trying to connect socket 15 to 82.119.104.134:8009
[Wed Jan 11 15:12:48 2006][3527:0000] [info] jk_open_socket::jk_connect.c (444): connect to 82.119.104.134:8009 failed with errno=22
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_connect_to_endpoint::jk_ajp_common.c (889): Failed opening socket to (82.119.104.134:8009) with (errno=22)
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_send_request::jk_ajp_common.c (1248): Error connecting to the Tomcat process.
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=1
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] jk_open_socket::jk_connect.c (328): socket TCP_NODELAY set to On
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] jk_open_socket::jk_connect.c (426): trying to connect socket 15 to 82.119.104.134:8009
[Wed Jan 11 15:12:48 2006][3527:0000] [info] jk_open_socket::jk_connect.c (444): connect to 82.119.104.134:8009 failed with errno=22
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_connect_to_endpoint::jk_ajp_common.c (889): Failed opening socket to (82.119.104.134:8009) with (errno=22)
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_send_request::jk_ajp_common.c (1248): Error connecting to the Tomcat process.
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=2
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] jk_open_socket::jk_connect.c (328): socket TCP_NODELAY set to On
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] jk_open_socket::jk_connect.c (426): trying to connect socket 15 to 82.119.104.134:8009
[Wed Jan 11 15:12:48 2006][3527:0000] [info] jk_open_socket::jk_connect.c (444): connect to 82.119.104.134:8009 failed with errno=22
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_connect_to_endpoint::jk_ajp_common.c (889): Failed opening socket to (82.119.104.134:8009) with (errno=22)
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_send_request::jk_ajp_common.c (1248): Error connecting to the Tomcat process.
[Wed Jan 11 15:12:48 2006][3527:0000] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=3
[Wed Jan 11 15:12:48 2006][3527:0000] [error] ajp_service::jk_ajp_common.c (1758): Error connecting to tomcat. Tomcat is probably not started or is listening on the wrong port. worker=node1 failed
[Wed Jan 11 15:12:48 2006][3527:0000] [debug] ajp_done::jk_ajp_common.c (2074): recycling connection cache slot=0 for worker node1
[Wed Jan 11 15:12:48 2006][3527:0000] node1 82.119.104.134 0.000531

[Wed Jan 11 15:12:48 2006][3527:0000] [info] jk_handler::mod_jk.c (1985): Service error=0 for worker=node1
-----------------------
-----------------------

my netstat command :

Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 0 0 *:cvspserver *:* LISTEN 971/inetd
tcp 0 0 *:imaps *:* LISTEN 971/inetd
tcp 0 0 *:afpovertcp *:* LISTEN 991/afpd
tcp 0 0 *:smux *:* LISTEN 1070/snmpd
tcp 0 0 *:8009 *:* LISTEN 3309/java
tcp 0 0 *:1098 *:* LISTEN 3309/java
tcp 0 0 *:rmiregistry *:* LISTEN 3309/java
tcp 0 0 *:pop3 *:* LISTEN 971/inetd
tcp 0 0 *:imap2 *:* LISTEN 971/inetd
tcp 0 0 *:sunrpc *:* LISTEN 763/portmap
tcp 0 0 *:www *:* LISTEN 3526/apache2
tcp 0 0 *:webcache *:* LISTEN 3309/java
tcp 0 0 *:auth *:* LISTEN 971/inetd
tcp 0 0 *:8083 *:* LISTEN 3309/java
tcp 0 0 *:ssh *:* LISTEN 1075/sshd
tcp 0 0 *:postgresql *:* LISTEN 1051/postmaster
tcp 0 0 *:smtp *:* LISTEN 965/exim4
tcp 0 0 *:4444 *:* LISTEN 3309/java
tcp 0 0 *:8093 *:* LISTEN 3309/java
tcp 0 0 *:4445 *:* LISTEN 3309/java
udp 0 0 *:snmp *:* 1070/snmpd
udp 0 0 *:bootpc *:* 1112/dhclient
udp 0 0 *:sunrpc *:* 763/portmap
raw 0 0 *:icmp *:* 7 1113/ping
Active UNIX domain sockets (only servers)
Proto RefCnt Flags Type State I-Node PID/Program name Path
unix 2 [ ACC ] STREAM LISTENING 1350 1051/postmaster /var/run/postgresql/.s.PGSQL.5432
unix 2 [ ACC ] STREAM LISTENING 1234 976/lpd /dev/printer

Where the hell is problem ??
I loose few days troubleshooting this please help.
JBoss start without errors
btw: I'm using mod_jk_1.2.15

----------------
15:04:26,534 INFO [UILServerILService] JBossMQ UIL service available at : /0.0.0.0:8093
15:04:26,608 INFO [DLQ] Bound to JNDI name: queue/DLQ
15:04:27,033 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name=JmsXA' to JNDI name 'java:JmsXA'
15:04:28,029 INFO [TomcatDeployer] deploy, ctxPath=/doctore2, warUrl=.../tmp/deploy/tmp22807doctore2.war/
15:04:28,200 INFO [PropertyMessageResources] Initializing, config='org.apache.struts.util.LocalStrings', returnNull=true
15:04:28,201 INFO [PropertyMessageResources] Initializing, config='org.apache.struts.action.ActionResources', returnNull=true
15:04:30,222 INFO [PropertyMessageResources] Initializing, config='com.doctore.struts.ApplicationResources', returnNull=true
15:04:30,263 INFO [TomcatDeployer] deploy, ctxPath=/jmx-console, warUrl=.../deploy/jmx-console.war/
15:04:30,837 INFO [Http11Protocol] Starting Coyote HTTP/1.1 on http-0.0.0.0-8080
15:04:30,969 INFO [ChannelSocket] JK: ajp13 listening on /0.0.0.0:8009
15:04:31,019 INFO [JkMain] Jk running ID=0 time=0/65 config=null
15:04:31,028 INFO [Server] JBoss (MX MicroKernel)
----------------

After starting apache i get this log in mo_jk.log

--------------------------------
-------------------------------
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] do_shm_open::jk_shm.c (291): Truncated shared memory to 67584
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] do_shm_open::jk_shm.c (323): Initialized shared memory size=67584 free=65536 addr=0x40c6a000
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] do_shm_open_lock::jk_shm.c (233): Opened shared memory lock /var/log/apache2/jk.shm.lock
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] init_jk::mod_jk.c (2364): Initialized shm:/var/log/apache2/jk.shm
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] uri_worker_map_open::jk_uri_worker_map.c (323): rule map size is 2
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] uri_worker_map_add::jk_uri_worker_map.c (268): exact rule /web-console=node1 was added
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] uri_worker_map_add::jk_uri_worker_map.c (260): wildchar rule /web-console/*=node1 was added
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] uri_worker_map_open::jk_uri_worker_map.c (340): there are 2 rules
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] build_worker_map::jk_worker.c (236): creating worker node1
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] wc_create_worker::jk_worker.c (141): about to create instance node1 of ajp13
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] wc_create_worker::jk_worker.c (154): about to validate and init node1
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_validate::jk_ajp_common.c (1806): worker node1 contact is '82.119.104.134:8009'
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1895): setting socket keepalive to 0
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1934): setting socket timeout to -1
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1938): setting socket buffer size to 0
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1942): setting connection recycle timeout to 0
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1946): setting cache timeout to 0
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1950): setting connect timeout to 0
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1954): setting reply timeout to 0
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1958): setting prepost timeout to 0
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1962): setting recovery opts to 0
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_init::jk_ajp_common.c (1966): setting number of retries to 3
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] ajp_create_endpoint_cache::jk_ajp_common.c (1843): setting connection cache size to 10
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] build_worker_map::jk_worker.c (248): removing old node1 worker
[Wed Jan 11 15:10:26 2006][3524:0000] [debug] jk_cleanup_shmem::mod_jk.c (1761): Shmem cleanup
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] do_shm_open::jk_shm.c (291): Truncated shared memory to 67584
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] do_shm_open::jk_shm.c (323): Initialized shared memory size=67584 free=65536 addr=0x40d7a000
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] do_shm_open_lock::jk_shm.c (233): Opened shared memory lock /var/log/apache2/jk.shm.lock
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] init_jk::mod_jk.c (2364): Initialized shm:/var/log/apache2/jk.shm
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] uri_worker_map_open::jk_uri_worker_map.c (323): rule map size is 2
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] uri_worker_map_add::jk_uri_worker_map.c (268): exact rule /web-console=node1 was added
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] uri_worker_map_add::jk_uri_worker_map.c (260): wildchar rule /web-console/*=node1 was added
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] uri_worker_map_open::jk_uri_worker_map.c (340): there are 2 rules
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] build_worker_map::jk_worker.c (236): creating worker node1
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] wc_create_worker::jk_worker.c (141): about to create instance node1 of ajp13
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] wc_create_worker::jk_worker.c (154): about to validate and init node1
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_validate::jk_ajp_common.c (1806): worker node1 contact is '82.119.104.134:8009'
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1895): setting socket keepalive to 0
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1934): setting socket timeout to -1
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1938): setting socket buffer size to 0
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1942): setting connection recycle timeout to 0
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1946): setting cache timeout to 0
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1950): setting connect timeout to 0
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1954): setting reply timeout to 0
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1958): setting prepost timeout to 0
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1962): setting recovery opts to 0
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_init::jk_ajp_common.c (1966): setting number of retries to 3
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] ajp_create_endpoint_cache::jk_ajp_common.c (1843): setting connection cache size to 10
[Wed Jan 11 15:10:26 2006][3526:0000] [debug] build_worker_map::jk_worker.c (248): removing old node1 worker
[Wed Jan 11 15:10:26 2006][3527:0000] [debug] do_shm_open::jk_shm.c (251): Shared memory is already open
[Wed Jan 11 15:10:26 2006][3527:0000] [debug] jk_child_init::mod_jk.c (2320): Attached shm:/var/log/apache2/jk.shm
[Wed Jan 11 15:10:26 2006][3527:0000] [debug] jk_child_init::mod_jk.c (2330): Initialized mod_jk/1.2.15
[Wed Jan 11 15:10:26 2006][3528:0000] [debug] do_shm_open::jk_shm.c (251): Shared memory is already open
[Wed Jan 11 15:10:26 2006][3528:0000] [debug] jk_child_init::mod_jk.c (2320): Attached shm:/var/log/apache2/jk.shm
[Wed Jan 11 15:10:26 2006][3528:0000] [debug] jk_child_init::mod_jk.c (2330): Initialized mod_jk/1.2.15
[Wed Jan 11 15:10:26 2006][3529:0000] [debug] do_shm_open::jk_shm.c (251): Shared memory is already open
[Wed Jan 11 15:10:26 2006][3529:0000] [debug] jk_child_init::mod_jk.c (2320): Attached shm:/var/log/apache2/jk.shm
[Wed Jan 11 15:10:26 2006][3529:0000] [debug] jk_child_init::mod_jk.c (2330): Initialized mod_jk/1.2.15
[Wed Jan 11 15:10:26 2006][3530:0000] [debug] do_shm_open::jk_shm.c (251): Shared memory is already open
[Wed Jan 11 15:10:26 2006][3530:0000] [debug] jk_child_init::mod_jk.c (2320): Attached shm:/var/log/apache2/jk.shm
[Wed Jan 11 15:10:26 2006][3530:0000] [debug] jk_child_init::mod_jk.c (2330): Initialized mod_jk/1.2.15
[Wed Jan 11 15:10:26 2006][3531:0000] [debug] do_shm_open::jk_shm.c (251): Shared memory is already open
[Wed Jan 11 15:10:26 2006][3531:0000] [debug] jk_child_init::mod_jk.c (2320): Attached shm:/var/log/apache2/jk.shm
[Wed Jan 11 15:10:26 2006][3531:0000] [debug] jk_child_init::mod_jk.c (2330): Initialized mod_jk/1.2.15
-------------------------------
-------------------------------

1. Re: Apache2 to JBoss 4.0.3SP1 mod_jk problem

swarne111 Jan 11, 2006 12:17 PM (in response to blindmen)

Look here:

http://www.techienuggets.com/Detail?tx=4
Actions
2. Re: Apache2 to JBoss 4.0.3SP1 mod_jk problem

blindmen Jan 11, 2006 4:11 PM (in response to blindmen)

Well i tried the same approach before (with loadbalancer) but it wasn't working. I got the same error message as now.

I don't know where the problem could be because apache wants to connect to jboss ip is ok no firewall rules set. jboss is listening as i can see from netstat command

Do u have any ideas ? where can be a problem ?
Could it be in bad binary mod_jk ? but it was compiled witout errors ...
Actions
3. Re: Apache2 to JBoss 4.0.3SP1 mod_jk problem

blindmen Jan 12, 2006 2:36 PM (in response to blindmen)

Actually the problem is probably in jboss because I can't telnet to the port 8009.
But startup log is saying that service is up, and also netstat shows that 8009 port is open and listening ?
Could it be in security settings of linux that is refusing telnet connection ???
Actions

Go to original post