Created attachment 27818 [details] default value for request_rec.status In case JkLogFormat contains "%s" (Request HTTP status) placeholder - it is not always shows correct codes. If there are no workers available - mod_jk records 200 (HTTP_OK) in logs, while httpd records and shows 503 error: <<access.log: 172.16.16.1 - - [19/Oct/2011:10:35:01 +0300] "GET / HTTP/1.1" 503 323 <<mod_jk.log: [Wed Oct 19 10:35:01.906 2011] [2053:3086162528] [error] ajp_send_request::jk_ajp_common.c (1630): (devel) connecting to backend failed. Tomcat is probably not started or is listening on the wrong port (errno=111) [Wed Oct 19 10:35:01.906 2011] [2053:3086162528] [error] ajp_send_request::jk_ajp_common.c (1630): (devel) connecting to backend failed. Tomcat is probably not started or is listening on the wrong port (errno=111) [Wed Oct 19 10:35:01.906 2011] [2053:3086162528] [error] ajp_service::jk_ajp_common.c (2626): (devel) connecting to tomcat failed. [Wed Oct 19 10:35:01.906 2011] 0.100435 - vm201.int GET / HTTP/1.1 200 [Wed Oct 19 10:35:01.906 2011] [2053:3086162528] [info] jk_handler::mod_jk.c (2678): Service error=-3 for worker=devel It seems that request.status (the one that got recorded in logs) have default value of 200 and is updated only in jk_ajp_common.c::ajp_get_reply(). But this function never hit if jk_ajp_common.c::ajp_send_request() returns anything besides JK_TRUE. Maybe request.status variable should be initialized the same way as is_error variable in jk_handler() - default value HTTP_INTERNAL_SERVER_ERROR, and all subsequent functions will alter its value to one they needed. With such modification mod_jk will put 500 error in case request failed before it have a chance to connect to backend (see attachment).
With patch applied I have more correct values in logs: <<access.log: [19/Oct/2011:12:32:45 +0300] "GET / HTTP/1.1" 503 323 "-" [19/Oct/2011:12:33:45 +0300] "GET /jk-status HTTP/1.1" 200 5459 "-" <<mod_jk.log: [19/Oct/2011:12:32:45 +0300] 0.101018 - vm201.int "GET / HTTP/1.1" 500 19/Oct/2011:12:33:45 +0300] 0.002270 - vm201.int "GET /jk-status HTTP/1.1" 200
1. Versions of everything = ? There are various fixes in various Tomcat versions and the behaviour may be different. 2. What exactly are those files, "access.log" and "mod_jk.log"? Or better provide exact steps & configuration to reproduce this.
Created attachment 27819 [details] mod_jk configuration
Created attachment 27820 [details] mod_jk workers properties Sorry, forget about versions: mod_jk - 1.2.32 (latest) httpd - 2.2.21 access.log - default apache access log, configured with: CustomLog /var/log/httpd/access.log combined mod_jk.log - default mod_jk log file: JkLogFile /var/log/httpd/mod_jk.log JkRequestLogFormat "%T %R %V \"%r\" %s" Configuration is simple - any unreachable worker will work. See attachments for example configuration.
Fixed in r1187906. Will be part of mod_jk 1.2.33. To fix the problem, the JK request log was refactored to use the standard request log hook. You can apply the changes in r1187906 on top of 1.2.32 to test it. regards, Rainer