Bug 41551 - mod_mem_cache cache incorrect header
Summary: mod_mem_cache cache incorrect header
Status: RESOLVED FIXED
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: mod_cache (show other bugs)
Version: 2.2.4
Hardware: Other Linux
: P2 regression (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2007-02-06 23:22 UTC by Xuekun Hu
Modified: 2014-02-17 13:52 UTC (History)
0 users



Attachments
don't use apr_table_copy to store/recall headers (1.87 KB, patch)
2007-04-13 05:22 UTC, Eric Covener
Details | Diff
table copy warning (521 bytes, patch)
2007-04-27 19:57 UTC, Davi Arnaut
Details | Diff
deep table copy (1.76 KB, patch)
2007-04-27 20:14 UTC, Davi Arnaut
Details | Diff
table copy (clone) function for apr (1.47 KB, patch)
2007-05-08 15:36 UTC, Davi Arnaut
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Xuekun Hu 2007-02-06 23:22:42 UTC
Hi, 
I'm using Apache2.2.4 (worker+mod_mem_cache). I just used mod_mem_cache to 
cache some little files. However after run severl minutes, I found the file 
content sent by mod_mem_cache are incorrect!! 

I captured the response package. And I found those error packages are sending  
the wrong http headers, like including several headers, wrong ETag value. Seems 
like memory overflow!! For example, one response are:
----------------------------------------------------------------------- 
HTTP/1.1 200 OK
Date: Thu, 25 Jan 2007 11:30:51 GMT
Server: Apache/2.2.4 (Unix) mod_jk/1.2.15
Last-Modified: Thu, 01 Jan 1970 00:00:00 GMT
ETag: 2<uwJU@x@)IzNFELwphctT&^r^MvqY
kP\k'gZ@Zrs3a-_S+"A@z%49o[9nyUX^-eR9j1*(lp9B4A3)R]J2?yi:sbVxZJV
?('9e@tFn$>.cokt;ao/V|^tXj\UIo-|Xz6YX(nXE9:y/OcK5Yl7]%D3`#s=+;o
cZci>tNQ+|UUp5RETf>f72<{b*0ICP*gz0>'|2UAY'4VeIfL;?4S>*0t9:V9B|B
hML1)p?]grrJ/ku4`h/'N(H63PEi@$qfiP<;f,$7a<Ogy7<[rR]!TMZf{c1($]M
-a_Sb,W`09|)D|NnaD`jHrd*h4ck6]W&xy?sv)]uVZ#u?d!^q/TBM1sD\&."SM/
Ad.W1[2)(2RgwQO.2^wQ|/s?^9np7MiN:9/A|V.xki1C8u164bo6pD,#>Jl2IX,
ZdOG;b4>ET>|%2[6Sv;vE_eLhtFhj\jlyA@QQKj`k3/ONE="7j'Ty.73`w&a-DE
l%@X&H:T*,x\@BbVPST!)Tbfjh0RS+yUI@',{sMP\I'z:M?_"dQadTN;"ob&_w`
EE[)\wj{'r:&]J|H%%j#W8>)0bZrJzlHH4:vLw[xyrtC]IY9%_pH-R8l(3?V#-N
fqo,?$R"<aE6aa1N7iU,,(>,Bv2zk<Z+Gqg'"O\nFxV/Zpz3I(_Z|hYi26f!n'X
tp`fyb!iqrBV7e6(h?6'zKL@PGc$bJsgc1$ZkrHL<tYJ1OFb,_h'5]!$XrMB^]!
94/>=OObnMgS33U'bg+Uf26dC:!4`8h_n>'w>U0/!mqc6-9yD#gN%.pV3DeJHsE
KNfI+wCCH]BPin<sChB21XKr1+pgDuWLzHGOkg>Jg0F'q,_I|M^$cnVbi7cU-T$
=eFc;h(8jov[Adbcy#>-n7G3l!DU!>f!zDx.#q42T1i-Z)H"4e*M6.`jhLnj0P"
+.H[yP'n?b7=KmoTwGCg,@rbV1Qf5n[4rRn\$7yB^/`zu?='@v3h$RdG7wJQY)K
1e/&zO5y-w5q("?NQmuPa"PAi.;-Os0NN>Nx/8Qk(kEb/0pILMbRd!Dd>3s80D/
o1s3@"#iSV0!"CJlDuDKlkmh41_s+>$*K?F{-i@Uz(+16t#xlqF""\SZ!-)miPG
U[PkYIO!Yfuz'tlGNb|`6[983jtwyB?F?A8Xmr*[@+^F|AuW!/o9k:50d)T)Twq
`f"n(?ou;(*ZBL-3=9Ue)\]Y[p1nNEI'lf2lNF3KS4BI()6smg1?q(bc'.0[b&O
F;=?q=V'&Lyq+_VGke@H*`$32\d[@3W<DS"[bV0^-c/wVX"+F(@#)r*/{5"LAxH
IJI#(SXmlmak6+]4n+p-F;]5V&00er+JQ[;hU]GR4+eXJ_]T;Cx*LS!|:m$#3G8
|vgF]TA_/d!G#Z,5-sTV,^J4UurZ['?,v$5\IDRcV(]`dN?.H`1@5ll1n7pq7([
'\eoDI1&R0#R*`VS8Mjy[q&{q&h<h=1x{CD[w'(5]SQ*)`uty*|(41&:n3%*dRq
RD9s:61RDRK3XO?n/TIF-dmK]1c0#Vgo@#0XLM1{x4s/w;M':j#GU=.ubloj@N#
Y=fI-2c{{^_?/tOIr$5jq&xpAaT_hc0XqE.Hbge6{76^h@ek/GH@Hi>TBob(;c+
i,8OS2aTS_dv5j*e^VCE`+UIU&y@S7huO!Xj?mTmz#Z,Ca0W-z2X%HysN[NxO{g
TDSvcaFVVz_3ms5*uV)bdA^K52p`UKO[HZ<WzVFUUECIcJjD2cIKxxW?{a?Sa/M
P;kma`)4q#*?'xjO1L-*BUuUjwDOHcUEFE1;oGwzQl!lzko2x5]@62$P{aRY*"3
o.m"1oT/q93&{(#M<g)!c^h$F--,Nnk|<.#Q:7L+$e(*@S3xJiFTJuYZ@Wf^\Q(
s4GQ#arbPmAg5T{70$KnVbbTsyc4fe'_*xf6W?$ExHU6_;>b4;$oKOX`4j*aApl
K#?s[/PwP6DkqxZB`Z:j?:Kdt;'^{wCLh|662k_k<pbm|&QbVBlt/LWjeBLKDVS
{kHTiH@w(1TIxwp"T2*5u){aMWoOsif4J5?lT"@C,vAKX!>^,wl`I58FBY3#e@&
+%1t&m@m4.m6L>q^5l3V',J?FPhC-_$:X,>t#yB"0!UgEHG.>eVJIzu)K|gJh"?
hmXf%bz3pHTzGHQ'A[9:vW-y_Fkunqalva%pu0vo8RBZE*{G1e=c(c-.`N,<J_T
D'$7I2XJpxgxT&h4mH-t+yr`DGK.8N]_=?ZB)V-84U(L7XrA+'MC|;,k*][XY0L
!::f@Zm]xAlQo`?FFJ)=>3Sp5Y,FDJLfp;(WST{U]MK$'Z0PbfrE&gk1grzC.l*
27<X%nau9%&]<IYA+.sA`9C|KLf@o^S2FAgB+]U8MkG_]G5?eg4&{2P#iLKenxT
fq(1LM,rn1@33.9]xp6;@FJPPFQYD"@>ED'D%nfkj;-qEK1[d^wV:i,"NLuylTN
/E(82(nsb,a`8')I=$jP6?8Z.4IH7NE@@$4l:79J/dCU@`=37bT(Opd"`n;(dk&
p6*F-#x!W<no$;Di2%s_]SmXlYgfhEiyTcv`0'PB`[[SP@cl:HM5B*[jvAkUvra
ff=fCE0?P2DqySbc{W5E@[-Bj3-S3,TT_o&=ek:sY(8a_HubaCTX+,,3PFL5.Ap
wWU%^Ohf!9WnizXy|sd.t[qftGmF(.&_fEF6\s`dvRfAg+R8q(Hv"9</pre>
</body>
</html>

Accept-Ranges: bytes
Content-Length: 2170
Expires: Fri, 26 Jan 2007 11:27:58 GMT
Age: 107
Content-Type: text/plain; charset=ISO-8859-1

Accept-Ranges: bytes
Content-Length: 90
Expires: Fri, 26 Jan 2007 11:27:11 GMT
Age: 158
Content-Type: text/plain; charset=ISO-8859-1
...
---------------------------------------------------------------------

While I also tested Apache2.2.3+mod_mem_cache, Apache2.2.4 without 
mod_mem_cache, Apache2.2.4+mod_disk_cache, all work fine. 
So, there must something wrong in mod_mem_cache itself.

I compared with mod_mem_cache in 2.2.3 vs. 2.2.4, the big change is using APR 
memory pool to cache http header, instead of malloc. However I had no idea what 
the real reason is. 

Any thoughts?

Thx, Xuekun
Comment 1 Eric Covener 2007-04-12 20:41:44 UTC
I am seeing the etag blown away on 2.2.4 and trunk as well, running with a
single child process and no concurrent connections.  This happens _before_
revalidation based on Expires or Age (on a particular system/config 4th
non-conditional request gets the ETag removed in some way (truncated, random
garbage)

I was occasionally seeing the Last-Modified time set to 0 as well, but not able
to reproduce it as easily.
Comment 2 Eric Covener 2007-04-13 05:22:46 UTC
Created attachment 19948 [details]
don't use apr_table_copy to store/recall headers

naive patch to deep copy in/out headers before storing/retrieving from cache.

when retrieving, we only bother to do the deep copy to appease pool debugging,
who would abort even when the cache pool is longer living, but not an ancester
of, the request pool.
Comment 3 Xuekun Hu 2007-04-16 02:18:52 UTC
(In reply to comment #2)
> Created an attachment (id=19948) [edit]
> don't use apr_table_copy to store/recall headers
> naive patch to deep copy in/out headers before storing/retrieving from cache.
> when retrieving, we only bother to do the deep copy to appease pool debugging,
> who would abort even when the cache pool is longer living, but not an ancester
> of, the request pool.

No. Your patch didn't resolve this issue. The same error still was blown away. 
Comment 4 Davi Arnaut 2007-04-27 19:37:43 UTC
Ouch, that's my fault. I naively believed that apr_table_copy copied the table data. We should revert 
revision 484642 ASAP.
Comment 5 Davi Arnaut 2007-04-27 19:57:18 UTC
Created attachment 20064 [details]
table copy warning
Comment 6 Davi Arnaut 2007-04-27 20:14:24 UTC
Created attachment 20065 [details]
deep table copy
Comment 7 Davi Arnaut 2007-04-27 20:15:35 UTC
Could you try the above patch and let me know if you still have these errors? Thanks.
Comment 8 Xuekun Hu 2007-04-29 20:02:13 UTC
(In reply to comment #7)
> Could you try the above patch and let me know if you still have these errors? 
Thanks.

I tried your patch with several hours run, all seems fine. Thanks 

Comment 9 Davi Arnaut 2007-05-08 15:36:35 UTC
Created attachment 20150 [details]
table copy (clone) function for apr
Comment 10 Ruediger Pluem 2007-08-27 04:48:00 UTC
Backported to 2.2.x as r555626 (http://svn.apache.org/viewvc?
view=rev&revision=555626).