[Varnish] #835: Varnish stops receiving incoming connections, but the process is still up
Renato Farias
renato at luren.com.br
Wed Dec 15 17:51:15 CET 2010
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/20101215/5c62184b/attachment.html>
More information about the varnish-bugs
mailing list