[Varnish] #835: Varnish stops receiving incoming connections, but the process is still up
Mihai Valentin
advertising at freegsm.ro
Thu Dec 16 08:15:15 CET 2010
Hi Renato,
Before it crashes, the number of TCP connections is really small. ~30
connections. It has nothing to do with the traffic volume.
On Wed, Dec 15, 2010 at 6:51 PM, Renato Farias <renato at luren.com.br> wrote:
> Hi blamer,
>
> Can you see how many connection is opened (ESTABILISHED, TIME_WAIT,
> SYN_SENT), three months ago I had same issue, my server cannot open new
> connection after 15K.
>
> Cya
>
> Renato
>
> On Wed, Dec 15, 2010 at 11:47 AM, Varnish <varnish-bugs at varnish-cache.org>wrote:
>
>> #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\<http://www.XXXXXXXX.ro/video%5C>
>> ">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
>>
>> _______________________________________________
>> varnish-bugs mailing list
>> varnish-bugs at varnish-cache.org
>> http://www.varnish-cache.org/lists/mailman/listinfo/varnish-bugs
>>
>
>
>
> --
>
> Att,
>
> Renato Farias
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-bugs/attachments/20101216/636fcbf5/attachment.html>
More information about the varnish-bugs
mailing list