Package: libapache2-mod-jk Version: 1:1.2.23-2 Severity: normal I have apache2 (version 2.2.3-4) setup in front of a tomcat5.5 (version 5.5.20-2) installation, and use libapache2-mod-jk for the connection between them.
With the introduction of version 1.2.23-1 into testing, I noticed an issue after reloading apache's modules. In my investigation, I also tested version 1.2.23-2 from unstable, with the same results. All the snippets from logs from my investigation were using 1.2.21-1 and 1.2.23-2. The webapp makes heavy use of rewrites, and after the upgrade, I immediately ran into issues... One of the rewrites in use in the system is: RewriteRule ^/item/([0-9]+)\.html$ /servlet/Main/ItemPage?item_id=$1 [QSA,PT,L] If I browsed to http://loris.website.com/servlet/Main/ItemPage?item_id=38244 there were no problems, but if I used the rewritten url, http://loris.website.com/item/38244.html I noticed a 400 response code in the apache access.log. First I checked the rewrite logs, and from the logging it appears to be working as expected: 10.0.0.18 - - [19/Jun/2007:15:29:37 --0500] [loris.website.com/sid#8265b28][rid#834a290/initial] (3) applying pattern '^/item/([0-9]+)\.html$' to uri '/item/38244.html' 10.0.0.18 - - [19/Jun/2007:15:29:37 --0500] [loris.website.com/sid#8265b28][rid#834a290/initial] (2) rewrite '/item/38244.html' -> '/servlet/Main/ItemPage?item_id=38244' 10.0.0.18 - - [19/Jun/2007:15:29:37 --0500] [loris.website.com/sid#8265b28][rid#834a290/initial] (3) split uri=/servlet/Main/ItemPage?item_id=38244 -> uri=/servlet/Main/ItemPage, args=item_id=38244 10.0.0.18 - - [19/Jun/2007:15:29:37 --0500] [loris.website.com/sid#8265b28][rid#834a290/initial] (2) forcing '/servlet/Main/ItemPage' to get passed through to next API URI-to-filename handler After bumping up the logging in the mod_jk.log, I see the following error: [Tue Jun 19 15:29:37 2007] [14509:2960] [debug] jk_handler::mod_jk.c (2238): Service finished with status=400 for worker=ajp13_worker A bit earlier in the log I can make out the following error message coming back from AJP: No Host matches server name loris.website.com I turned on the RequestDumperValve and I used ngrep for a little further investigation... For version 1.2.21-1 and 1.2.23-2, I first loaded the full url, and then the rewritten url, and used the following ngrep command to capture the conversation: ngrep -qW byline port 8009 -d lo version 1.2.21-1, full request: T 127.0.0.1:46581 -> 127.0.0.1:8009 [AP] .4.F....HTTP/1.1.../servlet/Main/ItemPage...10.0.0.18.....loris.website.com..P.......loris.website.com....eMozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.0.11) Gecko/20070324 (Debian-1.8.0.11-4) Epiphany/2.14....ctext/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5.....gzip,deflate.....ISO-8859-1,utf-8;q=0.7,*;q=0.7.. Keep-Alive...300.... keep-alive.....JSESSIONID=958FA4582A9B2D4770614436CA528B20; browser=H9FRGJ7YM5; cookiesEnabled=true; loyaltyDiscount=a3c3ede6-7a4b-4bef-8d7f-80242e348273; browser=YQB8JUJCQ8.....0....item_id=38244.. T 127.0.0.1:8009 -> 127.0.0.1:46581 [AP] AB.......OK.... Set-Cookie..3JSESSIONID=958FA4582A9B2D4770614436CA528B20; Path=/.. Set-Cookie..9tuylu=show; Expires=Thu, 01-Jan-1970 00:00:10 GMT; Path=/...Content-Type...text/html. T 127.0.0.1:8009 -> 127.0.0.1:46581 [AP] AB.....<!-- ItemPage.html --> <html> ... snip ... </html> .AB.... --- Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: REQUEST URI =/servlet/Main/ItemPage ... snip ... Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: contextPath=/servlet ... snip ... Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: method=GET Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: parameter=item_id=38244 Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: pathInfo=/ItemPage Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: protocol=HTTP/1.1 Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: queryString=item_id=38244 ... snip ... Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: serverName=loris.website.com Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: serverPort=80 Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: servletPath=/Main Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: isSecure=false Jun 19, 2007 3:24:33 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: --------------------------------------------------------------- Jun 19, 2007 3:24:38 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: --------------------------------------------------------------- Jun 19, 2007 3:24:38 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: authType=null ... snip ... Jun 19, 2007 3:24:38 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: status=200 Jun 19, 2007 3:24:38 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: =============================================================== ----- version 1.2.21-1, rewritten request: T 127.0.0.1:46581 -> 127.0.0.1:8009 [AP] .4.F....HTTP/1.1.../servlet/Main/ItemPage...10.0.0.18.....loris.website.com..P.......loris.website.com....eMozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.0.11) Gecko/20070324 (Debian-1.8.0.11-4) Epiphany/2.14....ctext/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5.....gzip,deflate.....ISO-8859-1,utf-8;q=0.7,*;q=0.7.. Keep-Alive...300.... keep-alive.....JSESSIONID=958FA4582A9B2D4770614436CA528B20; browser=H9FRGJ7YM5; cookiesEnabled=true; loyaltyDiscount=a3c3ede6-7a4b-4bef-8d7f-80242e348273; browser=YQB8JUJCQ8.....0....item_id=38244.. T 127.0.0.1:8009 -> 127.0.0.1:46581 [AP] AB.n.....OK.... Set-Cookie..9tuylu=show; Expires=Thu, 01-Jan-1970 00:00:10 GMT; Path=/...Content-Type...text/html. T 127.0.0.1:8009 -> 127.0.0.1:46581 [AP] AB.....<!-- ItemPage.html --> <html> ... snip ... </html> . T 127.0.0.1:8009 -> 127.0.0.1:46581 [AP] AB.... --- Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: REQUEST URI =/servlet/Main/ItemPage ... snip ... Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: contextPath=/servlet ... snip ... Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: method=GET Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: parameter=item_id=38244 Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: pathInfo=/ItemPage Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: protocol=HTTP/1.1 Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: queryString=item_id=38244 ... snip ... Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: serverName=loris.website.com Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: serverPort=80 Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: servletPath=/Main Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: isSecure=false Jun 19, 2007 3:24:45 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: --------------------------------------------------------------- Jun 19, 2007 3:24:46 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: --------------------------------------------------------------- Jun 19, 2007 3:24:46 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: authType=null ... snip ... Jun 19, 2007 3:24:46 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: status=200 Jun 19, 2007 3:24:46 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: =============================================================== ----- version 1.23-2, full request: T 127.0.0.1:49847 -> 127.0.0.1:8009 [AP] .4.F....HTTP/1.1.../servlet/Main/ItemPage...10.0.0.18.....loris.website.com..P.......loris.website.com....eMozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.0.11) Gecko/20070324 (Debian-1.8.0.11-4) Epiphany/2.14....ctext/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5.....gzip,deflate.....ISO-8859-1,utf-8;q=0.7,*;q=0.7.. Keep-Alive...300.... keep-alive.....JSESSIONID=958FA4582A9B2D4770614436CA528B20; browser=H9FRGJ7YM5; cookiesEnabled=true; loyaltyDiscount=a3c3ede6-7a4b-4bef-8d7f-80242e348273; browser=YQB8JUJCQ8.....0....item_id=38244.. T 127.0.0.1:8009 -> 127.0.0.1:49847 [AP] AB.n.....OK.... Set-Cookie..9tuylu=show; Expires=Thu, 01-Jan-1970 00:00:10 GMT; Path=/...Content-Type...text/html. T 127.0.0.1:8009 -> 127.0.0.1:49847 [AP] AB.....<!-- ItemPage.html --> <html> ... snip ... </html> . --- Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: REQUEST URI =/servlet/Main/ItemPage ... snip ... Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: contextPath=/servlet ... snip ... INFO: method=GET Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: parameter=item_id=38244 Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: pathInfo=/ItemPage Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: protocol=HTTP/1.1 Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: queryString=item_id=38244 ... snip ... Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: serverName=loris.website.com Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: serverPort=80 Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: servletPath=/Main Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: isSecure=false Jun 19, 2007 3:29:31 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: --------------------------------------------------------------- Jun 19, 2007 3:29:32 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: --------------------------------------------------------------- Jun 19, 2007 3:29:32 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: authType=null ... snip ... Jun 19, 2007 3:29:32 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: status=200 Jun 19, 2007 3:29:32 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: =============================================================== ----- version 1.2.23-2, rewritten request: T 127.0.0.1:49847 -> 127.0.0.1:8009 [AP] .4.?....HTTP/1.1.../item/38244.html...10.0.0.18.....loris.website.com..P.......loris.website.com....eMozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.0.11) Gecko/20070324 (Debian-1.8.0.11-4) Epiphany/2.14....ctext/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5.....gzip,deflate.....ISO-8859-1,utf-8;q=0.7,*;q=0.7.. Keep-Alive...300.... keep-alive.....JSESSIONID=958FA4582A9B2D4770614436CA528B20; browser=H9FRGJ7YM5; cookiesEnabled=true; loyaltyDiscount=a3c3ede6-7a4b-4bef-8d7f-80242e348273; browser=YQB8JUJCQ8.....0....item_id=38244.. T 127.0.0.1:8009 -> 127.0.0.1:49847 [AP] AB.3....+No Host matches server name loris.website.com... T 127.0.0.1:8009 -> 127.0.0.1:49847 [AP] AB.... --- Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: REQUEST URI =/item/38244.html ... snip ... Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: contextPath=null ... snip ... INFO: method=GET Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: parameter=item_id=38244 Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: pathInfo=null Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: protocol=HTTP/1.1 Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: queryString=item_id=38244 ... snip ... Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: serverName=loris.website.com Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: serverPort=80 Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: servletPath=null Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: isSecure=false Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: --------------------------------------------------------------- Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: --------------------------------------------------------------- Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: authType=null ... snip ... Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: status=400 Jun 19, 2007 3:29:37 PM org.apache.catalina.valves.RequestDumperValve invoke INFO: =============================================================== ----- Here are the mount points defined in /etc/apache2/conf.d/mod_jk.conf: JkMount /*.jsp ajp13_worker JkMount /servlet/* ajp13_worker JkMount /manager* ajp13_worker JkMount /admin* ajp13_worker As you can see, in version 1.2.23-2, the rewritten request appears to be comming in as /item/38244.html, even though the rewrite logs imply the rewrite to /servlet/Main/ItemPage?item_id=38244 is happening. Since there's nothing in the mod_jk.conf to match /item urls, mod_jk wouldn't be sending the request on to tomcat if it really thought it was an /item url. But somehow the /item/38244.html is actually getting through to tomcat, which has nothing defined for that context path, so tomcat is erroring out with the 400 status code. I'd be happy to provide any more information that might be helpful. Thanks for your hard work, and thanks for helping me out. -- System Information: Debian Release: lenny/sid APT prefers unstable APT policy: (500, 'unstable') Architecture: i386 (i686) Kernel: Linux 2.6.18-4-686 (SMP w/2 CPU cores) Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8) Shell: /bin/sh linked to /bin/bash Versions of packages libapache2-mod-jk depends on: ii apache2 2.2.3-4 Next generation, scalable, extenda ii apache2-mpm-worker [apache2] 2.2.3-4 High speed threaded model for Apac ii apache2.2-common 2.2.3-4 Next generation, scalable, extenda ii libc6 2.5-9+b1 GNU C Library: Shared libraries libapache2-mod-jk recommends no packages. -- no debconf information -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of "unsubscribe". Trouble? Contact [EMAIL PROTECTED]