Mod_jk logs errors but users report none

apache-2.2mod-jk

We have an apache server load balancing requests for downloads to two different servers. The mod_jk error log is filled with the following kind of errors

[Mon Feb 13 16:59:02.948 2012] [19453:139726932305664] [error] ajp_process_callback::jk_ajp_common.c (1800): ajp_unmarshal_response failed
[Mon Feb 13 16:59:02.948 2012] [19453:139726932305664] [info] ajp_service::jk_ajp_common.c (2540): (mrxdf3) sending request to tomcat failed (recoverable), because of server error (attempt=1)
[Mon Feb 13 16:59:03.048 2012] [19453:139726932305664] [info] ajp_send_request::jk_ajp_common.c (1490): (mrxdf3) did not receive END_RESPONSE, closing socket -1
[Mon Feb 13 16:59:03.054 2012] [19453:139726932305664] [error] ajp_unmarshal_response::jk_ajp_common.c (646): NULL status
[Mon Feb 13 16:59:03.054 2012] [19453:139726932305664] [error] ajp_process_callback::jk_ajp_common.c (1800): ajp_unmarshal_response failed
[Mon Feb 13 16:59:03.054 2012] [19453:139726932305664] [info] ajp_service::jk_ajp_common.c (2540): (mrxdf3) sending request to tomcat failed (recoverable), because of server error (attempt=2)
[Mon Feb 13 16:59:03.054 2012] [19453:139726932305664] [error] ajp_service::jk_ajp_common.c (2559): (mrxdf3) connecting to tomcat failed.
[Mon Feb 13 16:59:03.054 2012] [19453:139726932305664] [info] service::jk_lb_worker.c (1388): service failed, worker mrxdf3 is in error state
[Mon Feb 13 16:59:03.159 2012] [19453:139726932305664] [error] ajp_unmarshal_response::jk_ajp_common.c (646): NULL status
[Mon Feb 13 16:59:03.159 2012] [19453:139726932305664] [error] ajp_process_callback::jk_ajp_common.c (1800): ajp_unmarshal_response failed
[Mon Feb 13 16:59:03.159 2012] [19453:139726932305664] [info] ajp_service::jk_ajp_common.c (2540): (mrxdf2) sending request to tomcat failed (recoverable), because of server error (attempt=1)
[Mon Feb 13 16:59:03.259 2012] [19453:139726932305664] [info] ajp_send_request::jk_ajp_common.c (1490): (mrxdf2) did not receive END_RESPONSE, closing socket -1
[Mon Feb 13 16:59:03.263 2012] [19453:139726932305664] [error] ajp_unmarshal_response::jk_ajp_common.c (646): NULL status
[Mon Feb 13 16:59:03.264 2012] [19453:139726932305664] [error] ajp_process_callback::jk_ajp_common.c (1800): ajp_unmarshal_response failed
[Mon Feb 13 16:59:03.264 2012] [19453:139726932305664] [info] ajp_service::jk_ajp_common.c (2540): (mrxdf2) sending request to tomcat failed (recoverable), because of server error (attempt=2)
[Mon Feb 13 16:59:03.264 2012] [19453:139726932305664] [error] ajp_service::jk_ajp_common.c (2559): (mrxdf2) connecting to tomcat failed.
[Mon Feb 13 16:59:03.264 2012] [19453:139726932305664] [info] service::jk_lb_worker.c (1388): service failed, worker mrxdf2 is in local error state
[Mon Feb 13 16:59:03.264 2012] [19453:139726932305664] [info] service::jk_lb_worker.c (1457): All tomcat instances failed, no more workers left (attempt=1, retry=1)
[Mon Feb 13 16:59:03.264 2012] [19453:139726932305664] [info] service::jk_lb_worker.c (1468): All tomcat instances are busy or in error state
[Mon Feb 13 16:59:03.264 2012] [19453:139726932305664] [error] service::jk_lb_worker.c (1473): All tomcat instances failed, no more workers left
[Mon Feb 13 16:59:03.264 2012] [19453:139726932305664] [info] jk_handler::mod_jk.c (2618): Service error=0 for worker=lb_df_ajp13

We monitor the status and get a bit worried about the various servers switching from ok to error to ok to error…..

The thing is the only indication we have of an error is this. There are no reports that actual errors are happening. Users do not report broken downloads or not being able to reach the servers.

this is the mod_jk conf

# Minimal jk configuration
JkWorkerProperty worker.list=ajp13,api_ajp13,app_ajp13,status_ajp13,lb_df_ajp13

# web server
JkWorkerProperty worker.ajp13.type=ajp13
JkWorkerProperty worker.ajp13.host=web0.live.mbuyu.nl
JkWorkerProperty worker.ajp13.port=8009

# app
JkWorkerProperty worker.app_ajp13.type=ajp13
JkWorkerProperty worker.app_ajp13.host=app0.live.mbuyu.nl
JkWorkerProperty worker.app_ajp13.port=8009

# api server
JkWorkerProperty worker.api_ajp13.type=ajp13
JkWorkerProperty worker.api_ajp13.host=api0.live.mbuyu.nl
JkWorkerProperty worker.api_ajp13.port=8009

# DF Node0
JkWorkerProperty worker.mrxdf2.type=ajp13
JkWorkerProperty worker.mrxdf2.host=df2.live.mbuyu.nl
JkWorkerProperty worker.mrxdf2.port=8009
JkWorkerProperty worker.mrxdf2.lbfactor=1
# DF Node1
JkWorkerProperty worker.mrxdf3.type=ajp13
JkWorkerProperty worker.mrxdf3.host=df3.live.mbuyu.nl
JkWorkerProperty worker.mrxdf3.port=8009
JkWorkerProperty worker.mrxdf3.lbfactor=1

# JK Status worker
JkWorkerProperty worker.status_ajp13.type=status

# Load-balancer
JkWorkerProperty worker.lb_df_ajp13.type=lb
JkWorkerProperty worker.lb_df_ajp13.balanced_workers=mrxdf2,mrxdf3
JkWorkerProperty worker.lb_df_ajp13.sticky_session=1
JkWorkerProperty worker.lb_df_ajp13.local_worker_only=1

Should we be worried? Can we get rid of this?

mod_jk version = 1.2.30
apache 2.2.16
The download servers run JBoss 6.1.

btw, I'm actually a developer not a sysadmin but I get asked for help on that side occasionally. In this case the sysadmin wants to know what's wrong with the application of course. All I can say is nothing I can find either internally or externally. We are now in the very negative situation of ignoring an error warning because we think nothing is actually going wrong.

Best Answer

I don't know exactly for your problem but you should:

1/ Setup timeouts to your config file http://tomcat.apache.org/connectors-doc/generic_howto/timeouts.html

2/ If it's not already done, log or graph your ajp connection pool. You can get values from jboss for ajp threads and ajp connections using the jmx console or snmp https://community.jboss.org/wiki/JBossSNMPAdapter .

Related Topic