Mailing List Archive: a problem about

a problem about _.vsl log file

Jun 19, 2008, 1:34 AM

Post #1 of 4 (822 views)

Hey guys,

I do a high load test, the test keep one hour. One hour later , varnish
works fine with restarting child process some times but don't write log
file. It don't write anything in _.vsl file after a period of time , even
these keep alive words 'Rd ping ...' ,'Wr 0 200 PONG...' . Prior to this,
it wrote about 16 M . What's wrong ?

I don't know how to get gdb information , so Not 'Include a backtrace of
the core-dump' ,sorry

The test case detail:
servers:
10.217.12.67 A siege (a opensource software), used to simulate
with the http requests
10.217.12.19 varnish server
10.210.128.199 apache server , the backend of varnish with flv files
command( run in 10.217.12.67):
siege -c 100 -i -l -f test2.url
test2.url content :

http://10.217.12.19/files/0d8549c4833a494f1f7d399fdbdcb81413845300.flv

http://10.217.12.19/files/716bccbfe6cdac7e51e117b2e0cea61d11434007.flv

http://10.217.12.19/files/0e164d6c9214fef3c62273d1dc48558013845658.flv

http://10.217.12.19/files/716bccbfe6cdac7e51e117b2e0cea61d11434005.flv

http://10.217.12.19/files/125c8370ce789702aa77724c9f5f7b8413819002.flv

http://10.217.12.19/files/716bccbfe6cdac7e51e117b2e0cea61d11434006.flv

http://10.217.12.19/files/53a01e8576a2482212879607aa8d9bc013845100.flv

http://10.217.12.19/files/716bccbfe6cdac7e51e117b2e0cea61d11434002.flv

http://10.217.12.19/files/716bccbfe6cdac7e51e117b2e0cea61d11434004.flv

http://10.217.12.19/files/716bccbfe6cdac7e51e117b2e0cea61d11434828.flv

http://10.217.12.19/files/bb4cfcd666d8c0fb3bdea04a6991d3458966027.flv

http://10.217.12.19/files/716bccbfe6cdac7e51e117b2e0cea61d11434003.flv

http://10.217.12.19/files/ee360dfee7e0937cd3771c5940cd120913845212.flv

http://10.217.12.19/files/716bccbfe6cdac7e51e117b2e0cea61d11434001.flv

The environment of varnishd
os :
FreeBSD 7.0-RELEASE , 5G Disk free , 512M

varnishd version :
trunk 2008-05-26

command:
/usr/local/sbin/varnishd -n /home/varnish/ -f /home/varnish/flv.vcl
-a 0.0.0.0:80 <http://0.0.0.0/> -s
file,/home/varnish/varnish_cache.data,500M -g varnish -u varnish -w
3000,5120,10 -T 127.0.0.1:3500 -p client_http11=on

data and log files:
%ls -l /home/varnish
total 508672
-rw-r--r-- 1 root varnish 83886744 Jun 17 03:03 _.vsl
-rw-r--r-- 1 varnish varnish 1166 May 30 17:56 flv.vcl
-rw------- 1 root varnish 524288000 Jun 19 03:02
varnish_cache.data
-rwxr-xr-x 1 root varnish 14195 Jun 16 14:44 vcl.1P9zoqAU.o

process info:
%ps auwx
root 1103 0.0 0.1 85324 312 ?? Is Mon02PM 0:00.12
varnishd: Varnish-Mgr /home/varnish/ (varnishd)
varnish 1472 0.0 54.2 620160 272956 ?? I Mon04PM 1:02.91
varnishd: Varnish-Chld /home/varnish/ (varnishd)

assert message:
tail -n 100 /var/log/messages

Jun 16 06:44:47 bsd_cxy varnishd: Child (1104) said <<Child starts>>
Jun 16 06:44:47 bsd_cxy varnishd: Child (1104) said <<managed to mmap
524288000 bytes of 524288000>>
Jun 16 06:44:47 bsd_cxy varnishd: Child (1104) said <<Ready>>
Jun 16 16:02:29 bsd_cxy kernel: pid 1104 (varnishd), uid 1002: exited on
signal 6
Jun 16 08:02:29 bsd_cxy varnishd: Child (1104) said <<Assert error in
STV_alloc(), stevedore.c line 71:>>
Jun 16 08:02:29 bsd_cxy varnishd: Child (1104) said << Condition((st) !=
NULL) not true.>>
Jun 16 08:02:29 bsd_cxy varnishd: Child (1104) said << errno = 32 (Broken
pipe)>>
Jun 16 08:02:29 bsd_cxy varnishd: Child (1403) said <<Child starts>>
Jun 16 08:02:29 bsd_cxy varnishd: Child (1403) said <<managed to mmap
524288000 bytes of 524288000>>
Jun 16 08:02:29 bsd_cxy varnishd: Child (1403) said <<Ready>>
Jun 16 16:11:02 bsd_cxy kernel: pid 1403 (varnishd), uid 1002: exited on
signal 6
Jun 16 08:11:02 bsd_cxy varnishd: Child (1403) said <<Assert error in
STV_alloc(), stevedore.c line 71:>>
Jun 16 08:11:02 bsd_cxy varnishd: Child (1403) said << Condition((st) !=
NULL) not true.>>
Jun 16 08:11:02 bsd_cxy varnishd: Child (1423) said <<Child starts>>
Jun 16 08:11:02 bsd_cxy varnishd: Child (1423) said <<managed to mmap
524288000 bytes of 524288000>>
Jun 16 08:11:02 bsd_cxy varnishd: Child (1423) said <<Ready>>
Jun 16 16:20:24 bsd_cxy kernel: pid 1423 (varnishd), uid 1002: exited on
signal 6
Jun 16 08:20:24 bsd_cxy varnishd: Child (1423) said <<Assert error in
STV_alloc(), stevedore.c line 71:>>
Jun 16 08:20:24 bsd_cxy varnishd: Child (1423) said << Condition((st) !=
NULL) not true.>>
Jun 16 08:20:24 bsd_cxy varnishd: Child (1432) said <<Child starts>>
Jun 16 08:20:24 bsd_cxy varnishd: Child (1432) said <<managed to mmap
524288000 bytes of 524288000>>
Jun 16 08:20:24 bsd_cxy varnishd: Child (1432) said <<Ready>>
Jun 16 16:33:06 bsd_cxy kernel: pid 1432 (varnishd), uid 1002: exited on
signal 6
Jun 16 08:33:06 bsd_cxy varnishd: Child (1432) said <<Assert error in
STV_alloc(), stevedore.c line 71:>>
Jun 16 08:33:06 bsd_cxy varnishd: Child (1432) said << Condition((st) !=
NULL) not true.>>
Jun 16 08:33:06 bsd_cxy varnishd: Child (1432) said << errno = 32 (Broken
pipe)>>
Jun 16 08:33:06 bsd_cxy varnishd: Child (1465) said <<Child starts>>
Jun 16 08:33:06 bsd_cxy varnishd: Child (1465) said <<managed to mmap
524288000 bytes of 524288000>>
Jun 16 08:33:06 bsd_cxy varnishd: Child (1465) said <<Ready>>
Jun 16 16:42:42 bsd_cxy kernel: pid 1465 (varnishd), uid 1002: exited on
signal 6
Jun 16 08:42:42 bsd_cxy varnishd: Child (1465) said <<Assert error in
STV_alloc(), stevedore.c line 71:>>
Jun 16 08:42:42 bsd_cxy varnishd: Child (1465) said << Condition((st) !=
NULL) not true.>>
Jun 16 08:42:42 bsd_cxy varnishd: Child (1472) said <<Child starts>>
Jun 16 08:42:42 bsd_cxy varnishd: Child (1472) said <<managed to mmap
524288000 bytes of 524288000>>
Jun 16 08:42:42 bsd_cxy varnishd: Child (1472) said <<Ready>>

flv.vcl :

%cat flv.vcl
backend host2{
.host = "10.210.128.199";
.port = "http";
}
acl local {
"localhost"; /* myself */
"10.217.12.0"/24; /* and everyone on the local network */
}

sub vcl_recv {

if (req.request == "PURGE") {
if (!client.ip ~ local) {
error 405 "Not allowed.";
}
lookup;
}

if (req.request != "GET" && req.request != "HEAD") {
pipe;
}

if (req.http.Expect) {
pipe;
}
if (req.http.Authenticate) { // was (req.http.Authenticate ||
req.http.Cookie)
pass;
}
lookup;
}

sub vcl_pipe {
pipe;
}

sub vcl_pass {
pass;
}

sub vcl_hit {
if (!obj.cacheable) {
pass;
}
deliver;
}

sub vcl_miss {
fetch;
}

sub vcl_fetch {
if (!obj.valid) {
error;
}
if (!obj.cacheable) {
pass;
}
if (obj.http.Set-Cookie) {
pass;
}
insert;
}

sub vcl_deliver {
deliver;
}

sub vcl_timeout {
discard;
}

sub vcl_discard {
discard;
}
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://projects.linpro.no/pipermail/varnish-dev/attachments/20080619/eba21ecb/attachment.htm

a problem about _.vsl log file [ In reply to ]

chenxy.china at gmail

Jun 19, 2008, 1:34 AM

Post #2 of 4 (764 views)

Permalink

a problem about _.vsl log file [ In reply to ]

phk at phk

Jun 20, 2008, 12:15 AM

Post #3 of 4 (763 views)

Permalink

In message <7ab169e90806190134p68d978b0td58480e07ae70a60 at mail.gmail.com>, "chen
xiaoyong" writes:

>I do a high load test, the test keep one hour. One hour later , varnish
>works fine with restarting child process some times but don't write log
>file. It don't write anything in _.vsl file after a period of time , even
>these keep alive words 'Rd ping ...' ,'Wr 0 200 PONG...' . Prior to this,
>it wrote about 16 M . What's wrong ?

>Jun 16 08:02:29 bsd_cxy varnishd: Child (1104) said <<Assert error in
>STV_alloc(), stevedore.c line 71:>>
>Jun 16 08:02:29 bsd_cxy varnishd: Child (1104) said << Condition((st) !=
>NULL) not true.>>

You seem to run out of storage.

--
Poul-Henning Kamp | UNIX since Zilog Zeus 3.20
phk at FreeBSD.ORG | TCP/IP since RFC 956
FreeBSD committer | BSD since 4.3-tahoe
Never attribute to malice what can adequately be explained by incompetence.