[Varnish] #489: Assert error in BAN_CheckObject()
Varnish
varnish-bugs at projects.linpro.no
Fri May 22 13:57:44 CEST 2009
#489: Assert error in BAN_CheckObject()
----------------------+-----------------------------------------------------
Reporter: waschtl | Owner: phk
Type: defect | Status: new
Priority: normal | Milestone:
Component: varnishd | Version: trunk
Severity: major | Resolution:
Keywords: |
----------------------+-----------------------------------------------------
Comment (by waschtl):
waschtl replying to [comment:7 waschtl]:
So, now here is the panic message, the backtrace, and relevant information
based on the document of Debugging Varnish.
I am supplying a lot of information here. I hope all the necessary
information is in there, and if it's too much information -- I apologize.
Panic Message:
{{{
child (18618) Started
Child (18618) said Closed fds: 4 5 7 10 11 13 14
Child (18618) said Child starts
Child (18618) said managed to mmap 1073741824 bytes of 1073741824
Child (18618) said Ready
Child (18618) not responding to ping, killing it.
Child (18618) not responding to ping, killing it.
Child (18618) not responding to ping, killing it.
Child (18618) not responding to ping, killing it.
Child (18618) not responding to ping, killing it.
Child (18618) not responding to ping, killing it.
Child (18618) died signal=6 (core dumped)
Child (18618) Panic message: Assert error in BAN_CheckObject(),
cache_ban.c line 423:
Condition((o->ban) != NULL) not true.
thread = (cache-worker)
Backtrace:
0x42641f: pan_ic+132
0x411675: BAN_CheckObject+127
0x41f46e: HSH_Lookup+65a
0x414874: cnt_lookup+17b
0x41609a: CNT_Session+4e2
0x4280e3: wrk_do_cnt_sess+12a
0x427979: wrk_thread_real+5cd
0x427d67: wrk_thread+a0
sp = 0x2aab13a25008 {
fd = 34, id = 34, xid = 342003300,
client = 127.0.0.1:35706,
step = STP_LOOKUP,
handling = hash,
restarts = 1, esis = 0
ws = 0x2aab13a25078 {
id = "sess",
{s,f,r,e} = {0x2aab13a25808,+317,(nil),+16384},
},
http[req] = {
ws = 0x2aab13a25078[sess]
"GET",
"/VirtualHostBase/http/www.xxxx.de/xxxx/VirtualHostRoot//",
"HTTP/1.0",
"X-Enable-SSI: True",
"X-Hosting: www.xxxx.de",
"X-Real-IP: x.x.x.x",
"X-Forwarded-For: x.x.x.x",
"Host: www.xxxx.de",
"Connection: close",
"Cache-Control: no-cache",
"User-Agent: ApacheBench/2.0.40-dev",
"Accept: */*",
},
worker = 0x49010420 {
ws = 0x49010910 {
id = "wrk",
{s,f,r,e} = {0x4900a3a0,0x4900a3a0,(nil),+16384},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
}}}
GDB Output:
{{{
(gdb) bt
#0 0x00002b6ec9fad095 in raise () from /lib/libc.so.6
#1 0x00002b6ec9faeaf0 in abort () from /lib/libc.so.6
#2 0x00000000004264f8 in pan_ic (func=0x454200 "BAN_CheckObject",
file=0x453eb9 "cache_ban.c", line=423, cond=0x4541b1 "(o->ban) != NULL",
err=0, xxx=0)
at cache_panic.c:356
#3 0x0000000000411675 in BAN_CheckObject (o=0x2aaaac3d9000,
sp=0x2aab13a25008) at cache_ban.c:423
#4 0x000000000041f46e in HSH_Lookup (sp=0x2aab13a25008, poh=0x4900a2f0)
at cache_hash.c:472
#5 0x0000000000414874 in cnt_lookup (sp=0x2aab13a25008) at
cache_center.c:740
#6 0x000000000041609a in CNT_Session (sp=0x2aab13a25008) at steps.h:38
#7 0x00000000004280e3 in wrk_do_cnt_sess (w=0x49010420,
priv=0x2aab13a25008) at cache_pool.c:456
#8 0x0000000000427979 in wrk_thread_real (qp=0x2b6ec8f0c150,
shm_workspace=8192, sess_workspace=16384) at cache_pool.c:351
#9 0x0000000000427d67 in wrk_thread (priv=0x2b6ec8f0c150) at
cache_pool.c:387
#10 0x00002b6ec98ca3f7 in start_thread () from /lib/libpthread.so.0
#11 0x00002b6eca052b3d in clone () from /lib/libc.so.6
#12 0x0000000000000000 in ?? ()
(gdb) frame 3
#3 0x0000000000411675 in BAN_CheckObject (o=0x2aaaac3d9000,
sp=0x2aab13a25008) at cache_ban.c:423
423 in cache_ban.c
(gdb) print o
$3 = (struct object *) 0x2aaaac3d9000
(gdb) print *o
Cannot access memory at address 0x2aaaac3d9000
(gdb) print sp
$4 = (const struct sess *) 0x2aab13a25008
(gdb) print *sp
$5 = {magic = 741317722, fd = 34, id = 34, xid = 342003300, restarts = 1,
esis = 0, disable_esi = 0, wrk = 0x49010420, sockaddrlen = 16,
mysockaddrlen = 128, sockaddr = 0x2aab13a25708, mysockaddr =
0x2aab13a25788, mylsock = 0x2b6ec8f19ee0, addr = 0x2aab13a25808
"127.0.0.1",
port = 0x2aab13a25812 "35706", doclose = 0x456e4d "Connection: close",
http = 0x2aab13a25250, http0 = 0x2aab13a254a0, ws = {{magic = 905626964,
id = 0x4583d3 "sess", s = 0x2aab13a25808 "127.0.0.1", f =
0x2aab13a25945 "", r = 0x0, e = 0x2aab13a29808 "", overflow = 0}},
ws_ses = 0x2aab13a25818 "GET", ws_req = 0x2aab13a25945 "", htc = {{magic
= 1041886673, fd = 34, ws = 0x2aab13a25078, rxbuf = {b = 0x2aab13a25818
"GET",
e = 0x2aab13a25945 ""}, pipeline = {b = 0x0, e = 0x0}}}, t_open =
1242418936.7020173, t_req = 1242418936.7020481, t_resp =
nan(0x8000000000000),
t_end = nan(0x8000000000000), connect_timeout = 0.40000000000000002,
first_byte_timeout = 60, between_bytes_timeout = 60, grace = 30, step =
STP_LOOKUP,
cur_method = 0, handling = 2, sendbody = 0 '\0', wantbody = 1 '\001',
err_code = 0, err_reason = 0x0, list = {vtqe_next = 0x2aab124f1008,
vtqe_prev = 0x2aab7e1df850}, director = 0x2b6ec8f0c298, vbe = 0x0, obj
= 0x0, objcore = 0x0, objhead = 0x0, vcl = 0x2b6ec8f02428, mem =
0x2aab13a25000,
workreq = {list = {vtqe_next = 0x2aaaeb4e7198, vtqe_prev =
0x2b6ec8f0c1c0}, func = 0x427fb9 <wrk_do_cnt_sess>, priv =
0x2aab13a25008}, acct = {
first = 1242418936.7020173, sess = 0, req = 0, pipe = 0, pass = 0,
fetch = 0, hdrbytes = 0, bodybytes = 0}, acct_req = {first = 0, sess = 1,
req = 1,
pipe = 0, pass = 0, fetch = 0, hdrbytes = 0, bodybytes = 0}, nhashptr
= 0, ihashptr = 0, lhashptr = 0, hashptr = 0x0}
}}}
Further information consolidated (given here and there elsewhere):
* Version: r4076[[BR]]
* Architecture: x86_64 (amd64 on Intel)[[BR]]
* Mode: 64-bit[[BR]]
* RAM: 16 GB, varnish uses 1 GB[[BR]]
* OS/Kernel: ubuntu 8.04 (hardy) / linux-2.6.22.10-vs2.2.0.4 (with linux-
vserver-patch)[[BR]]
* VCL: see below[[BR]]
vcl.conf:
{{{
acl purge {
"localhost";
"127.0.0.1";
"x.x.x.x"/26;
}
backend default {
/* backend = pound */
.host = "127.0.0.1";
.port = "8001";
}
sub vcl_recv {
if (req.request != "GET" &&
req.request != "HEAD" &&
req.request != "PUT" &&
req.request != "POST" &&
req.request != "TRACE" &&
req.request != "OPTIONS" &&
req.request != "PURGE" &&
req.request != "DELETE") {
/* Non-RFC2616 or CONNECT which is weird. */
pipe;
}
if (req.request == "POST") {
pipe;
}
# purge if someone hits shift-reload. This ONLY WORKS IF THE URL
does not look like a regexp (i.e. with a "+" in it!)
# for such urls see the workaround in vcl_hit.
if (req.http.Cache-Control ~ "no-cache") {
purge_url(req.url);
}
if (req.request != "GET" && req.request != "HEAD") {
# PURGE request if zope asks nicely
if (req.request == "PURGE") {
if (!client.ip ~ purge) {
error 405 "Not allowed.";
}
lookup;
}
pass;
}
if (req.http.Expect) {
pipe;
}
/* Don't use the cache for /community. */
if (req.url ~ "/communityfotos") {
set req.grace = 30s;
lookup;
}
/* Don't use the cache for /community. */
if (req.url ~ "/community/") {
pass;
}
/* Always cache images, css and js */
if (req.url ~
"\.(jpg|jpeg|gif|png|tiff|tif|svg|swf|ico|css|js|vsd|doc|ppt|pps|xls|pdf|mp3|mp4|m4a|ogg|mov|avi|wmv|sxw|zip|gz|bz2|tgz|tar|rar|odc|odb|odf|odg|odi|odp|ods|odt|sxc|sxd|sxi|sxw|dmg|torrent|deb|msi|iso|rpm)$")
{
set req.grace = 30s;
lookup;
}
# We only care about the "__ac.*" cookies, used for authentication
and special persistent p_* cookies.
if (req.http.Cookie && ( req.http.Cookie ~
"__ac|(_(name|password|persistent))=" || req.http.Cookie ~ "p_[^=]+=" ||
req.http.Cookie ~ "captchasessionid=" )) {
pass;
}
# throw away cookies all other and lookup
set req.grace = 30s;
remove req.http.cookie;
lookup;
}
sub vcl_pipe {
pipe;
}
sub vcl_pass {
pass;
}
sub vcl_hash {
set req.hash += req.url;
if (req.http.host) {
set req.hash += req.http.host;
} else {
set req.hash += server.ip;
}
hash;
}
sub vcl_hit {
# this should all work in vcl_recv, but it doesn't for urls with a
"+" in it, i.e.
# urls that look like regular expressions. So we workaround here.
# THIS ONLY WORK IN VARNISH 2.0.3 OR GREATER (or trunk)!!!
if (req.request == "PURGE") {
set obj.ttl = 0s;
error 200 "Purged.";
}
if (req.http.Cache-Control ~ "no-cache") {
set obj.ttl = 0s;
restart;
}
if (!obj.cacheable) {
pass;
}
deliver;
}
sub vcl_miss {
if (req.request == "PURGE") {
error 404 "Not in cache.";
}
fetch;
}
sub vcl_fetch {
set beresp.grace = 30s;
if (beresp.ttl < 300s) {
set beresp.ttl = 300s;
}
if (beresp.http.Set-Cookie) {
pass;
}
if (req.url ~ "(/rss|search_rss)") {
set beresp.ttl = 1800s;
}
/* Always cache images, css and js for at least 24 hours */
if (req.url ~
"\.(jpg|jpeg|gif|png|tiff|tif|svg|swf|ico|css|js|vsd|doc|ppt|pps|xls|pdf|mp3|mp4|m4a|ogg|mov|avi|wmv|sxw|zip|gz|bz2|tgz|tar|rar|odc|odb|odf|odg|odi|odp|ods|odt|sxc|sxd|sxi|sxw|dmg|torrent|deb|msi|iso|rpm)$")
{
set beresp.ttl = 86400s;
}
#set beresp.prefetch = -30s;
deliver;
}
sub vcl_deliver {
deliver;
}
sub vcl_error {
set obj.http.Content-Type = "text/html; charset=utf-8";
synthetic {"
<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0
Strict//EN"
"http://www.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd">
<html>
<head>
<title>"} obj.status " " obj.response {"</title>
</head>
<body>
<h1>Fehler</h1>
<p>
Beim Zugriff auf <a
href="http://www.freitag.de">http://www.freitag.de</a> ist es aufgrund von
Wartungsarbeiten
zu einer Zeitüberschreitung gekommen.<br
/>
Bitte rufen Sie die Seite erneut auf oder
probieren es in ein paar Minuten wieder.
</p>
</body>
</html>
"};
deliver;
}
}}}
--
Ticket URL: <http://varnish.projects.linpro.no/ticket/489#comment:8>
Varnish <http://varnish.projects.linpro.no/>
The Varnish HTTP Accelerator
More information about the varnish-bugs
mailing list