[Varnish] #835: Varnish stops receiving incoming connections, but the process is still up
Varnish
varnish-bugs at varnish-cache.org
Wed Dec 15 14:47:48 CET 2010
#835: Varnish stops receiving incoming connections, but the process is still up
----------------------+-----------------------------------------------------
Reporter: blamer | Owner: phk
Type: defect | Status: new
Priority: high | Milestone: Varnish 2.1 release
Component: varnishd | Version: 2.1.4
Severity: major | Keywords: broken pipe, freeze, crash
----------------------+-----------------------------------------------------
Comment(by blamer):
System:
{{{
Linux myh0stz 2.6.26-2-sparc64-smp #1 SMP Fri Sep 17 02:49:30 UTC 2010
sparc64 GNU/Linux
32 Cores
8 GB RAM
1000 MBit
Plently of disk space (> 100 gb free)
Debian Sparc
Varnish was compiled from 2.1.4 source
}}}
Symptom: At random moments (the resources of the servers are free in those
moments), varnishd does not allow connections. It's like nothing is opened
on those sockets. It just freezes. I strace-d it (strace -p PID -f -t)
(last 500 lines):
{{{
[pid 18629] 18:18:12 clock_gettime(CLOCK_REALTIME, {1291997892,
856942092}) = 0
[pid 18629] 18:18:12 poll([{fd=14, events=POLLIN}], 1, 50 <unfinished ...>
[pid 18618] 18:18:12 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:12 write(8, "R"..., 1) = 1
[pid 18619] 18:18:12 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:12 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:12 read(7, "R"..., 1) = 1
[pid 18619] 18:18:12 clock_gettime(CLOCK_REALTIME, {1291997892,
871675208}) = 0
[pid 18619] 18:18:12 epoll_wait(10, <unfinished ...>
[pid 18629] 18:18:12 <... poll resumed> ) = 0 (Timeout)
[pid 18629] 18:18:12 ioctl(14, 0x8004667e, 0xf19d43bc) = 0
[pid 18629] 18:18:12 write(4, "\355\235 \10"..., 4) = 4
[pid 18619] 18:18:12 <... epoll_wait resumed> {{EPOLLIN, {u32=565332,
u64=2428082451382272}}}, 100, -1) = 1
[pid 18629] 18:18:12 futex(0xf19db18c, FUTEX_WAIT_PRIVATE, 25621, NULL
<unfinished ...>
[pid 18619] 18:18:12 read(3, "\355\235 \10"..., 400) = 4
[pid 18619] 18:18:12 epoll_ctl(10, EPOLL_CTL_MOD, 14,
{EPOLLIN|EPOLLPRI|EPOLLONESHOT|0x2000, {u32=3986497544,
u64=17121876577064321024}}) = 0
[pid 18619] 18:18:12 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:12 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:12 write(8, "R"..., 1) = 1
[pid 18619] 18:18:12 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:12 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:12 read(7, "R"..., 1) = 1
[pid 18619] 18:18:12 clock_gettime(CLOCK_REALTIME, {1291997892,
972535516}) = 0
[pid 18619] 18:18:12 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:13 write(8, "R"..., 1) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893, 73349872})
= 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:13 write(8, "R"..., 1) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
174123604}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18620] 18:18:13 <... poll resumed> ) = 0 (Timeout)
[pid 18620] 18:18:13 clock_gettime(CLOCK_REALTIME, <unfinished ...>
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=3998392328,
u64=17172964285337305088}}}, 100, -1) = 1
[pid 18620] 18:18:13 <... clock_gettime resumed> {1291997893, 195829832})
= 0
[pid 18619] 18:18:13 read(15, <unfinished ...>
[pid 18620] 18:18:13 poll([{fd=5, events=POLLIN}], 1, 1000 <unfinished
...>
[pid 18619] 18:18:13 <... read resumed> "GET /wp-
content/themes/XXXXXXXX/"..., 8191) = 589
[pid 18619] 18:18:13 futex(0xf7b3f18c, FUTEX_WAKE_OP_PRIVATE, 1, 1,
0xf7b3f188, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
[pid 18624] 18:18:13 <... futex resumed> ) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18624] 18:18:13 futex(0xf7a10984, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 18624] 18:18:13 ioctl(15, 0x8004667e, 0xf7b3842c) = 0
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
197972548}) = 0
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
198420916}) = 0
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
198734648}) = 0
[pid 18624] 18:18:13 writev(15, [{"HTTP/1.1"..., 8}, {" "..., 1},
{"404"..., 3}, {" "..., 1}, {"Not Found"..., 9}, {"\r\n"..., 2}, {"Server:
Microsoft-IIS/7.5"..., 25}, {"\r\n"..., 2}, {"X-Pingback:
http://www.XXXXXXXX."..., 46}, {"\r\n"..., 2}, {"Expires: Wed, 11 Jan 1984
05:00:0"..., 38}, {"\r\n"..., 2}, {"Last-Modified: Fri, 10 Dec 2010 1"...,
44}, {"\r\n"..., 2}, {"Cache-Control: no-cache, must-rev"..., 51},
{"\r\n"..., 2}, {"Pragma: no-cache"..., 16}, {"\r\n"..., 2}, {"Vary:
Accept-Encoding"..., 21}, {"\r\n"..., 2}, {"Content-Encoding: gzip"...,
22}, {"\r\n"..., 2}, {"Content-Type: text/html; charset="..., 38},
{"\r\n"..., 2}, {"Content-Length: 17208"..., 21}, {"\r\n"..., 2}, {"Date:
Fri, 10 Dec 2010 16:18:13 G"..., 35}, {"\r\n"..., 2}, {"X-Varnish:
1052092382 1052083617"..., 32}, {"\r\n"..., 2}, {"Age: 1073"..., 9},
{"\r\n"..., 2}, ...], 38) = 17700
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
200894048}) = 0
[pid 18624] 18:18:13 poll([{fd=15, events=POLLIN}], 1, 50 <unfinished ...>
[pid 18612] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18612] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
240571564}) = 0
[pid 18612] 18:18:13 nanosleep({1, 0}, <unfinished ...>
[pid 18617] 18:18:13 <... nanosleep resumed> {1, 0}) = 0
[pid 18617] 18:18:13 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 18617] 18:18:13 rt_sigaction(SIGCHLD, NULL, {0xf7f30798, [],
SA_NOCLDSTOP}, 0, 4033866460) = 0
[pid 18617] 18:18:13 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 18617] 18:18:13 nanosleep({1, 0}, <unfinished ...>
[pid 18615] 18:18:13 <... nanosleep resumed> {1, 0}) = 0
[pid 18615] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
250373144}) = 0
[pid 18615] 18:18:13 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 18615] 18:18:13 rt_sigaction(SIGCHLD, NULL, {0xf7f30798, [],
SA_NOCLDSTOP}, 0, 4050643676) = 0
[pid 18615] 18:18:13 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 18615] 18:18:13 nanosleep({1, 0}, <unfinished ...>
[pid 18624] 18:18:13 <... poll resumed> ) = 0 (Timeout)
[pid 18624] 18:18:13 ioctl(15, 0x8004667e, 0xf7b383bc) = 0
[pid 18624] 18:18:13 write(4, "\356R\240\10"..., 4 <unfinished ...>
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=565332,
u64=2428082451382272}}}, 100, -1) = 1
[pid 18624] 18:18:13 <... write resumed> ) = 4
[pid 18619] 18:18:13 read(3, <unfinished ...>
[pid 18624] 18:18:13 futex(0xf7b3f18c, FUTEX_WAIT_PRIVATE, 25917, NULL
<unfinished ...>
[pid 18619] 18:18:13 <... read resumed> "\356R\240\10"..., 400) = 4
[pid 18619] 18:18:13 epoll_ctl(10, EPOLL_CTL_MOD, 15,
{EPOLLIN|EPOLLPRI|EPOLLONESHOT|0x2000, {u32=3998392328,
u64=17172964285337305088}}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:13 write(8, "R"..., 1) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
274913284}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:13 write(8, "R"..., 1) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
375723208}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18625] 18:18:13 <... read resumed> "1"..., 1) = 1
[pid 18625] 18:18:13 read(11, "0"..., 1) = 1
[pid 18625] 18:18:13 read(11, "6"..., 1) = 1
[pid 18625] 18:18:13 read(11, "f"..., 1) = 1
[pid 18625] 18:18:13 read(11, "\r"..., 1) = 1
[pid 18625] 18:18:13 read(11, "\n"..., 1) = 1
[pid 18625] 18:18:13 read(11, "http://www.XXXXXXXX.ro/video\">Vi"...,
4207) = 4207
[pid 18625] 18:18:13 read(11, "\r"..., 1) = 1
[pid 18625] 18:18:13 read(11, "\n"..., 1) = 1
[pid 18625] 18:18:13 read(11, <unfinished ...>
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=3986497544,
u64=17121876577064321024}}}, 100, -1) = 1
[pid 18619] 18:18:13 read(14, "GET /img/wp-content/uploads/2010/"...,
8191) = 703
[pid 18619] 18:18:13 futex(0xf19db18c, FUTEX_WAKE_OP_PRIVATE, 1, 1,
0xf19db188, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
[pid 18629] 18:18:13 <... futex resumed> ) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18629] 18:18:13 futex(0xf7a109b4, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 18629] 18:18:13 ioctl(14, 0x8004667e, 0xf19d442c) = 0
[pid 18629] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
471524104}) = 0
[pid 18629] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
472037492}) = 0
[pid 18629] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
472340392}) = 0
[pid 18629] 18:18:13 writev(14, [{"HTTP/1.1"..., 8}, {" "..., 1},
{"200"..., 3}, {" "..., 1}, {"OK"..., 2}, {"\r\n"..., 2}, {"Server:
Microsoft-IIS/7.5"..., 25}, {"\r\n"..., 2}, {"Content-Disposition: inline;
file"..., 71}, {"\r\n"..., 2}, {"Last-Modified: Fri, 10 Dec 2010 1"...,
44}, {"\r\n"..., 2}, {"Content-Type: image/jpeg"..., 24}, {"\r\n"..., 2},
{"Content-Length: 34330"..., 21}, {"\r\n"..., 2}, {"Date: Fri, 10 Dec 2010
16:18:13 G"..., 35}, {"\r\n"..., 2}, {"X-Varnish: 1052092383
1052054539"..., 32}, {"\r\n"..., 2}, {"Age: 4457"..., 9}, {"\r\n"..., 2},
{"Via: 1.1 varnish"..., 16}, {"\r\n"..., 2}, {"Connection: keep-alive"...,
22}, {"\r\n"..., 2}, {"\r\n"..., 2},
{"\377\330\377\340\0\20JFIF\0\1\1\1\0\226\0\226\0\0\377\333\0C\0\10\6\6\7\6\5\10\7"...,
34330}], 28) = 34668
[pid 18629] 18:18:13 clock_gettime(CLOCK_REALTIME, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18629] 18:18:13 <... clock_gettime resumed> {1291997893, 475416560})
= 0
[pid 18618] 18:18:13 write(8, "R"..., 1 <unfinished ...>
[pid 18629] 18:18:13 poll([{fd=14, events=POLLIN}], 1, 50 <unfinished ...>
[pid 18618] 18:18:13 <... write resumed> ) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
476985560}) = 0
[pid 18619] 18:18:13 epoll_wait(10, {{EPOLLIN, {u32=3998392328,
u64=17172964285337305088}}}, 100, -1) = 1
[pid 18619] 18:18:13 read(15, "HEAD / HTTP/1.1\r\nX-Forwarded-For:"...,
8191) = 102
[pid 18619] 18:18:13 futex(0xf7b3f18c, FUTEX_WAKE_OP_PRIVATE, 1, 1,
0xf7b3f188, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
[pid 18624] 18:18:13 <... futex resumed> ) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18624] 18:18:13 futex(0xf7a10984, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 18624] 18:18:13 ioctl(15, 0x8004667e, 0xf7b3842c) = 0
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
495145448}) = 0
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
495574520}) = 0
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
495897344}) = 0
[pid 18624] 18:18:13 writev(15, [{"HTTP/1.1"..., 8}, {" "..., 1},
{"200"..., 3}, {" "..., 1}, {"OK"..., 2}, {"\r\n"..., 2}, {"Server:
Microsoft-IIS/7.5"..., 25}, {"\r\n"..., 2}, {"Last-Modified: Tue, 03 Aug
2010 0"..., 44}, {"\r\n"..., 2}, {"ETag: \"40125-0-48ce652c74380\""...,
29}, {"\r\n"..., 2}, {"Vary: Accept-Encoding"..., 21}, {"\r\n"..., 2},
{"Content-Type: text/html"..., 23}, {"\r\n"..., 2}, {"Content-Length:
0"..., 17}, {"\r\n"..., 2}, {"Date: Fri, 10 Dec 2010 16:18:13 G"..., 35},
{"\r\n"..., 2}, {"X-Varnish: 1052092384 1052090630"..., 32}, {"\r\n"...,
2}, {"Age: 236"..., 8}, {"\r\n"..., 2}, {"Via: 1.1 varnish"..., 16},
{"\r\n"..., 2}, {"Connection: keep-alive"..., 22}, {"\r\n"..., 2},
{"\r\n"..., 2}], 29) = 313
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
497661528}) = 0
[pid 18624] 18:18:13 poll([{fd=15, events=POLLIN}], 1, 50 <unfinished ...>
[pid 18629] 18:18:13 <... poll resumed> ) = 0 (Timeout)
[pid 18629] 18:18:13 ioctl(14, 0x8004667e, 0xf19d43bc) = 0
[pid 18629] 18:18:13 write(4, "\355\235 \10"..., 4) = 4
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=565332,
u64=2428082451382272}}}, 100, -1) = 1
[pid 18629] 18:18:13 futex(0xf19db18c, FUTEX_WAIT_PRIVATE, 25623, NULL
<unfinished ...>
[pid 18619] 18:18:13 read(3, "\355\235 \10"..., 400) = 4
[pid 18619] 18:18:13 epoll_ctl(10, EPOLL_CTL_MOD, 14,
{EPOLLIN|EPOLLPRI|EPOLLONESHOT|0x2000, {u32=3986497544,
u64=17121876577064321024}}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18624] 18:18:13 <... poll resumed> ) = 0 (Timeout)
[pid 18624] 18:18:13 ioctl(15, 0x8004667e, 0xf7b383bc) = 0
[pid 18624] 18:18:13 write(4, "\356R\240\10"..., 4 <unfinished ...>
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=565332,
u64=2428082451382272}}}, 100, -1) = 1
[pid 18624] 18:18:13 <... write resumed> ) = 4
[pid 18619] 18:18:13 read(3, <unfinished ...>
[pid 18624] 18:18:13 futex(0xf7b3f18c, FUTEX_WAIT_PRIVATE, 25919, NULL
<unfinished ...>
[pid 18619] 18:18:13 <... read resumed> "\356R\240\10"..., 400) = 4
[pid 18619] 18:18:13 epoll_ctl(10, EPOLL_CTL_MOD, 15,
{EPOLLIN|EPOLLPRI|EPOLLONESHOT|0x2000, {u32=3998392328,
u64=17172964285337305088}}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:13 write(8, "R"..., 1) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
577819076}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:13 write(8, "R"..., 1) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
678596784}) = 0
[pid 18619] 18:18:13 epoll_wait(10, {{EPOLLIN, {u32=3986497544,
u64=17121876577064321024}}}, 100, -1) = 1
[pid 18619] 18:18:13 read(14, "GET /stiri HTTP/1.1\r\nUser-Agent: "...,
8191) = 773
[pid 18619] 18:18:13 futex(0xf19db18c, FUTEX_WAKE_OP_PRIVATE, 1, 1,
0xf19db188, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
[pid 18629] 18:18:13 <... futex resumed> ) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18629] 18:18:13 futex(0xf7a109b4, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 18629] 18:18:13 ioctl(14, 0x8004667e, 0xf19d442c) = 0
[pid 18629] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
738793608}) = 0
[pid 18629] 18:18:13 futex(0xf19db18c, FUTEX_WAIT_PRIVATE, 25625, NULL
<unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:13 write(8, "R"..., 1) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
779390960}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:13 write(8, "R"..., 1) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, "R"..., 1) = 1
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
880271512}) = 0
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:13 <... nanosleep resumed> NULL) = 0
[pid 18620] 18:18:13 <... poll resumed> ) = 1 ([{fd=5, revents=POLLIN}])
[pid 18618] 18:18:13 write(8, "R"..., 1 <unfinished ...>
[pid 18620] 18:18:13 clock_gettime(CLOCK_REALTIME, <unfinished ...>
[pid 18618] 18:18:13 <... write resumed> ) = 1
[pid 18619] 18:18:13 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:13 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:13 read(7, <unfinished ...>
[pid 18620] 18:18:13 <... clock_gettime resumed> {1291997893, 980448784})
= 0
[pid 18619] 18:18:13 <... read resumed> "R"..., 1) = 1
[pid 18620] 18:18:13 accept(5, <unfinished ...>
[pid 18619] 18:18:13 clock_gettime(CLOCK_REALTIME, <unfinished ...>
[pid 18620] 18:18:13 <... accept resumed> {sa_family=AF_INET,
sin_port=htons(50619), sin_addr=inet_addr("x.y.z.36")}, [16]) = 17
[pid 18619] 18:18:13 <... clock_gettime resumed> {1291997893, 981728996})
= 0
[pid 18620] 18:18:13 futex(0xf7b3f18c, FUTEX_WAKE_OP_PRIVATE, 1, 1,
0xf7b3f188, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid 18619] 18:18:13 epoll_wait(10, <unfinished ...>
[pid 18620] 18:18:13 <... futex resumed> ) = 1
[pid 18624] 18:18:13 <... futex resumed> ) = 0
[pid 18620] 18:18:13 poll([{fd=5, events=POLLIN}], 1, 1000 <unfinished
...>
[pid 18624] 18:18:13 futex(0xf7a10984, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 18624] 18:18:13 ioctl(17, 0x8004667e, 0xf7b3842c) = 0
[pid 18624] 18:18:13 poll([{fd=17, events=POLLIN}], 1, 50) = 1 ([{fd=17,
revents=POLLIN}])
[pid 18624] 18:18:13 read(17, "GET /wp-content/themes/XXXXXXXX/"..., 8191)
= 427
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
984534164}) = 0
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
984991888}) = 0
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
985292996}) = 0
[pid 18624] 18:18:13 writev(17, [{"HTTP/1.1"..., 8}, {" "..., 1},
{"200"..., 3}, {" "..., 1}, {"OK"..., 2}, {"\r\n"..., 2}, {"Server:
Microsoft-IIS/7.5"..., 25}, {"\r\n"..., 2}, {"Last-Modified: Tue, 16 Feb
2010 0"..., 44}, {"\r\n"..., 2}, {"ETag: \"46853-65c-47fb4c59bb740\""...,
31}, {"\r\n"..., 2}, {"Content-Type: image/gif"..., 23}, {"\r\n"..., 2},
{"Content-Length: 1628"..., 20}, {"\r\n"..., 2}, {"Date: Fri, 10 Dec 2010
16:18:13 G"..., 35}, {"\r\n"..., 2}, {"X-Varnish: 1052092386
1052083384"..., 32}, {"\r\n"..., 2}, {"Age: 1100"..., 9}, {"\r\n"..., 2},
{"Via: 1.1 varnish"..., 16}, {"\r\n"..., 2}, {"Connection: keep-alive"...,
22}, {"\r\n"..., 2}, {"\r\n"..., 2},
{"GIF89a\34\0$\0\367\0\0\"\37\210w\344\363\235\237\314\36\271\336XZ\250\0\215\303\307\361"...,
1628}], 28) = 1924
[pid 18624] 18:18:13 clock_gettime(CLOCK_REALTIME, {1291997893,
987145288}) = 0
[pid 18624] 18:18:13 poll([{fd=17, events=POLLIN}], 1, 50) = 0 (Timeout)
[pid 18624] 18:18:14 ioctl(17, 0x8004667e, 0xf7b383bc) = 0
[pid 18624] 18:18:14 write(4, "\367\244\200\10"..., 4 <unfinished ...>
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=565332,
u64=2428082451382272}}}, 100, -1) = 1
[pid 18624] 18:18:14 <... write resumed> ) = 4
[pid 18619] 18:18:14 read(3, <unfinished ...>
[pid 18624] 18:18:14 futex(0xf7b3f18c, FUTEX_WAIT_PRIVATE, 25921, NULL
<unfinished ...>
[pid 18619] 18:18:14 <... read resumed> "\367\244\200\10"..., 400) = 4
[pid 18619] 18:18:14 epoll_ctl(10, EPOLL_CTL_ADD, 17,
{EPOLLIN|EPOLLPRI|EPOLLONESHOT|0x2000, {u32=4154753032,
u64=17844528395396841472}}) = 0
[pid 18619] 18:18:14 epoll_wait(10, {{EPOLLIN, {u32=4154753032,
u64=17844528395396841472}}}, 100, -1) = 1
[pid 18619] 18:18:14 read(17, "GET /stiri HTTP/1.1\r\nUser-Agent: "...,
8191) = 773
[pid 18619] 18:18:14 futex(0xf19db18c, FUTEX_WAKE_OP_PRIVATE, 1, 1,
0xf19db188, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
[pid 18629] 18:18:14 <... futex resumed> ) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18629] 18:18:14 futex(0xf7a109b4, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 18629] 18:18:14 ioctl(17, 0x8004667e, 0xf19d442c) = 0
[pid 18629] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894, 47222624})
= 0
[pid 18629] 18:18:14 futex(0xf19db18c, FUTEX_WAIT_PRIVATE, 25627, NULL
<unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894, 82163424})
= 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
183055080}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18612] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18612] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
241243672}) = 0
[pid 18612] 18:18:14 nanosleep({1, 0}, <unfinished ...>
[pid 18617] 18:18:14 <... nanosleep resumed> {1, 0}) = 0
[pid 18617] 18:18:14 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 18617] 18:18:14 rt_sigaction(SIGCHLD, NULL, {0xf7f30798, [],
SA_NOCLDSTOP}, 0, 4033866460) = 0
[pid 18617] 18:18:14 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 18617] 18:18:14 nanosleep({1, 0}, <unfinished ...>
[pid 18615] 18:18:14 <... nanosleep resumed> {1, 0}) = 0
[pid 18615] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
252058036}) = 0
[pid 18615] 18:18:14 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 18615] 18:18:14 rt_sigaction(SIGCHLD, NULL, {0xf7f30798, [],
SA_NOCLDSTOP}, 0, 4050643676) = 0
[pid 18615] 18:18:14 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 18615] 18:18:14 nanosleep({1, 0}, <unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
283774800}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
384582084}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18620] 18:18:14 <... poll resumed> ) = 1 ([{fd=5, revents=POLLIN}])
[pid 18620] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
419035140}) = 0
[pid 18620] 18:18:14 accept(5, {sa_family=AF_INET, sin_port=htons(50630),
sin_addr=inet_addr("x.y.z.36")}, [16]) = 18
[pid 18620] 18:18:14 futex(0xf7b3f18c, FUTEX_WAKE_OP_PRIVATE, 1, 1,
0xf7b3f188, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
[pid 18624] 18:18:14 <... futex resumed> ) = 0
[pid 18620] 18:18:14 poll([{fd=5, events=POLLIN}], 1, 1000 <unfinished
...>
[pid 18624] 18:18:14 futex(0xf7a10984, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 18624] 18:18:14 ioctl(18, 0x8004667e, 0xf7b3842c) = 0
[pid 18624] 18:18:14 poll([{fd=18, events=POLLIN}], 1, 50) = 1 ([{fd=18,
revents=POLLIN}])
[pid 18624] 18:18:14 read(18, "GET /stiri HTTP/1.1\r\nUser-Agent: "...,
8191) = 773
[pid 18624] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
421629696}) = 0
[pid 18624] 18:18:14 futex(0xf7b3f18c, FUTEX_WAIT_PRIVATE, 25923, NULL
<unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
485429080}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
586203652}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
687050580}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
787847056}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
888672272}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:14 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:14 write(8, "R"..., 1) = 1
[pid 18619] 18:18:14 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:14 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:14 read(7, "R"..., 1) = 1
[pid 18619] 18:18:14 clock_gettime(CLOCK_REALTIME, {1291997894,
989458320}) = 0
[pid 18619] 18:18:14 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895, 90264196})
= 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18611] 18:18:15 <... poll resumed> ) = 1 ([{fd=6, revents=POLLIN}])
[pid 18611] 18:18:15 read(6, "ping\n"..., 8191) = 5
[pid 18611] 18:18:15 time(NULL) = 1291997895
[pid 18611] 18:18:15 writev(9, [{"200 19 \n"..., 13}, {"PONG
1291997895 1.0"..., 19}, {"\n"..., 1}], 3) = 33
[pid 18611] 18:18:15 poll([{fd=6, events=POLLIN}], 1, -1 <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
191048264}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18612] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18612] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
241947668}) = 0
[pid 18612] 18:18:15 nanosleep({1, 0}, <unfinished ...>
[pid 18617] 18:18:15 <... nanosleep resumed> {1, 0}) = 0
[pid 18617] 18:18:15 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 18617] 18:18:15 rt_sigaction(SIGCHLD, NULL, {0xf7f30798, [],
SA_NOCLDSTOP}, 0, 4033866460) = 0
[pid 18617] 18:18:15 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 18617] 18:18:15 nanosleep({1, 0}, <unfinished ...>
[pid 18615] 18:18:15 <... nanosleep resumed> {1, 0}) = 0
[pid 18615] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
253632384}) = 0
[pid 18615] 18:18:15 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 18615] 18:18:15 rt_sigaction(SIGCHLD, NULL, {0xf7f30798, [],
SA_NOCLDSTOP}, 0, 4050643676) = 0
[pid 18615] 18:18:15 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 18615] 18:18:15 nanosleep({1, 0}, <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
291949320}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
392767872}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18620] 18:18:15 <... poll resumed> ) = 0 (Timeout)
[pid 18620] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
423866840}) = 0
[pid 18620] 18:18:15 poll([{fd=5, events=POLLIN}], 1, 1000 <unfinished
...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
493554528}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
594343716}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
695131520}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
795928848}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
896786468}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:15 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:15 write(8, "R"..., 1) = 1
[pid 18619] 18:18:15 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:15 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:15 read(7, "R"..., 1) = 1
[pid 18619] 18:18:15 clock_gettime(CLOCK_REALTIME, {1291997895,
997543276}) = 0
[pid 18619] 18:18:15 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:16 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:16 write(8, "R"..., 1) = 1
[pid 18619] 18:18:16 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:16 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:16 read(7, "R"..., 1) = 1
[pid 18619] 18:18:16 clock_gettime(CLOCK_REALTIME, {1291997896, 98361332})
= 0
[pid 18619] 18:18:16 epoll_wait(10, <unfinished ...>
[pid 18618] 18:18:16 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:16 write(8, "R"..., 1) = 1
[pid 18619] 18:18:16 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:16 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:16 read(7, "R"..., 1) = 1
[pid 18619] 18:18:16 clock_gettime(CLOCK_REALTIME, {1291997896,
199182492}) = 0
[pid 18619] 18:18:16 epoll_wait(10, <unfinished ...>
[pid 18612] 18:18:16 <... nanosleep resumed> NULL) = 0
[pid 18612] 18:18:16 clock_gettime(CLOCK_REALTIME, {1291997896,
242623312}) = 0
[pid 18612] 18:18:16 nanosleep({1, 0}, <unfinished ...>
[pid 18617] 18:18:16 <... nanosleep resumed> {1, 0}) = 0
[pid 18617] 18:18:16 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 18617] 18:18:16 rt_sigaction(SIGCHLD, NULL, {0xf7f30798, [],
SA_NOCLDSTOP}, 0, 4033866460) = 0
[pid 18617] 18:18:16 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 18617] 18:18:16 nanosleep({1, 0}, <unfinished ...>
[pid 18615] 18:18:16 <... nanosleep resumed> {1, 0}) = 0
[pid 18615] 18:18:16 clock_gettime(CLOCK_REALTIME, {1291997896,
255275216}) = 0
[pid 18615] 18:18:16 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 18615] 18:18:16 rt_sigaction(SIGCHLD, NULL, {0xf7f30798, [],
SA_NOCLDSTOP}, 0, 4050643676) = 0
[pid 18615] 18:18:16 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 18615] 18:18:16 nanosleep({1, 0}, <unfinished ...>
[pid 18618] 18:18:16 <... nanosleep resumed> NULL) = 0
[pid 18618] 18:18:16 write(8, "R"..., 1) = 1
[pid 18619] 18:18:16 <... epoll_wait resumed> {{EPOLLIN, {u32=570960,
u64=2452254527324160}}}, 100, -1) = 1
[pid 18618] 18:18:16 nanosleep({0, 100000000}, <unfinished ...>
[pid 18619] 18:18:16 read(7, "R"..., 1) = 1
[pid 18619] 18:18:16 clock_gettime(CLOCK_REALTIME, {1291997896,
299975276}) = 0
[pid 18619] 18:18:16 epoll_wait(10, <unfinished ...>
[pid 18620] 18:18:16 <... poll resumed> ) = 1 ([{fd=5, revents=POLLIN}])
[pid 18620] 18:18:16 clock_gettime(CLOCK_REALTIME, {1291997896,
315826092}) = 0
[pid 18620] 18:18:16 accept(5, {sa_family=AF_INET, sin_port=htons(42033),
sin_addr=inet_addr("x.y.z.86")}, [16]) = 19
[pid 18620] 18:18:16 futex(0xf19db18c, FUTEX_WAKE_OP_PRIVATE, 1, 1,
0xf19db188, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
[pid 18629] 18:18:16 <... futex resumed> ) = 0
[pid 18620] 18:18:16 poll([{fd=5, events=POLLIN}], 1, 1000 <unfinished
...>
[pid 18629] 18:18:16 futex(0xf7a109b4, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 18629] 18:18:16 ioctl(19, 0x8004667e, 0xf19d442c) = 0
[pid 18629] 18:18:16 poll([{fd=19, events=POLLIN}], 1, 50) = 1 ([{fd=19,
revents=POLLIN}])
[pid 18629] 18:18:16 read(19, "GET / HTTP/1.1\r\nHost: www.Xspo"..., 8191)
= 99
[pid 18629] 18:18:16 clock_gettime(CLOCK_REALTIME, {1291997896,
318403888}) = 0
[pid 18629] 18:18:16 futex(0xf19db18c, FUTEX_WAIT_PRIVATE, 25629, NULL
<unfinished ...>
[pid 18611] 18:18:16 <... poll resumed> ) = 1 ([{fd=6, revents=POLLHUP}])
[pid 18611] 18:18:16 close(6) = 0
[pid 18611] 18:18:16 close(9) = 0
[pid 18611] 18:18:16 close(5) = 0
[pid 18611] 18:18:16 write(1, "Child dies"..., 10) = -1 EPIPE (Broken
pipe)
[pid 18611] 18:18:16 --- SIGPIPE (Broken pipe) @ 0 (0) ---
[pid 18611] 18:18:16 exit_group(1) = ?
Process 18611 detached
[pid 18612] 18:18:16 <... nanosleep resumed> 0) = ? ERESTART_RESTARTBLOCK
(To be restarted)
[pid 18614] 18:18:16 <... futex resumed> ) = ? ERESTARTSYS (To be
restarted)
[pid 18615] 18:18:16 <... nanosleep resumed> 0xf16fec68) = ?
ERESTART_RESTARTBLOCK (To be restarted)
[pid 18616] 18:18:16 <... nanosleep resumed> 0) = ? ERESTART_RESTARTBLOCK
(To be restarted)
[pid 18617] 18:18:16 <... nanosleep resumed> 0xf06fec68) = ?
ERESTART_RESTARTBLOCK (To be restarted)
[pid 18618] 18:18:16 <... nanosleep resumed> 0) = ? ERESTART_RESTARTBLOCK
(To be restarted)
[pid 18619] 18:18:16 <... epoll_wait resumed> ef6feb20, 100, -1) = -1
EINTR (Interrupted system call)
[pid 18620] 18:18:16 <... poll resumed> ) = 1 ([{fd=5, revents=POLLNVAL}])
[pid 18622] 18:18:16 <... read resumed> 0xf7b59108, 8191) = -1 EINTR
(Interrupted system call)
[pid 18623] 18:18:16 <... futex resumed> ) = ? ERESTARTSYS (To be
restarted)
[pid 18624] 18:18:16 <... futex resumed> ) = ? ERESTARTSYS (To be
restarted)
[pid 18625] 18:18:16 <... read resumed> 0xf7b2839a, 1) = -1 EINTR
(Interrupted system call)
[pid 18626] 18:18:16 <... futex resumed> ) = ? ERESTARTSYS (To be
restarted)
[pid 18627] 18:18:16 <... futex resumed> ) = ? ERESTARTSYS (To be
restarted)
[pid 18628] 18:18:16 <... futex resumed> ) = ? ERESTARTSYS (To be
restarted)
[pid 18629] 18:18:16 <... futex resumed> ) = ? ERESTARTSYS (To be
restarted)
[pid 18630] 18:18:16 <... futex resumed> ) = ? ERESTARTSYS (To be
restarted)
Process 18611 detached
Process 18984 detached
}}}
All I can see is the SIGPIPE and the ERESTARTSYS (those two things do not
appear until the freeze).
Varnish default conf: -f /srv/varnish/conf/XXXXXXXX.vcl -s malloc,1024M -a
0.0.0.0:8080
VCL:
{{{
backend default {
.host = "XX.YY.ZZ.WW";
.port = "80";
}
sub vcl_recv {
if (req.url ~ "cgi-bin") {
return (pipe);
}
if (req.http.Accept-Encoding) {
if (req.http.Accept-Encoding ~ "gzip") {
set req.http.Accept-Encoding = "gzip";
} elsif (req.http.Accept-Encoding ~ "deflate") {
set req.http.Accept-Encoding = "deflate";
} else {
# unkown algorithm
remove req.http.Accept-Encoding;
}
}
if (req.http.Accept-Language) {
remove req.http.Accept-Language;
}
if (req.http.User-Agent) {
remove req.http.User-Agent;
}
if (req.http.Host ~ "live.XXXXXXXX.ro" || req.http.Host ~
"live2.XXXXXXXX.ro") {
return (pipe);
}
if (req.request != "GET" && req.request != "HEAD") {
return (pass);
}
if (req.url ~ "\.(png|gif|jpg|swf)" || req.url ~ "/img/" || req.url ~
"\.(js|css)") {
remove req.http.cookie;
return (lookup);
}
if (
!(req.url ~ "wp-(login|admin)") &&
!(req.http.Cookie ~ "wordpress_logged_in")
) {
remove req.http.cookie;
return (lookup);
} else {
return (pass);
}
if (req.http.Cookie ~ "wordpress_logged_in") {
return (pass);
} else {
return (lookup);
}
}
sub vcl_fetch {
if (req.http.Host ~ "live.XXXXXXX.ro" || req.http.Host ~
"live2.XXXXXXXX.ro") {
return(pass);
}
if (beresp.http.Content-Type ~ "text/html") {
//set beresp.http.Cache-Control = "no-store, no-cache,
must-revalidate, post-check=0, pre-check=0";
//set beresp.http.Pragma = "no-cache";
}
if (!(req.url ~ "wp-(login|admin)")) {
#remove beresp.http.set-cookie;
}
if (req.url ~ "\.(png|gif|jpg|swf)" || req.url ~ "/img/" ||
beresp.http.Content-Type ~ "javascript" || beresp.http.Content-Type ~
"css") {
remove beresp.http.set-cookie;
//log "request-ul se preteaza: " beresp.http.Content-Type;
set beresp.ttl = 7200s;
return (deliver);
} else {
set beresp.ttl = 240s;
}
}
}}}
I cannot link any request to the crash event.
--
Ticket URL: <http://www.varnish-cache.org/trac/ticket/835#comment:1>
Varnish <http://varnish-cache.org/>
The Varnish HTTP Accelerator
More information about the varnish-bugs
mailing list