[Varnish] #1001: Varnish 3.0.1 crashes in http_GetHdr
Varnish
varnish-bugs at varnish-cache.org
Wed Aug 31 21:33:11 CEST 2011
#1001: Varnish 3.0.1 crashes in http_GetHdr
----------------------+-----------------------------------------------------
Reporter: anders | Owner:
Type: defect | Status: new
Priority: high | Milestone:
Component: varnishd | Version: 3.0.1
Severity: critical | Keywords:
----------------------+-----------------------------------------------------
Comment(by anders):
When this happens, the last lines outputted by varnishlog -O was:
{{{
395 RxHeader c Accept-Encoding: gzip, deflate
395 RxHeader c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
395 RxHeader c Connection: keep-alive
395 RxHeader c Referer: http://www.aftenbladet.no/
395 RxHeader c Cookie: rsi_segs=; xtvrn=$398888$
395 RxHeader c If-Modified-Since: Wed, 31 Aug 2011 18:07:49 GMT
395 RxHeader c Cache-Control: max-age=0
395 VCL_call c recv
395 VCL_acl c NO_MATCH nocacheclients
395 VCL_return c lookup
395 VCL_call c hash
395 Hash c
/incoming/article2857960.ece/ALTERNATES/w680c169/halltoll.jpg
395 Hash c www.aftenbladet.no
395 VCL_return c hash
395 VCL_call c miss
395 VCL_return c fetch
398 BackendOpen b sa 80.91.37.197 64009 80.91.41.74 80
395 Backend c 398 sa sa
398 TxRequest b GET
398 TxURL b
/incoming/article2857960.ece/ALTERNATES/w680c169/halltoll.jpg
398 TxProtocol b HTTP/1.1
398 TxHeader b Host: mediahash2.aftenbladet.no
398 TxHeader b User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64;
rv:6.0) Gecko/20100101 Firefox/6.0
398 TxHeader b Accept: image/png,image/*;q=0.8,*/*;q=0.5
398 TxHeader b Accept-Language: nb-no,nb;q=0.9,no-no;q=0.8,no;q=0.6
,nn-no;q=0.5,nn;q=0.4,en-us;q=0.3,en;q=0.1
398 TxHeader b Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
398 TxHeader b Referer: http://www.aftenbladet.no/
398 TxHeader b Cookie: rsi_segs=; xtvrn=$398888$
398 TxHeader b X-Varnish: 534089652
398 TxHeader b Accept-Encoding: gzip
}}}
The last request from Varnish as seen from ngrep:
{{{
T 80.91.37.197:64009 -> 80.91.41.74:80 [AP]
GET /incoming/article2857960.ece/ALTERNATES/w680c169/halltoll.jpg
HTTP/1.1.
Host: mediahash2.aftenbladet.no.
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:6.0) Gecko/20100101
Firefox/6
.0.
Accept: image/png,image/*;q=0.8,*/*;q=0.5.
Accept-Language: nb-no,nb;q=0.9,no-no;q=0.8,no;q=0.6,nn-no;q=0.5,nn;q=0.4
,en-us;
q=0.3,en;q=0.1.
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7.
Referer: http://www.aftenbladet.no/.
Cookie: rsi_segs=; xtvrn=$398888$.
X-Varnish: 534089652.
Accept-Encoding: gzip.
}}}
And the response:
{{{
T 80.91.41.74:80 -> 80.91.37.197:64009 [A]
HTTP/1.1 200 OK.
Date: Wed, 31 Aug 2011 19:12:11 GMT.
Server: Apache-Coyote/1.1.
Last-Modified: Wed, 31 Aug 2011 18:10:15 GMT.
Cache-Control: public, max-age=31536000.
Content-Type: image/jpeg.
Content-Length: 38891.
Set-Cookie: JSESSIONID=E5FBDEB1DA51A5C3431A9520E31385D6; Path=/sa.
X-Backend: saweb3.
Connection: close.
.
......JFIF.............C.
(picture data..)
}}}
A gdb trace (gdb attached to process) with this particular crash:
{{{
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 806640b80 (LWP 101300)]
0x00000008008c9e7f in getframeaddr (level=Variable "level" is not
available.
) at execinfo.c:273
273 case 2: return __builtin_frame_address(3);
(gdb) bt
#0 0x00000008008c9e7f in getframeaddr (level=Variable "level" is not
available.
) at execinfo.c:273
#1 0x00000008008c9ebc in backtrace (buffer=Variable "buffer" is not
available.
) at execinfo.c:53
#2 0x000000000042d849 in pan_ic (func=0x455df0 "http_GetHdr",
file=0x4557f0 "cache_http.c", line=266, cond=0x455900 "l == strlen(hdr
+ 1)",
err=Variable "err" is not available.
) at cache_panic.c:283
#3 0x0000000000429afc in http_GetHdr (hp=0x80907b3e8,
hdr=0x807060e42 ".91.37.197", ptr=0x7ffff3b8b4c8) at cache_http.c:266
#4 0x000000000043339f in VRY_Match (sp=0x80907b008,
vary=0x807060e40 "80.91.37.197") at cache_vary.c:192
#5 0x000000000042630b in HSH_Lookup (sp=0x80907b008, poh=0x7ffff3b8b580)
at cache_hash.c:358
#6 0x0000000000414592 in cnt_lookup (sp=0x80907b008) at
cache_center.c:1088
#7 0x0000000000417aaf in CNT_Session (sp=0x80907b008) at steps.h:38
#8 0x0000000000430221 in wrk_do_cnt_sess (w=0x7ffff3b9ec80, priv=Variable
"priv" is not available.
)
at cache_pool.c:301
#9 0x000000000042f3ba in wrk_thread_real (qp=0x801213600,
shm_workspace=Variable "shm_workspace" is not available.
)
at cache_pool.c:184
#10 0x0000000800e61511 in pthread_getprio () from /lib/libthr.so.3
#11 0x0000000000000000 in ?? ()
Error accessing memory address 0x7ffff3b9f000: Bad address.
(gdb) frame 4
#4 0x000000000043339f in VRY_Match (sp=0x80907b008,
vary=0x807060e40 "80.91.37.197") at cache_vary.c:192
192 i = http_GetHdr(sp->http, (const
char*)(vary+2), &h);
(gdb) print sp->http
$1 = (struct http *) 0x80907b3e8
(gdb) print *sp->http
$2 = {magic = 1680389577, logtag = HTTP_Rx, ws = 0x80907b080, hd =
0x80907b410,
hdf = 0x80907b810 "", shd = 64, nhd = 14, status = 0, protover = 11
'\v',
conds = 0 '\0'}
(gdb) print vary
$3 = (const uint8_t *) 0x807060e40 "80.91.37.197"
(gdb) print *vary
$4 = 56 '8'
(gdb) print *sp
$5 = {magic = 741317722, fd = 384, id = 384, xid = 534089653, restarts =
0,
esi_level = 0, disable_esi = 0, hash_ignore_busy = 0 '\0',
hash_always_miss = 0 '\0', wrk = 0x7ffff3b9ec80, sockaddrlen = 16,
mysockaddrlen = 128, sockaddr = 0x80907b2e8, mysockaddr = 0x80907b368,
mylsock = 0x8012224f0, addr = 0x80907bcb8 "80.202.232.18",
port = 0x80907bcc8 "3166", client_identity = 0x0, doclose = 0x0,
http = 0x80907b3e8, http0 = 0x80907b850, ws = {{magic = 905626964,
overflow = 0,
id = 0x453366 "sess", s = 0x80907bcb8 "80.202.232.18", f =
0x80907bfa8 "",
r = 0x80908bcb8 "", e = 0x80908bcb8 ""}}, ws_ses = 0x80907bcd0
"GET",
ws_req = 0x80907bf78 "Accept-Encoding: gzip",
digest = "A�f\201Lw�-p\031/�hq*�\032\210l\202\213^�*Vp\217�xJqO",
vary_b = 0x80907bfa8 "", vary_l = 0x0, vary_e = 0x80908bcb8 "", htc = {{
magic = 1041886673, fd = 384, maxbytes = 32768, maxhdr = 4096,
ws = 0x80907b080, rxbuf = {b = 0x80907bcd0 "GET", e = 0x80907bf75
""},
pipeline = {b = 0x0, e = 0x0}}}, t_open = 1314817931.3116455,
t_req = 1314817931.3199937, t_resp = nan(0x8000000000000),
t_end = 1314817931.3116455, exp = {ttl = -1, grace = 21600, keep = -1,
age = 0,
entered = 0}, step = STP_LOOKUP, cur_method = 0, handling = 3,
sendbody = 0 '\0', wantbody = 1 '\001', err_code = 0, err_reason = 0x0,
list = {
vtqe_next = 0x0, vtqe_prev = 0x0}, director = 0x801213978, vbc = 0x0,
obj = 0x0, objcore = 0x0, vcl = 0x80139ee28, hash_objhead = 0x0,
mem = 0x80907b000, workreq = {list = {vtqe_next = 0x0, vtqe_prev = 0x0},
func = 0x430160 <wrk_do_cnt_sess>, priv = 0x80907b008}, acct_tmp =
{first = 0,
sess = 1, req = 1, pipe = 0, pass = 0, fetch = 0, hdrbytes = 0,
bodybytes = 0},
acct_req = {first = 0, sess = 0, req = 0, pipe = 0, pass = 0, fetch = 0,
hdrbytes = 0, bodybytes = 0}, acct_ses = {first = 1314817931.3116455,
sess = 0,
req = 0, pipe = 0, pass = 0, fetch = 0, hdrbytes = 0, bodybytes = 0}}
(gdb) print h
$8 = 0x42d295 "�E\020\001"
(gdb) print *h
$9 = -57 '�'
}}}
So it doesn't seem to be a Vary header?
--
Ticket URL: <http://www.varnish-cache.org/trac/ticket/1001#comment:8>
Varnish <http://varnish-cache.org/>
The Varnish HTTP Accelerator
More information about the varnish-bugs
mailing list