This is similar, but does not appear to be the same as bug 39266. I've applied the patch to mod_mem_cache.c and it makes no diffrence. It also does not matter if the storage for mod_cache is disk or memory cache. Here's the configuration: Frontend reverse caching proxy server running httpd 2.2.2, prefork mpm. The backend web server is httpd 1.3.36 with mod_jk 1.2.15. Mod_jk connects to Tomcat 5.0.30 via an ajp 1.3 connector. The namespace /res/* is mounted into Tomcat via mod_jk's JKMount directive. The first time content is accessed via the front end proxy, it sends the approperate content-type header, e.g. 'image/jpeg'. Further attempts to get the same image usually return a content-type header of 'text/html'. Here's the correct headers from the client and server: GET /res/img/content/liferaft.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Keep-Alive: 300 Connection: keep-alive Cookie: TRNO=1127250133.198.144.205.133; NumAd=-1; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; fcP=C=133&T=1137020088512&V=1137020102487; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; RMFD=011FiFmA; RMID=c690cd854329f1d0; T3CK=TANT%3D1%7CTANO%3D0; s_cc=true; s_sq=%5B%5BB%5D%5D; JSESSIONID=8870E2C3BE344A492CCC1DCCDE4036AC; PATHWAY=3 Pragma: no-cache Cache-Control: no-cache HTTP/1.x 200 OK Date: Tue, 23 May 2006 20:22:31 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 Etag: W/"26797-1148335021000" Content-Length: 26797 Expires: Wed, 24 May 2006 00:22:31 GMT Content-Type: image/jpeg Last-Modified: Mon, 22 May 2006 21:57:01 GMT Keep-Alive: timeout=5, max=99 Connection: Keep-Alive The next time the image is requested, the server returns the context-type as 'text/html', which causes the browser to try to render the image as if it where html. GET /res/img/content/liferaft.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Keep-Alive: 300 Connection: keep-alive Cookie: TRNO=1127250133.198.144.205.133; NumAd=-1; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; fcP=C=133&T=1137020088512&V=1137020102487; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; RMFD=011FiFmA; RMID=c690cd854329f1d0; T3CK=TANT%3D1%7CTANO%3D0; s_cc=true; s_sq=%5B%5BB%5D%5D; JSESSIONID=8870E2C3BE344A492CCC1DCCDE4036AC; PATHWAY=3 Pragma: no-cache Cache-Control: no-cache HTTP/1.x 200 OK Date: Tue, 23 May 2006 20:22:32 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 Etag: W/"26797-1148335021000" Content-Length: 26797 Expires: Wed, 24 May 2006 00:22:32 GMT Content-Type: text/html Last-Modified: Mon, 22 May 2006 21:57:01 GMT Keep-Alive: timeout=5, max=98 Connection: Keep-Alive Here's another data point: If the browser requests content that is not being served by mod_jk, then it will work correctly every time. For example, if the browser requests images/reportcard.jpg, which is being served directly by the backend web server, it will always send a content type of image/jpeg. GET /images/reportcard.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Keep-Alive: 300 Connection: keep-alive Cookie: TRNO=1127250133.198.144.205.133; NumAd=-1; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; fcP=C=133&T=1137020088512&V=1137020102487; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; RMFD=011FiFmA; RMID=c690cd854329f1d0; T3CK=TANT%3D1%7CTANO%3D0; s_cc=true; s_sq=%5B%5BB%5D%5D; JSESSIONID=8870E2C3BE344A492CCC1DCCDE4036AC; PATHWAY=3 Pragma: no-cache Cache-Control: no-cache HTTP/1.x 200 OK Date: Tue, 23 May 2006 20:30:24 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 Cache-Control: max-age=21600 Expires: Wed, 24 May 2006 02:30:24 GMT Etag: "1fae43-4487-3f4e92c4" Accept-Ranges: bytes Content-Length: 17543 Last-Modified: Thu, 28 Aug 2003 23:39:48 GMT Keep-Alive: timeout=5, max=89 Connection: Keep-Alive Content-Type: image/jpeg
Please post your cache and proxy configuration here. Furthermore please set the loglevel to debug on the proxy server and post the error_log of two subsequent requests where the first one is served directly and the second one is served by the cache with the wrong content-type.
Thank you for the follow up. Here's some more information: --- httpd.conf --- ServerRoot "/usr/local" Listen 80 LoadModule authn_file_module libexec/apache22/mod_authn_file.so LoadModule authn_dbm_module libexec/apache22/mod_authn_dbm.so LoadModule authn_anon_module libexec/apache22/mod_authn_anon.so LoadModule authn_default_module libexec/apache22/mod_authn_default.so LoadModule authz_host_module libexec/apache22/mod_authz_host.so LoadModule authz_groupfile_module libexec/apache22/mod_authz_groupfile.so LoadModule authz_user_module libexec/apache22/mod_authz_user.so LoadModule authz_dbm_module libexec/apache22/mod_authz_dbm.so LoadModule authz_owner_module libexec/apache22/mod_authz_owner.so LoadModule authz_default_module libexec/apache22/mod_authz_default.so LoadModule auth_basic_module libexec/apache22/mod_auth_basic.so LoadModule auth_digest_module libexec/apache22/mod_auth_digest.so LoadModule file_cache_module libexec/apache22/mod_file_cache.so LoadModule cache_module libexec/apache22/mod_cache.so LoadModule disk_cache_module libexec/apache22/mod_disk_cache.so LoadModule mem_cache_module libexec/apache22/mod_mem_cache.so LoadModule include_module libexec/apache22/mod_include.so LoadModule filter_module libexec/apache22/mod_filter.so LoadModule charset_lite_module libexec/apache22/mod_charset_lite.so LoadModule deflate_module libexec/apache22/mod_deflate.so LoadModule log_config_module libexec/apache22/mod_log_config.so LoadModule logio_module libexec/apache22/mod_logio.so LoadModule env_module libexec/apache22/mod_env.so LoadModule mime_magic_module libexec/apache22/mod_mime_magic.so LoadModule cern_meta_module libexec/apache22/mod_cern_meta.so LoadModule expires_module libexec/apache22/mod_expires.so LoadModule headers_module libexec/apache22/mod_headers.so LoadModule usertrack_module libexec/apache22/mod_usertrack.so LoadModule unique_id_module libexec/apache22/mod_unique_id.so LoadModule setenvif_module libexec/apache22/mod_setenvif.so LoadModule version_module libexec/apache22/mod_version.so LoadModule proxy_module libexec/apache22/mod_proxy.so LoadModule proxy_connect_module libexec/apache22/mod_proxy_connect.so LoadModule proxy_ftp_module libexec/apache22/mod_proxy_ftp.so LoadModule proxy_http_module libexec/apache22/mod_proxy_http.so LoadModule proxy_ajp_module libexec/apache22/mod_proxy_ajp.so LoadModule proxy_balancer_module libexec/apache22/mod_proxy_balancer.so LoadModule ssl_module libexec/apache22/mod_ssl.so LoadModule mime_module libexec/apache22/mod_mime.so LoadModule dav_module libexec/apache22/mod_dav.so LoadModule status_module libexec/apache22/mod_status.so LoadModule autoindex_module libexec/apache22/mod_autoindex.so LoadModule asis_module libexec/apache22/mod_asis.so LoadModule info_module libexec/apache22/mod_info.so LoadModule cgi_module libexec/apache22/mod_cgi.so LoadModule dav_fs_module libexec/apache22/mod_dav_fs.so LoadModule vhost_alias_module libexec/apache22/mod_vhost_alias.so LoadModule negotiation_module libexec/apache22/mod_negotiation.so LoadModule dir_module libexec/apache22/mod_dir.so LoadModule imagemap_module libexec/apache22/mod_imagemap.so LoadModule actions_module libexec/apache22/mod_actions.so LoadModule speling_module libexec/apache22/mod_speling.so LoadModule userdir_module libexec/apache22/mod_userdir.so LoadModule alias_module libexec/apache22/mod_alias.so LoadModule rewrite_module libexec/apache22/mod_rewrite.so User www Group www ServerAdmin sysadmin@greatschools.net <Directory /> AllowOverride None Order deny,allow Deny from all </Directory> TypesConfig /usr/local/etc/apache22/mime.types ErrorLog /var/log/httpd-error.log LogLevel debug # simulated proxy log LogFormat "%h %u %X %t \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\" \"%{Cookie}i\"" proxylog customlog /var/log/apache/proxy.log proxylog # proxy-level rewrites RewriteEngine on # return 403 forbidden if no user-agent specified # but don't block our load balancers since they don't specify a user-agent RewriteCond %{HTTP_USER_AGENT} ="" ReWriteCond %{REMOTE_ADDR} !207.33.22.13[34] ReWriteRule ^/* / [L,F] # cache MCacheRemovalAlgorithm GDSF MCacheSize 786432 MCacheMaxObjectSize 256000 MCacheMaxObjectCount 65535 CacheDefaultExpire 14400 CacheEnable mem / # proxy ProxyRequests Off ProxyPreserveHost on ProxyPass / http://dev.greatschools.net/ <Proxy *> Order deny,allow Allow from all </Proxy> # mod_deflate <Location /> SetOutputFilter DEFLATE SetEnvIfNoCase Request_URI \.(?:gif|jpe?g|png)$ no-gzip dont-vary Header append Vary User-Agent env=!dont-vary </Location> --- Here's the relevent log for the working request: [Tue May 23 14:23:20 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /res/img/content/liferaft.jpg [Tue May 23 14:23:20 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /res/img/content/liferaft.jpg [Tue May 23 14:23:20 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1378): [client 198.144.205.133] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:20 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Tue May 23 14:23:20 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/res/img/content/liferaft.jpg to dev.greatschools.net:80 [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1951): proxy: connected /res/img/content/liferaft.jpg to dev.greatschools.net:80 [Tue May 23 14:23:20 2006] [debug] proxy_util.c(2045): proxy: HTTP: fam 2 socket created to connect to dev.greatschools.net [Tue May 23 14:23:20 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Tue May 23 14:23:20 2006] [debug] mod_proxy_http.c(1448): proxy: start body send [Tue May 23 14:23:20 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Tue May 23 14:23:20 2006] [debug] mod_cache.c(602): cache: Caching url: /res/img/content/liferaft.jpg [Tue May 23 14:23:20 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Tue May 23 14:23:20 2006] [info] mem_cache: Cached url: http://nuked.greatschools.net:80/res/img/content/liferaft.jpg? [Tue May 23 14:23:20 2006] [debug] mod_proxy_http.c(1537): proxy: end body send [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 0 in child 63574 for worker http://dev.greatschools.net/ [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1644): proxy: worker http://dev.greatschools.net/ already initialized [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 0 in child 63574 for (dev.greatschools.net) [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 1 in child 63574 for worker proxy:reverse [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1644): proxy: worker proxy:reverse already initialized [Tue May 23 14:23:20 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 1 in child 63574 for (*) Here's the relevent log for the non-working request: [Tue May 23 14:23:24 2006] [debug] cache_storage.c(261): Cached response for /res/img/content/liferaft.jpg isn't fresh. Adding/replacing conditional request headers. [Tue May 23 14:23:24 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1378): [client 198.144.205.133] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Tue May 23 14:23:24 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/res/img/content/liferaft.jpg to dev.greatschools.net:80 [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1951): proxy: connected /res/img/content/liferaft.jpg to dev.greatschools.net:80 [Tue May 23 14:23:24 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Tue May 23 14:23:24 2006] [debug] mod_proxy_http.c(1541): proxy: header only [Tue May 23 14:23:24 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Tue May 23 14:23:24 2006] [debug] mod_cache.c(602): cache: Caching url: /res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Tue May 23 14:23:24 2006] [debug] cache_storage.c(261): Cached response for /res/img/content/liferaft.jpg isn't fresh. Adding/replacing conditional request headers. [Tue May 23 14:23:24 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1378): [client 198.144.205.133] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Tue May 23 14:23:24 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/res/img/content/liferaft.jpg to dev.greatschools.net:80 [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1951): proxy: connected /res/img/content/liferaft.jpg to dev.greatschools.net:80 [Tue May 23 14:23:24 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Tue May 23 14:23:24 2006] [debug] mod_proxy_http.c(1541): proxy: header only [Tue May 23 14:23:24 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Tue May 23 14:23:24 2006] [debug] mod_cache.c(602): cache: Caching url: /res/img/content/liferaft.jpg [Tue May 23 14:23:24 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Tue May 23 14:23:24 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net)
Heres some data from the log when fetching a stand-alone image, one not served via mod_jk. Interestingly I noticed when mem_cache cached the content, it added a '?' at the end of the URI. I added a '?' to the end of /res/img/content/liferaft.jpg and it looks like it sent the headers correctly every time. [Tue May 23 15:15:20 2006] [info] mod_unique_id: using ip addr 198.144.205.144 [Tue May 23 15:15:21 2006] [info] Init: Seeding PRNG with 0 bytes of entropy [Tue May 23 15:15:21 2006] [info] Init: Generating temporary RSA private keys (512/1024 bits) [Tue May 23 15:15:21 2006] [info] Init: Generating temporary DH parameters (512/1024 bits) [Tue May 23 15:15:21 2006] [warn] Init: Session Cache is not configured [hint: SSLSessionCache] [Tue May 23 15:15:21 2006] [info] Init: Initializing (virtual) servers for SSL [Tue May 23 15:15:21 2006] [info] Server: Apache/2.2.2, Interface: mod_ssl/2.2.2, Library: OpenSSL/0.9.7e-p1 [Tue May 23 15:15:21 2006] [info] mod_unique_id: using ip addr 198.144.205.144 [Tue May 23 15:15:22 2006] [info] Init: Seeding PRNG with 0 bytes of entropy [Tue May 23 15:15:22 2006] [info] Init: Generating temporary RSA private keys (512/1024 bits) [Tue May 23 15:15:23 2006] [info] Init: Generating temporary DH parameters (512/1024 bits) [Tue May 23 15:15:23 2006] [info] Init: Initializing (virtual) servers for SSL [Tue May 23 15:15:23 2006] [info] Server: Apache/2.2.2, Interface: mod_ssl/2.2.2, Library: OpenSSL/0.9.7e-p1 [Tue May 23 15:15:23 2006] [notice] Digest: generating secret for digest authentication ... [Tue May 23 15:15:23 2006] [notice] Digest: done [Tue May 23 15:15:23 2006] [notice] Apache/2.2.2 (FreeBSD) mod_ssl/2.2.2 OpenSSL/0.9.7e-p1 DAV/2 configured -- resuming normal operations [Tue May 23 15:15:23 2006] [info] Server built: May 23 2006 12:40:34 [Tue May 23 15:15:23 2006] [debug] prefork.c(991): AcceptMutex: flock (default: flock) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 0 in child 63711 for worker http://dev.greatschools.net/ [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 0 in child 63711 for (dev.greatschools.net) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 1 in child 63711 for worker proxy:reverse [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 1 in child 63711 for (*) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 0 in child 63712 for worker http://dev.greatschools.net/ [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1644): proxy: worker http://dev.greatschools.net/ already initialized [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 0 in child 63712 for (dev.greatschools.net) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 1 in child 63712 for worker proxy:reverse [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1644): proxy: worker proxy:reverse already initialized [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 1 in child 63712 for (*) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 0 in child 63715 for worker http://dev.greatschools.net/ [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1644): proxy: worker http://dev.greatschools.net/ already initialized [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 0 in child 63715 for (dev.greatschools.net) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 1 in child 63715 for worker proxy:reverse [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1644): proxy: worker proxy:reverse already initialized [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 1 in child 63715 for (*) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 0 in child 63713 for worker http://dev.greatschools.net/ [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1644): proxy: worker http://dev.greatschools.net/ already initialized [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 0 in child 63713 for (dev.greatschools.net) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 1 in child 63713 for worker proxy:reverse [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1644): proxy: worker proxy:reverse already initialized [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 1 in child 63713 for (*) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 0 in child 63714 for worker http://dev.greatschools.net/ [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1644): proxy: worker http://dev.greatschools.net/ already initialized [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 0 in child 63714 for (dev.greatschools.net) [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 1 in child 63714 for worker proxy:reverse [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1644): proxy: worker proxy:reverse already initialized [Tue May 23 15:15:23 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 1 in child 63714 for (*) [Tue May 23 15:16:25 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /images/reportcard.jpg [Tue May 23 15:16:25 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /images/reportcard.jpg [Tue May 23 15:16:25 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/images/reportcard.jpg [Tue May 23 15:16:25 2006] [debug] proxy_util.c(1378): [client 198.144.205.133] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/images/reportcard.jpg [Tue May 23 15:16:25 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Tue May 23 15:16:25 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/images/reportcard.jpg [Tue May 23 15:16:25 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Tue May 23 15:16:25 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/images/reportcard.jpg to dev.greatschools.net:80 [Tue May 23 15:16:25 2006] [debug] proxy_util.c(1951): proxy: connected /images/reportcard.jpg to dev.greatschools.net:80 [Tue May 23 15:16:25 2006] [debug] proxy_util.c(2045): proxy: HTTP: fam 2 socket created to connect to dev.greatschools.net [Tue May 23 15:16:25 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Tue May 23 15:16:25 2006] [debug] mod_proxy_http.c(1448): proxy: start body send [Tue May 23 15:16:25 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Tue May 23 15:16:25 2006] [debug] mod_cache.c(602): cache: Caching url: /images/reportcard.jpg [Tue May 23 15:16:25 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Tue May 23 15:16:25 2006] [info] mem_cache: Cached url: http://nuked.greatschools.net:80/images/reportcard.jpg? [Tue May 23 15:16:25 2006] [debug] mod_proxy_http.c(1537): proxy: end body send [Tue May 23 15:16:25 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Tue May 23 15:16:26 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 0 in child 63719 for worker http://dev.greatschools.net/ [Tue May 23 15:16:26 2006] [debug] proxy_util.c(1644): proxy: worker http://dev.greatschools.net/ already initialized [Tue May 23 15:16:26 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 0 in child 63719 for (dev.greatschools.net) [Tue May 23 15:16:26 2006] [debug] proxy_util.c(1625): proxy: grabbed scoreboard slot 1 in child 63719 for worker proxy:reverse [Tue May 23 15:16:26 2006] [debug] proxy_util.c(1644): proxy: worker proxy:reverse already initialized [Tue May 23 15:16:26 2006] [debug] proxy_util.c(1724): proxy: initialized single connection worker 1 in child 63719 for (*) [Tue May 23 15:16:41 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /images/reportcard.jpg [Tue May 23 15:16:41 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /images/reportcard.jpg [Tue May 23 15:16:41 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/images/reportcard.jpg [Tue May 23 15:16:41 2006] [debug] proxy_util.c(1378): [client 198.144.205.133] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/images/reportcard.jpg [Tue May 23 15:16:41 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Tue May 23 15:16:41 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/images/reportcard.jpg [Tue May 23 15:16:41 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Tue May 23 15:16:41 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/images/reportcard.jpg to dev.greatschools.net:80 [Tue May 23 15:16:41 2006] [debug] proxy_util.c(1951): proxy: connected /images/reportcard.jpg to dev.greatschools.net:80 [Tue May 23 15:16:41 2006] [debug] proxy_util.c(2045): proxy: HTTP: fam 2 socket created to connect to dev.greatschools.net [Tue May 23 15:16:41 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Tue May 23 15:16:41 2006] [debug] mod_proxy_http.c(1448): proxy: start body send [Tue May 23 15:16:41 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Tue May 23 15:16:41 2006] [debug] mod_cache.c(602): cache: Caching url: /images/reportcard.jpg [Tue May 23 15:16:41 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Tue May 23 15:16:41 2006] [info] mem_cache: Cached url: http://nuked.greatschools.net:80/images/reportcard.jpg? [Tue May 23 15:16:41 2006] [debug] mod_proxy_http.c(1537): proxy: end body send [Tue May 23 15:16:41 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net)
Here's an interesting data point. I was tinkering with this issue a bit more today and discovered that I could hit the cached image that was origionally served via mod_jk using wget all I want, and it would always return image/jpeg as the content-type. Once I loaded up firefox and hit ctrl+F5 (force refresh) mod_cache started to return text/html as the content type. So for some reason, the act of force refreshing in firefox seems to be a trigger.
You are correct that this has something to do with doing a refresh in Firefox. Requesting a refresh in Firefox requires the cache to revalidate the cached entity on the back end server. Something seems to go wrong during this process. Currently I cannot decide if this is because something is wrong in the cache code or because the backend delivers a bad response. So it would be most helpful if you could sniff the network traffic between your proxy httpd and your backend httpd, do a non working refresh request with Firefox and attach the results of your sniffing to this report.
Thank you for the followup. Here's some investigation with tcpdump and ethereal from the proxy server. The client is 198.144.205.133, the reverse proxy server is 198.144.205.144 and the backend web server is 198.144.205.152. Here is the client making the inital request for /res/img/content/liferaft.jpg. 13:39:20.748596 IP 198.144.205.133.3180 > 198.144.205.144.80: S 3335533019:3335533019(0) win 65535 <mss 1460,nop,nop,sackOK> 13:39:20.748697 IP 198.144.205.144.80 > 198.144.205.133.3180: S 876667792:876667792(0) ack 3335533020 win 65535 <mss 1460,sackOK,eol> 13:39:20.748824 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 1 win 65535 13:39:20.749129 IP 198.144.205.133.3180 > 198.144.205.144.80: P 1:834(833) ack 1 win 65535 Here are the headers the client sent to the proxy server. GET /res/img/content/liferaft.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Keep-Alive: 300 Connection: keep-alive Cookie: T3CK=TANT%3D1%7CTANO%3D0; fcP=C=133&T=1137020088512&V=1137020102487; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; RMID=c690cd854329f1d0; RMFD=011Fiz3b; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; TRNO=1127250133.198.144.205.133 Next, the proxy server makes a connection to the backend web server to fufill the request: 13:39:20.751945 IP 198.144.205.144.55524 > 198.144.205.152.80: S 1402262641:1402262641(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp 4082124725 0,sackOK,eol> 13:39:20.752099 IP 198.144.205.152.80 > 198.144.205.144.55524: S 2054288495:2054288495(0) ack 1402262642 win 57344 <mss 1460,nop,wscale 0,nop,nop,timestamp 1733763502 4082124725> 13:39:20.752170 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 1 win 33304 <nop,nop,timestamp 4082124725 1733763502> 13:39:20.752735 IP 198.144.205.144.55524 > 198.144.205.152.80: P 1:956(955) ack 1 win 33304 <nop,nop,timestamp 4082124726 1733763502> 13:39:20.757824 IP 198.144.205.152.80 > 198.144.205.144.55524: . 1:1449(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124726> 13:39:20.757934 IP 198.144.205.152.80 > 198.144.205.144.55524: . 1449:2897(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124726> 13:39:20.757977 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 2897 win 32580 <nop,nop,timestamp 4082124731 1733763503> 13:39:20.758057 IP 198.144.205.152.80 > 198.144.205.144.55524: . 2897:4345(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124726> 13:39:20.758179 IP 198.144.205.152.80 > 198.144.205.144.55524: . 4345:5793(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124726> 13:39:20.758211 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 5793 win 31132 <nop,nop,timestamp 4082124731 1733763503> 13:39:20.758313 IP 198.144.205.152.80 > 198.144.205.144.55524: . 5793:7241(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124726> 13:39:20.758426 IP 198.144.205.152.80 > 198.144.205.144.55524: . 7241:8689(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124731> 13:39:20.758462 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 8689 win 29684 <nop,nop,timestamp 4082124732 1733763503> 13:39:20.758549 IP 198.144.205.152.80 > 198.144.205.144.55524: . 8689:10137(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124731> 13:39:20.758675 IP 198.144.205.152.80 > 198.144.205.144.55524: . 10137:11585(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124731> 13:39:20.758715 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 11585 win 28236 <nop,nop,timestamp 4082124732 1733763503> 13:39:20.758796 IP 198.144.205.152.80 > 198.144.205.144.55524: . 11585:13033(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124731> 13:39:20.758918 IP 198.144.205.152.80 > 198.144.205.144.55524: . 13033:14481(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124731> 13:39:20.758953 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 14481 win 26788 <nop,nop,timestamp 4082124732 1733763503> 13:39:20.759041 IP 198.144.205.152.80 > 198.144.205.144.55524: . 14481:15929(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124731> 13:39:20.759168 IP 198.144.205.152.80 > 198.144.205.144.55524: . 15929:17377(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124732> 13:39:20.759211 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 17377 win 25340 <nop,nop,timestamp 4082124732 1733763503> 13:39:20.759288 IP 198.144.205.152.80 > 198.144.205.144.55524: . 17377:18825(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124732> 13:39:20.759411 IP 198.144.205.152.80 > 198.144.205.144.55524: . 18825:20273(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124732> 13:39:20.759448 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 20273 win 23892 <nop,nop,timestamp 4082124733 1733763503> 13:39:20.759536 IP 198.144.205.152.80 > 198.144.205.144.55524: . 20273:21721(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124732> 13:39:20.759656 IP 198.144.205.152.80 > 198.144.205.144.55524: . 21721:23169(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124732> 13:39:20.759697 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 23169 win 22444 <nop,nop,timestamp 4082124733 1733763503> 13:39:20.759780 IP 198.144.205.152.80 > 198.144.205.144.55524: . 23169:24617(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124732> 13:39:20.759903 IP 198.144.205.152.80 > 198.144.205.144.55524: . 24617:26065(1448) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124732> 13:39:20.759940 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 26065 win 20996 <nop,nop,timestamp 4082124733 1733763503> 13:39:20.759994 IP 198.144.205.152.80 > 198.144.205.144.55524: P 26065:27126(1061) ack 956 win 57920 <nop,nop,timestamp 1733763503 4082124732> 13:39:20.760244 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 27126 win 24465 <nop,nop,timestamp 4082124733 1733763503> 13:39:20.761346 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 27126 win 28465 <nop,nop,timestamp 4082124735 1733763503> 13:39:20.762105 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 27126 win 32465 <nop,nop,timestamp 4082124735 1733763503> 13:39:37.395766 IP 198.144.205.152.80 > 198.144.205.144.55524: F 27126:27126(0) ack 956 win 57920 <nop,nop,timestamp 1733765167 4082124735> 13:39:37.395864 IP 198.144.205.144.55524 > 198.144.205.152.80: . ack 27127 win 33304 <nop,nop,timestamp 4082141370 1733765167> 13:40:46.519437 IP 198.144.205.144.55524 > 198.144.205.152.80: F 956:956(0) ack 27127 win 33304 <nop,nop,timestamp 4082210495 1733765167> 13:40:46.519586 IP 198.144.205.152.80 > 198.144.205.144.55524: . ack 957 win 57920 <nop,nop,timestamp 1733772078 4082210495> Here are the headers that the proxy server sends to the backend for the request: GET /res/img/content/liferaft.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Cookie: T3CK=TANT%3D1%7CTANO%3D0; fcP=C=133&T=1137020088512&V=1137020102487; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; RMID=c690cd854329f1d0; RMFD=011Fiz3b; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; TRNO=1127250133.198.144.205.133 Max-Forwards: 10 X-Forwarded-For: 198.144.205.133 X-Forwarded-Host: nuked.greatschools.net X-Forwarded-Server: nuked.greatschools.net. Connection: Keep-Alive Here are the headers the backend responds with: HTTP/1.1 200 OK Date: Thu, 25 May 2006 20:39:20 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 ETag: W/"26797-1148506126000" Last-Modified: Wed, 24 May 2006 21:28:46 GMT Content-Length: 26797 Keep-Alive: timeout=15, max=1000 Connection: Keep-Alive Content-Type: image/jpeg Then the proxy server responds to the client's request: 13:39:20.760358 IP 198.144.205.144.80 > 198.144.205.133.3180: . 1:1461(1460) ack 834 win 65535 13:39:20.760894 IP 198.144.205.144.80 > 198.144.205.133.3180: . 1461:2921(1460) ack 834 win 65535 13:39:20.760919 IP 198.144.205.144.80 > 198.144.205.133.3180: . 2921:4381(1460) ack 834 win 65535 13:39:20.760932 IP 198.144.205.144.80 > 198.144.205.133.3180: . 4381:5841(1460) ack 834 win 65535 13:39:20.761507 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 2921 win 65535 13:39:20.761607 IP 198.144.205.144.80 > 198.144.205.133.3180: . 5841:7301(1460) ack 834 win 65535 13:39:20.761621 IP 198.144.205.144.80 > 198.144.205.133.3180: . 7301:8761(1460) ack 834 win 65535 13:39:20.761635 IP 198.144.205.144.80 > 198.144.205.133.3180: . 8761:10221(1460) ack 834 win 65535 13:39:20.761719 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 5841 win 65535 13:39:20.761748 IP 198.144.205.144.80 > 198.144.205.133.3180: . 10221:11681(1460) ack 834 win 65535 13:39:20.761763 IP 198.144.205.144.80 > 198.144.205.133.3180: . 11681:13141(1460) ack 834 win 65535 13:39:20.761778 IP 198.144.205.144.80 > 198.144.205.133.3180: . 13141:14601(1460) ack 834 win 65535 13:39:20.763225 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 8761 win 65535 13:39:20.763468 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 11681 win 65535 13:39:20.763526 IP 198.144.205.144.80 > 198.144.205.133.3180: . 14601:16061(1460) ack 834 win 65535 13:39:20.763544 IP 198.144.205.144.80 > 198.144.205.133.3180: . 16061:17521(1460) ack 834 win 65535 13:39:20.763712 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 14601 win 65535 13:39:20.763735 IP 198.144.205.144.80 > 198.144.205.133.3180: . 17521:18981(1460) ack 834 win 65535 13:39:20.763748 IP 198.144.205.144.80 > 198.144.205.133.3180: . 18981:20441(1460) ack 834 win 65535 13:39:20.764661 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 17521 win 65535 13:39:20.764691 IP 198.144.205.144.80 > 198.144.205.133.3180: . 20441:21901(1460) ack 834 win 65535 13:39:20.764703 IP 198.144.205.144.80 > 198.144.205.133.3180: . 21901:23361(1460) ack 834 win 65535 13:39:20.764904 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 20441 win 65535 13:39:20.764924 IP 198.144.205.144.80 > 198.144.205.133.3180: . 23361:24821(1460) ack 834 win 65535 13:39:20.764937 IP 198.144.205.144.80 > 198.144.205.133.3180: . 24821:26281(1460) ack 834 win 65535 13:39:20.765177 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 23361 win 65535 13:39:20.765197 IP 198.144.205.144.80 > 198.144.205.133.3180: P 26281:27164(883) ack 834 win 65535 13:39:20.765423 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 26281 win 65535 13:39:20.941506 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 27164 win 64652 13:39:25.763406 IP 198.144.205.144.80 > 198.144.205.133.3180: F 27164:27164(0) ack 834 win 65535 13:39:25.763601 IP 198.144.205.133.3180 > 198.144.205.144.80: . ack 27165 win 64652 13:39:27.958133 IP 198.144.205.133.3180 > 198.144.205.144.80: F 834:834(0) ack 27165 win 64652 13:39:27.958237 IP 198.144.205.144.80 > 198.144.205.133.3180: . ack 835 win 65534 Here are the headers the proxy responds with: HTTP/1.1 200 OK Date: Thu, 25 May 2006 20:39:20 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 ETag: W/"26797-1148506126000" Last-Modified: Wed, 24 May 2006 21:28:46 GMT Content-Length: 26797 Content-Type: image/jpeg Expires: Thu, 25 May 2006 22:58:23 GMT Keep-Alive: timeout=5, max=100 Connection: Keep-Alive That transaction worked okay. Here's one that didn't work: 13:41:01.094260 IP 198.144.205.133.3187 > 198.144.205.144.80: S 1953506917:1953506917(0) win 65535 <mss 1460,nop,nop,sackOK> 13:41:01.094354 IP 198.144.205.144.80 > 198.144.205.133.3187: S 1632330321:1632330321(0) ack 1953506918 win 65535 <mss 1460,sackOK,eol> 13:41:01.094490 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 1 win 65535 13:41:01.094805 IP 198.144.205.133.3187 > 198.144.205.144.80: P 1:877(876) ack 1 win 65535 13:41:01.102707 IP 198.144.205.144.80 > 198.144.205.133.3187: . 1:1461(1460) ack 877 win 65535 13:41:01.102733 IP 198.144.205.144.80 > 198.144.205.133.3187: . 1461:2921(1460) ack 877 win 65535 13:41:01.103237 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 2921 win 65535 13:41:01.103328 IP 198.144.205.144.80 > 198.144.205.133.3187: . 2921:4381(1460) ack 877 win 65535 13:41:01.103340 IP 198.144.205.144.80 > 198.144.205.133.3187: . 4381:5841(1460) ack 877 win 65535 13:41:01.103354 IP 198.144.205.144.80 > 198.144.205.133.3187: . 5841:7301(1460) ack 877 win 65535 13:41:01.103824 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 5841 win 65535 13:41:01.103847 IP 198.144.205.144.80 > 198.144.205.133.3187: . 7301:8761(1460) ack 877 win 65535 13:41:01.103858 IP 198.144.205.144.80 > 198.144.205.133.3187: . 8761:10221(1460) ack 877 win 65535 13:41:01.103870 IP 198.144.205.144.80 > 198.144.205.133.3187: . 10221:11681(1460) ack 877 win 65535 13:41:01.104210 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 8761 win 65535 13:41:01.104234 IP 198.144.205.144.80 > 198.144.205.133.3187: . 11681:13141(1460) ack 877 win 65535 13:41:01.104246 IP 198.144.205.144.80 > 198.144.205.133.3187: . 13141:14601(1460) ack 877 win 65535 13:41:01.104258 IP 198.144.205.144.80 > 198.144.205.133.3187: . 14601:16061(1460) ack 877 win 65535 13:41:01.104457 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 11681 win 65535 13:41:01.104481 IP 198.144.205.144.80 > 198.144.205.133.3187: . 16061:17521(1460) ack 877 win 65535 13:41:01.104495 IP 198.144.205.144.80 > 198.144.205.133.3187: . 17521:18981(1460) ack 877 win 65535 13:41:01.104507 IP 198.144.205.144.80 > 198.144.205.133.3187: . 18981:20441(1460) ack 877 win 65535 13:41:01.104724 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 14601 win 65535 13:41:01.104745 IP 198.144.205.144.80 > 198.144.205.133.3187: . 20441:21901(1460) ack 877 win 65535 13:41:01.104758 IP 198.144.205.144.80 > 198.144.205.133.3187: . 21901:23361(1460) ack 877 win 65535 13:41:01.104771 IP 198.144.205.144.80 > 198.144.205.133.3187: . 23361:24821(1460) ack 877 win 65535 13:41:01.104966 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 17521 win 65535 13:41:01.104985 IP 198.144.205.144.80 > 198.144.205.133.3187: . 24821:26281(1460) ack 877 win 65535 13:41:01.105004 IP 198.144.205.144.80 > 198.144.205.133.3187: P 26281:27164(883) ack 877 win 65535 13:41:01.105213 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 20441 win 65535 13:41:01.105461 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 23361 win 65535 13:41:01.105706 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 26281 win 65535 13:41:01.237467 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 27164 win 64652 13:41:05.312399 IP 198.144.205.133.3187 > 198.144.205.144.80: P 877:1753(876) ack 27164 win 64652 13:41:05.316143 IP 198.144.205.144.80 > 198.144.205.133.3187: . 27164:28624(1460) ack 1753 win 65535 13:41:05.316167 IP 198.144.205.144.80 > 198.144.205.133.3187: . 28624:30084(1460) ack 1753 win 65535 13:41:05.316187 IP 198.144.205.144.80 > 198.144.205.133.3187: . 30084:31544(1460) ack 1753 win 65535 13:41:05.316197 IP 198.144.205.144.80 > 198.144.205.133.3187: . 31544:33004(1460) ack 1753 win 65535 13:41:05.316217 IP 198.144.205.144.80 > 198.144.205.133.3187: . 33004:34464(1460) ack 1753 win 65535 13:41:05.316233 IP 198.144.205.144.80 > 198.144.205.133.3187: . 34464:35924(1460) ack 1753 win 65535 13:41:05.316242 IP 198.144.205.144.80 > 198.144.205.133.3187: . 35924:37384(1460) ack 1753 win 65535 13:41:05.316261 IP 198.144.205.144.80 > 198.144.205.133.3187: . 37384:38844(1460) ack 1753 win 65535 13:41:05.316278 IP 198.144.205.144.80 > 198.144.205.133.3187: . 38844:40304(1460) ack 1753 win 65535 13:41:05.316293 IP 198.144.205.144.80 > 198.144.205.133.3187: . 40304:41764(1460) ack 1753 win 65535 13:41:05.316302 IP 198.144.205.144.80 > 198.144.205.133.3187: . 41764:43224(1460) ack 1753 win 65535 13:41:05.316323 IP 198.144.205.144.80 > 198.144.205.133.3187: . 43224:44684(1460) ack 1753 win 65535 13:41:05.316679 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 30084 win 65535 13:41:05.316774 IP 198.144.205.144.80 > 198.144.205.133.3187: . 44684:46144(1460) ack 1753 win 65535 13:41:05.316785 IP 198.144.205.144.80 > 198.144.205.133.3187: . 46144:47604(1460) ack 1753 win 65535 13:41:05.316795 IP 198.144.205.144.80 > 198.144.205.133.3187: . 47604:49064(1460) ack 1753 win 65535 13:41:05.316874 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 33004 win 65535 13:41:05.316897 IP 198.144.205.144.80 > 198.144.205.133.3187: . 49064:50524(1460) ack 1753 win 65535 13:41:05.316910 IP 198.144.205.144.80 > 198.144.205.133.3187: . 50524:51984(1460) ack 1753 win 65535 13:41:05.316922 IP 198.144.205.144.80 > 198.144.205.133.3187: . 51984:53444(1460) ack 1753 win 65535 13:41:05.317132 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 35924 win 65535 13:41:05.317153 IP 198.144.205.144.80 > 198.144.205.133.3187: P 53444:54325(881) ack 1753 win 65535 13:41:05.317382 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 38844 win 65535 13:41:05.317626 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 41764 win 65535 13:41:05.317868 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 44684 win 65535 13:41:05.318118 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 47604 win 65535 13:41:05.318363 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 50524 win 65535 13:41:05.318610 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 53444 win 65535 13:41:05.503052 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 54325 win 64654 13:41:05.629138 IP 198.144.205.133.3187 > 198.144.205.144.80: P 1753:2489(736) ack 54325 win 64654 13:41:05.633724 IP 198.144.205.144.80 > 198.144.205.133.3187: P 54325:54883(558) ack 2489 win 65535 13:41:05.831178 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 54883 win 64096 13:41:10.634808 IP 198.144.205.144.80 > 198.144.205.133.3187: F 54883:54883(0) ack 2489 win 65535 13:41:10.634969 IP 198.144.205.133.3187 > 198.144.205.144.80: . ack 54884 win 64096 13:41:24.506079 IP 198.144.205.133.3187 > 198.144.205.144.80: F 2489:2489(0) ack 54884 win 64096 13:41:24.506191 IP 198.144.205.144.80 > 198.144.205.133.3187: . ack 2490 win 65534 This is actually two requests over a single tcp connection. I assume firefox is recycling a still connected keep alive session if the user hits ctrl+F5 fast enough. The client / server headers: GET /res/img/content/liferaft.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Keep-Alive: 300 Connection: keep-alive Cookie: T3CK=TANT%3D1%7CTANO%3D0; fcP=C=133&T=1137020088512&V=1137020102487; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; RMID=c690cd854329f1d0; RMFD=011Fiz3b; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; TRNO=1127250133.198.144.205.133 Pragma: no-cache Cache-Control: no-cache HTTP/1.1 200 OK Date: Thu, 25 May 2006 20:41:01 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 ETag: W/"26797-1148506126000" Content-Length: 26797 Expires: Fri, 26 May 2006 00:41:01 GMT Content-Type: image/jpeg Last-Modified: Wed, 24 May 2006 21:28:46 GMT Keep-Alive: timeout=5, max=100 Connection: Keep-Alive GET /res/img/content/liferaft.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Keep-Alive: 300 Connection: keep-alive Cookie: T3CK=TANT%3D1%7CTANO%3D0; fcP=C=133&T=1137020088512&V=1137020102487; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; RMID=c690cd854329f1d0; RMFD=011Fiz3b; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; TRNO=1127250133.198.144.205.133 Pragma: no-cache Cache-Control: no-cache HTTP/1.1 200 OK Date: Thu, 25 May 2006 20:41:05 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 ETag: W/"26797-1148506126000" Content-Length: 26797 Expires: Fri, 26 May 2006 00:41:05 GMT Content-Type: text/html Last-Modified: Wed, 24 May 2006 21:28:46 GMT Keep-Alive: timeout=5, max=99 Connection: Keep-Alive The first request worked, but the second one was returned as text/html. Meanwhile, the proxy server is making requests to the backend to handle the client's request. 13:40:46.519646 IP 198.144.205.144.64919 > 198.144.205.152.80: S 755704577:755704577(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp 4082210496 0,sackOK,eol> 13:40:46.519763 IP 198.144.205.152.80 > 198.144.205.144.64919: S 2886095240:2886095240(0) ack 755704578 win 57344 <mss 1460,nop,wscale 0,nop,nop,timestamp 1733772078 4082210496> 13:40:46.519805 IP 198.144.205.144.64919 > 198.144.205.152.80: . ack 1 win 33304 <nop,nop,timestamp 4082210496 1733772078> 13:40:46.520087 IP 198.144.205.144.64919 > 198.144.205.152.80: P 1:1089(1088) ack 1 win 33304 <nop,nop,timestamp 4082210496 1733772078> 13:40:46.524652 IP 198.144.205.152.80 > 198.144.205.144.64919: P 1:257(256) ack 1089 win 57920 <nop,nop,timestamp 1733772079 4082210496> 13:40:46.624500 IP 198.144.205.144.64919 > 198.144.205.152.80: . ack 257 win 33304 <nop,nop,timestamp 4082210601 1733772079> 13:41:01.097038 IP 198.144.205.144.63148 > 198.144.205.152.80: F 999:999(0) ack 27127 win 33304 <nop,nop,timestamp 4082225073 1733765874> 13:41:01.097158 IP 198.144.205.152.80 > 198.144.205.144.63148: . ack 1000 win 57920 <nop,nop,timestamp 1733773536 4082225073> 13:41:01.097278 IP 198.144.205.144.55877 > 198.144.205.152.80: S 3660931143:3660931143(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp 4082225074 0,sackOK,eol> 13:41:01.097392 IP 198.144.205.152.80 > 198.144.205.144.55877: S 1545466721:1545466721(0) ack 3660931144 win 57344 <mss 1460,nop,wscale 0,nop,nop,timestamp 1733773536 4082225074> 13:41:01.097431 IP 198.144.205.144.55877 > 198.144.205.152.80: . ack 1 win 33304 <nop,nop,timestamp 4082225074 1733773536> 13:41:01.097709 IP 198.144.205.144.55877 > 198.144.205.152.80: P 1:1089(1088) ack 1 win 33304 <nop,nop,timestamp 4082225074 1733773536> 13:41:01.102080 IP 198.144.205.152.80 > 198.144.205.144.55877: P 1:257(256) ack 1089 win 57920 <nop,nop,timestamp 1733773536 4082225074> 13:41:01.202018 IP 198.144.205.144.55877 > 198.144.205.152.80: . ack 257 win 33304 <nop,nop,timestamp 4082225179 1733773536> 13:41:03.254784 IP 198.144.205.152.80 > 198.144.205.144.64919: F 257:257(0) ack 1089 win 57920 <nop,nop,timestamp 1733773752 4082210601> 13:41:03.254877 IP 198.144.205.144.64919 > 198.144.205.152.80: . ack 258 win 33304 <nop,nop,timestamp 4082227231 1733773752> 13:41:05.313389 IP 198.144.205.144.55877 > 198.144.205.152.80: P 1089:2177(1088) ack 257 win 33304 <nop,nop,timestamp 4082229290 1733773536> 13:41:05.315555 IP 198.144.205.152.80 > 198.144.205.144.55877: P 257:512(255) ack 2177 win 57920 <nop,nop,timestamp 1733773958 4082229290> 13:41:05.414874 IP 198.144.205.144.55877 > 198.144.205.152.80: . ack 512 win 33304 <nop,nop,timestamp 4082229392 1733773958> 13:41:05.629992 IP 198.144.205.144.55877 > 198.144.205.152.80: P 2177:3035(858) ack 512 win 33304 <nop,nop,timestamp 4082229607 1733773958> 13:41:05.631281 IP 198.144.205.152.80 > 198.144.205.144.55877: P 512:1753(1241) ack 3035 win 57920 <nop,nop,timestamp 1733773989 4082229607> 13:41:05.730896 IP 198.144.205.144.55877 > 198.144.205.152.80: . ack 1753 win 33304 <nop,nop,timestamp 4082229708 1733773989> 13:41:22.446789 IP 198.144.205.152.80 > 198.144.205.144.55877: F 1753:1753(0) ack 3035 win 57920 <nop,nop,timestamp 1733775671 4082229708> 13:41:22.446885 IP 198.144.205.144.55877 > 198.144.205.152.80: . ack 1754 win 33304 <nop,nop,timestamp 4082246424 1733775671> Here are the headers from the proxy -> backend conversation. GET /res/img/content/liferaft.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Cookie: T3CK=TANT%3D1%7CTANO%3D0; fcP=C=133&T=1137020088512&V=1137020102487; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; RMID=c690cd854329f1d0; RMFD=011Fiz3b; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; TRNO=1127250133.198.144.205.133 Pragma: no-cache Cache-Control: no-cache If-None-Match: W/"26797-1148506126000" If-Modified-Since: Wed, 24 May 2006 21:28:46 GMT Max-Forwards: 10 X-Forwarded-For: 198.144.205.133 X-Forwarded-Host: nuked.greatschools.net X-Forwarded-Server: nuked.greatschools.net. Connection: Keep-Alive HTTP/1.1 304 Not Modified Date: Thu, 25 May 2006 20:41:01 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 Content-Length: 0 Keep-Alive: timeout=15, max=1000 Connection: Keep-Alive Content-Type: text/html It looks like the backend is responding with http status code 304. I'm wondering if the text/html content-type from the 304 code is being erroniously cached in this case? I have the tcpdump capture file here. If I can provide any more information or perhaps put the capture file somewhere for download please don't hesitate to ask.
I just ran some tcpdump sniffing while pulling an image served directly by httpd on the backend, not going through mod_jk. It does not set the conent-type header when it returns a 304 http status code. Here are the headers from the proxy -> backend conversation: GET /images/reportcard.jpg HTTP/1.1 Host: nuked.greatschools.net User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.0.3) Gecko/20060426 Firefox/1.5.0.3 Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Cookie: TRNO=1127250133.198.144.205.133; NXCLICK2=011FHWHwNX_mailing/gn/2006_02/ca/8951!y!01!4qcu!52qf!02!4qcv!52qhNX_mailing/gn/2006_02_21/ca/8427!y!01!4r4q!53Uk!02!4r4r!53UqNX_mailing/mss/2006_03/ca/8438.76346803398!y!02!4rJ8!53pF; RMFD=011Fiz3b; NumAd=-1; RMID=c690cd854329f1d0; s_vi=[CS]v1|43F0FFA7000062EC-A160B0300000792[CE]; T3CK=TANT%3D1%7CTANO%3D0; fcP=C=133&T=1137020088512&V=1137020102487 Pragma: no-cache Cache-Control: no-cache If-None-Match: "1fae43-4487-3f4e92c4" If-Modified-Since: Thu, 28 Aug 2003 23:39:48 GMT Max-Forwards: 10 X-Forwarded-For: 198.144.205.133 X-Forwarded-Host: nuked.greatschools.net X-Forwarded-Server: nuked.greatschools.net. Connection: Keep-Alive HTTP/1.1 304 Not Modified Date: Thu, 25 May 2006 23:56:23 GMT Server: Apache/1.3.33 (Unix) mod_perl/1.29 mod_ssl/2.8.22 OpenSSL/0.9.7d mod_jk/1.2.15 Connection: Keep-Alive, Keep-Alive Keep-Alive: timeout=15, max=998 ETag: "1fae43-4487-3f4e92c4" Expires: Fri, 26 May 2006 05:56:23 GMT Cache-Control: max-age=21600
Created attachment 18353 [details] Patch for additional Debug messages against 2.2.x Thanks for the update. I think we are getting closer. Can you please apply the attached patch, run a non working request and post the according error log? The patch is only temporary and does not fix anything, but it should help me to understand the problem better.
Here you go. I applied the patch, and also the patch found in bug 39266. Here is a snipit from the debug log. [Fri May 26 11:15:05 2006] [debug] cache_storage.c(261): Cached response for /res/img/content/liferaft.jpg isn't fresh. Adding/replacing conditional request headers. [Fri May 26 11:15:05 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /res/img/content/liferaft.jpg [Fri May 26 11:15:05 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /res/img/content/liferaft.jpg [Fri May 26 11:15:05 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/res/img/content/liferaft.jpg [Fri May 26 11:15:05 2006] [debug] proxy_util.c(1378): [client 64.85.232.3] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/res/img/content/liferaft.jpg [Fri May 26 11:15:05 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Fri May 26 11:15:05 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/res/img/content/liferaft.jpg [Fri May 26 11:15:05 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Fri May 26 11:15:05 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/res/img/content/liferaft.jpg to dev.greatschools.net:80 [Fri May 26 11:15:05 2006] [debug] proxy_util.c(1951): proxy: connected /res/img/content/liferaft.jpg to dev.greatschools.net:80 [Fri May 26 11:15:05 2006] [debug] proxy_util.c(2045): proxy: HTTP: fam 2 socket created to connect to dev.greatschools.net [Fri May 26 11:15:05 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Fri May 26 11:15:05 2006] [debug] mod_proxy_http.c(1541): proxy: header only [Fri May 26 11:15:05 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Fri May 26 11:15:05 2006] [debug] mod_cache.c(602): cache: Caching url: /res/img/content/liferaft.jpg [Fri May 26 11:15:05 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Fri May 26 11:15:05 2006] [debug] mod_cache.c(726): cache: Content-Type text/html text/html [Fri May 26 11:15:05 2006] [debug] mod_cache.c(738): cache: Content-Type text/html image/jpeg [Fri May 26 11:15:05 2006] [debug] http_filters.c(990): http_filter: Content-Type text/html image/jpeg [Fri May 26 11:15:05 2006] [debug] http_filters.c(995): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:15:05 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Fri May 26 11:15:06 2006] [debug] cache_storage.c(261): Cached response for /res/img/content/liferaft.jpg isn't fresh. Adding/replacing conditional request headers. [Fri May 26 11:15:06 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /res/img/content/liferaft.jpg [Fri May 26 11:15:06 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /res/img/content/liferaft.jpg [Fri May 26 11:15:06 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/res/img/content/liferaft.jpg [Fri May 26 11:15:06 2006] [debug] proxy_util.c(1378): [client 64.85.232.3] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/res/img/content/liferaft.jpg [Fri May 26 11:15:06 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Fri May 26 11:15:06 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/res/img/content/liferaft.jpg [Fri May 26 11:15:06 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Fri May 26 11:15:06 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/res/img/content/liferaft.jpg to dev.greatschools.net:80 [Fri May 26 11:15:06 2006] [debug] proxy_util.c(1951): proxy: connected /res/img/content/liferaft.jpg to dev.greatschools.net:80 [Fri May 26 11:15:06 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Fri May 26 11:15:06 2006] [debug] mod_proxy_http.c(1541): proxy: header only [Fri May 26 11:15:06 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Fri May 26 11:15:06 2006] [debug] mod_cache.c(602): cache: Caching url: /res/img/content/liferaft.jpg [Fri May 26 11:15:06 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Fri May 26 11:15:06 2006] [debug] mod_cache.c(726): cache: Content-Type text/html text/html [Fri May 26 11:15:06 2006] [debug] mod_cache.c(738): cache: Content-Type text/html text/html [Fri May 26 11:15:06 2006] [debug] http_filters.c(990): http_filter: Content-Type text/html text/html [Fri May 26 11:15:06 2006] [debug] http_filters.c(995): http_filter: Content-Type text/html text/html [Fri May 26 11:15:06 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) This is two requests over the same tcp keepalive connection from firefox. The first request seemed to work, the second one firefix tried to render the jpeg as if it was html.
Just for comparison's sake, here is some debug log output while force-refreshing an image being served directly by the backend httpd server, not through mod_jk. [Fri May 26 11:20:28 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /images/reportcard.jpg [Fri May 26 11:20:28 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /images/reportcard.jpg [Fri May 26 11:20:28 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:28 2006] [debug] proxy_util.c(1378): [client 64.85.232.3] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:28 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Fri May 26 11:20:28 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:28 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Fri May 26 11:20:28 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:28 2006] [debug] proxy_util.c(1951): proxy: connected /images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:28 2006] [debug] proxy_util.c(2045): proxy: HTTP: fam 2 socket created to connect to dev.greatschools.net [Fri May 26 11:20:28 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Fri May 26 11:20:29 2006] [debug] mod_proxy_http.c(1448): proxy: start body send [Fri May 26 11:20:29 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Fri May 26 11:20:29 2006] [debug] mod_cache.c(602): cache: Caching url: /images/reportcard.jpg [Fri May 26 11:20:29 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Fri May 26 11:20:29 2006] [debug] http_filters.c(990): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:20:29 2006] [debug] http_filters.c(995): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:20:29 2006] [info] mem_cache: Cached url: http://nuked.greatschools.net:80/images/reportcard.jpg? [Fri May 26 11:20:29 2006] [debug] mod_proxy_http.c(1537): proxy: end body send [Fri May 26 11:20:29 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Fri May 26 11:20:38 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /images/reportcard.jpg [Fri May 26 11:20:38 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /images/reportcard.jpg [Fri May 26 11:20:38 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:38 2006] [debug] proxy_util.c(1378): [client 64.85.232.3] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:38 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Fri May 26 11:20:38 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:38 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Fri May 26 11:20:38 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:38 2006] [debug] proxy_util.c(1951): proxy: connected /images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:38 2006] [debug] proxy_util.c(2045): proxy: HTTP: fam 2 socket created to connect to dev.greatschools.net [Fri May 26 11:20:38 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Fri May 26 11:20:38 2006] [debug] mod_proxy_http.c(1448): proxy: start body send [Fri May 26 11:20:38 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Fri May 26 11:20:38 2006] [debug] mod_cache.c(602): cache: Caching url: /images/reportcard.jpg [Fri May 26 11:20:38 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Fri May 26 11:20:38 2006] [debug] http_filters.c(990): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:20:38 2006] [debug] http_filters.c(995): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:20:38 2006] [info] mem_cache: Cached url: http://nuked.greatschools.net:80/images/reportcard.jpg? [Fri May 26 11:20:38 2006] [debug] mod_proxy_http.c(1537): proxy: end body send [Fri May 26 11:20:38 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Fri May 26 11:20:39 2006] [debug] cache_storage.c(261): Cached response for /images/reportcard.jpg isn't fresh. Adding/replacing conditional request headers. [Fri May 26 11:20:39 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /images/reportcard.jpg [Fri May 26 11:20:39 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /images/reportcard.jpg [Fri May 26 11:20:39 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:39 2006] [debug] proxy_util.c(1378): [client 64.85.232.3] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:39 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Fri May 26 11:20:39 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:39 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Fri May 26 11:20:39 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:39 2006] [debug] proxy_util.c(1951): proxy: connected /images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:39 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Fri May 26 11:20:39 2006] [debug] mod_proxy_http.c(1541): proxy: header only [Fri May 26 11:20:39 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Fri May 26 11:20:39 2006] [debug] mod_cache.c(602): cache: Caching url: /images/reportcard.jpg [Fri May 26 11:20:39 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Fri May 26 11:20:39 2006] [debug] mod_cache.c(726): cache: Content-Type (null) image/jpeg [Fri May 26 11:20:39 2006] [debug] mod_cache.c(738): cache: Content-Type (null) image/jpeg [Fri May 26 11:20:39 2006] [debug] http_filters.c(990): http_filter: Content-Type (null) image/jpeg [Fri May 26 11:20:39 2006] [debug] http_filters.c(995): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:20:39 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Fri May 26 11:20:40 2006] [debug] cache_storage.c(261): Cached response for /images/reportcard.jpg isn't fresh. Adding/replacing conditional request headers. [Fri May 26 11:20:40 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /images/reportcard.jpg [Fri May 26 11:20:40 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /images/reportcard.jpg [Fri May 26 11:20:40 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:40 2006] [debug] proxy_util.c(1378): [client 64.85.232.3] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:40 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Fri May 26 11:20:40 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:40 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Fri May 26 11:20:40 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:40 2006] [debug] proxy_util.c(1951): proxy: connected /images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:40 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Fri May 26 11:20:40 2006] [debug] mod_proxy_http.c(1541): proxy: header only [Fri May 26 11:20:40 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Fri May 26 11:20:40 2006] [debug] mod_cache.c(602): cache: Caching url: /images/reportcard.jpg [Fri May 26 11:20:40 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Fri May 26 11:20:40 2006] [debug] mod_cache.c(726): cache: Content-Type (null) image/jpeg [Fri May 26 11:20:40 2006] [debug] mod_cache.c(738): cache: Content-Type (null) image/jpeg [Fri May 26 11:20:40 2006] [debug] http_filters.c(990): http_filter: Content-Type (null) image/jpeg [Fri May 26 11:20:40 2006] [debug] http_filters.c(995): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:20:40 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Fri May 26 11:20:41 2006] [debug] cache_storage.c(261): Cached response for /images/reportcard.jpg isn't fresh. Adding/replacing conditional request headers. [Fri May 26 11:20:41 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1378): [client 64.85.232.3] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Fri May 26 11:20:41 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1951): proxy: connected /images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:41 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Fri May 26 11:20:41 2006] [debug] mod_proxy_http.c(1541): proxy: header only [Fri May 26 11:20:41 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Fri May 26 11:20:41 2006] [debug] mod_cache.c(602): cache: Caching url: /images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Fri May 26 11:20:41 2006] [debug] mod_cache.c(726): cache: Content-Type (null) image/jpeg [Fri May 26 11:20:41 2006] [debug] mod_cache.c(738): cache: Content-Type (null) image/jpeg [Fri May 26 11:20:41 2006] [debug] http_filters.c(990): http_filter: Content-Type (null) image/jpeg [Fri May 26 11:20:41 2006] [debug] http_filters.c(995): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net) [Fri May 26 11:20:41 2006] [debug] cache_storage.c(261): Cached response for /images/reportcard.jpg isn't fresh. Adding/replacing conditional request headers. [Fri May 26 11:20:41 2006] [debug] mod_cache.c(129): Adding CACHE_SAVE filter for /images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] mod_cache.c(136): Adding CACHE_REMOVE_URL filter for /images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] mod_proxy_http.c(54): proxy: HTTP: canonicalising URL //dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1378): [client 64.85.232.3] proxy: http: found worker http://dev.greatschools.net/ for http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] mod_proxy.c(756): Running scheme http handler (attempt 0) [Fri May 26 11:20:41 2006] [debug] mod_proxy_http.c(1662): proxy: HTTP: serving URL http://dev.greatschools.net/images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1798): proxy: HTTP: has acquired connection for (dev.greatschools.net) [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1858): proxy: connecting http://dev.greatschools.net/images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1951): proxy: connected /images/reportcard.jpg to dev.greatschools.net:80 [Fri May 26 11:20:41 2006] [debug] proxy_util.c(2141): proxy: HTTP: connection complete to 198.144.205.152:80 (dev.greatschools.net) [Fri May 26 11:20:41 2006] [debug] mod_proxy_http.c(1541): proxy: header only [Fri May 26 11:20:41 2006] [debug] mod_headers.c(612): headers: ap_headers_output_filter() [Fri May 26 11:20:41 2006] [debug] mod_cache.c(602): cache: Caching url: /images/reportcard.jpg [Fri May 26 11:20:41 2006] [debug] mod_cache.c(608): cache: Removing CACHE_REMOVE_URL filter. [Fri May 26 11:20:41 2006] [debug] mod_cache.c(726): cache: Content-Type (null) image/jpeg [Fri May 26 11:20:41 2006] [debug] mod_cache.c(738): cache: Content-Type (null) image/jpeg [Fri May 26 11:20:41 2006] [debug] http_filters.c(990): http_filter: Content-Type (null) image/jpeg [Fri May 26 11:20:41 2006] [debug] http_filters.c(995): http_filter: Content-Type image/jpeg image/jpeg [Fri May 26 11:20:41 2006] [debug] proxy_util.c(1816): proxy: HTTP: has released connection for (dev.greatschools.net)
Created attachment 18357 [details] Patch against trunk I think I got it know. The attached patch should fix your problem. So could you please do the following: 1. Start with clean sources (at least without the debug patch I sent earlier) 2. Apply the patch for 39266 3. Apply the attached patch 4. Compile 5. Test 6. Let me know the results :-).
Created attachment 18358 [details] Patch against mod_jk.c (1.3 Version) of mod_jk 1.2.15 Apart from the patch against 2.2.x I am pretty much sure that the behaviour of the backend (sending Content-Length and Content-Type for a 304 response) is not compliant with RFC 2616. 10.3.5 in RFC 2616 states: The 304 response MUST NOT contain a message-body, and thus is always terminated by the first empty line after the header fields. I read this as Content-Length and Content-Type header MUST NOT be sent with 304 responses and the behaviour of httpd 2.2.x and the http connector of Tomcat not doing this seem to support this view. From my limited point of view on httpd 1.3 this should be fixed inside mod_jk. I think that the attached patch, which is untested due to my lack of an available httpd 1.3, does this without breaking other things. So, if you like you can give the attached patch a try to make your backend RFC 2616 compliant again :-).
Hi there. Thanks for your help on this issue. The patch modules/cache/cache_storage.c seems to do the trick! I'll try out the patch to mod_jk too. I agree, it seems like mod_jk is breaking RFC 2616, I'll try out the patch on the backend web server and make sure it doesn't break anything else.
Committed to trunk as r410370 (http://svn.apache.org/viewvc?rev=410370&view=rev).
FYI I've been running the patch against mod_jk.c for about two weeks now with no ill effects.
Backported to 2.2.x as r425725 (http://svn.apache.org/viewvc?rev=425725&view=rev).
The resolution to this bug breaks a MUST-level requirement of RFC2616. From <http://www.w3.org/ Protocols/rfc2616/rfc2616-sec13.html#sec13.5.3>; [[[ The end-to-end headers stored in the cache entry are used for the constructed response, except that [...] - any end-to-end headers provided in the 304 or 206 response MUST replace the corresponding headers from the cache entry. Unless the cache decides to remove the cache entry, it MUST also replace the end-to-end headers stored with the cache entry with corresponding headers received in the incoming response, except for Warning headers as described immediately above. If a header field- name in the incoming response matches more than one header in the cache entry, all such old headers MUST be replaced. In other words, the set of end-to-end headers received in the incoming response overrides all corresponding end-to-end headers stored with the cache entry (except for stored Warning headers with warn-code 1xx, which are deleted even if not overridden). ]]] The correct resolution was to fix mod_jk, which the reporter said worked for them. Please back this patch out.
I respectfully disagree here. According to 10.3.5 the response must not / should not contain any entity headers (depending on the validator type). Furthermore 10.3.5 states that this should prevent inconsistencies between the cached entity body and the updated header. Content-type is an entity header and changing the Content-type clearly would create inconsistencies between the cached entity body and the updated header. So we are generous in what we acccept. If you still disagree please continue this discussion on the dev@httpd.apache.org list.
10.3.5 says: [[[ If the conditional GET used a strong cache validator (see section 13.3.3), the response SHOULD NOT include other entity-headers. Otherwise (i.e., the conditional GET used a weak validator), the response MUST NOT include other entity-headers; this prevents inconsistencies between cached entity-bodies and updated headers. ]]] That applies to the responses; it doesn't specify the behaviour of the cache when it receives such responses. 10.3.5 goes on to say [[[ If a cache uses a received 304 response to update a cache entry, the cache MUST update the entry to reflect any new field values given in the response. ]]] However, your reading does make sense. Rather than try and second-guess an apparent inconsistency in the spec, I"ll follow up with the HTTP-WG list.