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

    Apache2 to JBoss 4.0.3SP1 mod_jk problem

    jozef nuesclh Newbie

      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
      -------------------------------
      -------------------------------