|
Home > Archive > Perlbal > September 2006 > Perlbal reproxied downloads stalling
You are viewing an archived Text-only version of the thread.
To view this thread in it's original format and/or if you want to reply to
this thread please [click here]
| Author |
Perlbal reproxied downloads stalling
|
|
|
| Hi all,
I have perlbal installed on a Centos 4.4 x64 dual Opteron server w/ 4GB
RAM, and am reproxying from a webserver to read files from a clustered
storage backend running Apache/DAV. When I do a reproxied download, things
seem to go well until a few megabytes into the file; then, the download
seems to slow down sharply then hang. It will happen at different parts of
the file, but the speed always starts out strong (500kb/s to 2mb/s,
depending on the connection I'm downloading from) but after 10 seconds or
so comes to a halt. Sometimes it'll slow way down, speed back up, but then
slow down again, finally hanging. This happens for virtually any large
file.
I've tried both 'ioaio' and 'none' for the aio_mode parameter (Linux::IO
won't pass tests), but same thing happens in both cases. I can pull from
the storage to the perlbal machine no problem with HTTP wget, at about 30
MB/s uninterrupted. As the reeproxied download happens, perlbal CPU usage
never goes above 1%. I have the default buffer settings; have tried
tweaking a little but to no avail.
Anyone have any ideas why this might be happening?
--
Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
| |
| Brad Fitzpatrick 2006-09-08, 1:12 pm |
| Hm. Can you get an strace on the main Perlbal process while this is
happening?
$ strace -s 500 -o perlbal.trace -p <pid-of-perlbal>
....... (wait)
^C
On Fri, 8 Sep 2006, Sam G wrote:
> Hi all,
>
> I have perlbal installed on a Centos 4.4 x64 dual Opteron server w/ 4GB
> RAM, and am reproxying from a webserver to read files from a clustered
> storage backend running Apache/DAV. When I do a reproxied download, things
> seem to go well until a few megabytes into the file; then, the download
> seems to slow down sharply then hang. It will happen at different parts of
> the file, but the speed always starts out strong (500kb/s to 2mb/s,
> depending on the connection I'm downloading from) but after 10 seconds or
> so comes to a halt. Sometimes it'll slow way down, speed back up, but then
> slow down again, finally hanging. This happens for virtually any large
> file.
>
> I've tried both 'ioaio' and 'none' for the aio_mode parameter (Linux::IO
> won't pass tests), but same thing happens in both cases. I can pull from
> the storage to the perlbal machine no problem with HTTP wget, at about 30
> MB/s uninterrupted. As the reeproxied download happens, perlbal CPU usage
> never goes above 1%. I have the default buffer settings; have tried
> tweaking a little but to no avail.
>
> Anyone have any ideas why this might be happening?
>
> --
> Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
>
>
| |
|
| This seems to be the bulk of what's happening:
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
<lots of large chunks of text scrolling by as file downloads...>
.....
<snip>
.....
epoll_ctl(5, EPOLL_CTL_MOD, 9, & #123;EPOLLIN|EPOLLOUT|EPOLLERR|EPOLLHUP|
0x20,=
=
{u32=3D9, u64=3D9}}) =3D 0
time(NULL) =3D 1157770135
gettimeofday({1157770135, 330342}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D12, u64=3D12}}}, 1000, 1000) =3D 1
read(12, =
"\2100)\"\33\31\207\244\241\0254\210v\360W{\321$\221\331^\302\237\22480\=
33\257\35\2220\25\337f\17#e\7%\253\23\33
0\21\356\321\250fd\204\241%\372h=
D\374h\214\225\16\232w\322@O\16m_!\375\2
37w)\20\n\256YF\353B\10|\231j7\2=
3
1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\30=
1\37V\307\371\216\354\234k =
\223\247\333\316'\f\235\226h< \344\344uD\25\251\253\4\364*\361\215\264
\2=
34\377\202\222\27\262\6\257\223J\6\313\3
44\300\331\222\
243\304U\211\304\257\206vO\341\322\307\3
46\307\270I\300\362\330>xH\267\3=
2+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\215d\3=
5\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
237,J\=
251\210/Ud
g\377\231`KZ\34\342\302'\320\240T\177\3
21\304\7\320*\241T)\326\256I\264=
\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277\6\2=
25\\\f\226\247\3!qi\341`\323\rV\251.`w\26\27\17 =
`\247\346 \232\257\356/b\205\223'
?\366\nz\242L\304\261\255\223\276-\231\361\371\314\31\303\303\367 =
{\24ha(\374\34\315\365\270\212"..., 61449) =3D 61449
time(NULL) =3D 1157770135
gettimeofday({1157770135, 330707}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D12, u64=3D12}}}, 1000, 1000) =3D 1
epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLERR|EPOLLHUP|0x20, {u32=3D12, =
u64=3D12}}) =3D 0
time(NULL) =3D 1157770135
gettimeofday({1157770135, 330867}, NULL) =3D 0
epoll_wait(5, {{EPOLLOUT, {u32=3D9, u64=3D9}}}, 1000, 1000) =3D 1
time(NULL) =3D 1157770135
write(9, =
" Q\344\7\330,\301\355!k\3278\31:\256\371\
264<\330\352\310j\225\30\325\31=
0\361\360D\353\353w\344L\3\341*\345\227\
3460\204\354\23Q\332\316-O\301\3=
50\270w\206t\235v\365\300r;\367\377\220s
\244\311\302\226\372\0\357\3025\=
3
60\266\336\341\0\377%O\3324\213\364\344\
201D\232si\5\301JS?\341|o\250\27=
4\377\240F\364\32\250$\24\372\315\325q\2
33_\350at\324\363\320\343qG\32\2=
21\345\f\272\324\t\2524\\\232]^\301\241\
220\212\241R\372\3240\360*A\3709=
}\203@\22\
313\n(_\200H\263\335\243\261\342Q\33\16\
264\243_\230\372A:g*Y\331\324\32=
5F\326N\27,~\200\235\306_\222@\301\246\2
66\r\374\202\216\311A\2mb\3\213+=
r\201\22K\323\374'\277\5l\353\10\355+<~\35\\\272\320\277\323\34\37\345\=
361\335\26
1\27\305\276\224\321> \222JKNjwo\336\224PmJ\246\1A\210\374\27w
\33\377\r\2=
1\340\32\326\326f\332\255\214T0%\253,!1\
212\206\374\351UE\25\274\360*>\3=
10\236\262hcP[- ZW\27\0f\311+@U\305\214\2701e\10\320\5\3
3S\302K\352\366\3=
46.\314\36
7:Z9\316j\313]K\342\356X\31\245S\5\251\t
8\223KXrZ\277\277\236I\352;T\200=
\327\r1\240iO\21\31\301\10"..., =
26868) =3D 26868
write(9, =
"\2100)\"\33\31\207\244\241\0254\210v\360W{\321$\221\331^\302\237\22480\=
33\257\35\2220\25\337f\17#e\7%\253\23\33
0\21\356\321\250fd\204\241%\372h=
D\374h\214\225\16\232w\322@O\16m_!\375\2
37w)\20\n\256YF\353B\10|\231j7\2=
3
1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\30=
1\37V\307\371\216\354\234k =
\223\247\333\316'\f\235\226h< \344\344uD\25\251\253\4\364*\361\215\264
\2=
34\377\202\222\27\262\6\257\223J\6\313\3
44\300\331\222\
243\304U\211\304\257\206vO\341\322\307\3
46\307\270I\300\362\330>xH\267\3=
2+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\215d\3=
5\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
237,J\=
251\210/Ud
g\377\231`KZ\34\342\302'\320\240T\177\3
21\304\7\320*\241T)\326\256I\264=
\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277\6\2=
25\\\f\226\247\3!qi\341`\323\rV\251.`w\26\27\17 =
`\247\346 \232\257\356/b\205\223'
?\366\nz\242L\304\261\255\223\276-\231\361\371\314\31\303\303\367 =
{\24ha(\374\34\315\365\270\212"..., 61449) =3D 61449
epoll_ctl(5, EPOLL_CTL_MOD, 9, {EPOLLIN|EPOLLERR|EPOLLHUP|0x20, {u32=3D9=
, =
u64=3D9}}) =3D 0
epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLIN|EPOLLERR|EPOLLHUP|0x20, {u32=3D=
12, =
u64=3D12}}) =3D 0
time(NULL) =3D 1157770135
gettimeofday({1157770135, 505376}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D12, u64=3D12}}}, 1000, 1000) =3D 1
read(12, =
"\\\270\t\311\260&\347y\300\7$*+\245M\364.\306\255\246\357\177\206F'\30=
38& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\220R\2=
0\274\201b\31\232r\370\263\240\331\305\3
0\323\3351Z\372\276>\3768[eg\f\3=
2
3\330\265\276K\200\tR& #91;\36\363\v\334\225\204\266\24)\351\34
\345\20h_\245x=
\206\232\336\217\261\1\362 =
\303sj\214\251\353qQ\235g\244CJ\372\344\
343U\221?y*\373\1\341\274\203\26=
5W\356\233\2=3D\331\303B\264U\211\231\33
3\235\253|\217a\2
60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\=
276\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\306\25=
0\27\30\255\213\2649`\30\22\223\316\351\
240.\"\362e\335\201\255L\305\335=
\207\301\2
70\266@\226\347\272\373\231G\267\207I\26
2\352\272\247\352\17\231.\32\345=
\202\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\5\327\335Z\24=
7\343y\327W\241l\277\231\375\232\262\261
\177]Mur\275\271y\223\270\2020\2=
67\366EE~e
\226L\326\247\f\334Mi$b\v\377\255\351K\3
20ORR\225}Z\331k\344\213\337V\24=
5b.b_]\36\27_\375f\211\25"..., =
61449) =3D 61449
write(9, =
"\\\270\t\311\260&\347y\300\7$*+\245M\364.\306\255\246\357\177\206F'\30=
38& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\220R\2=
0\274\201b\31\232r\370\263\240\331\305\3
0\323\3351Z\372\276>\3768[eg\f\3=
2
3\330\265\276K\200\tR& #91;\36\363\v\334\225\204\266\24)\351\34
\345\20h_\245x=
\206\232\336\217\261\1\362 =
\303sj\214\251\353qQ\235g\244CJ\372\344\
343U\221?y*\373\1\341\274\203\26=
5W\356\233\2=3D\331\303B\264U\211\231\33
3\235\253|\217a\2
60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\=
276\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\306\25=
0\27\30\255\213\2649`\30\22\223\316\351\
240.\"\362e\335\201\255L\305\335=
\207\301\2
70\266@\226\347\272\373\231G\267\207I\26
2\352\272\247\352\17\231.\32\345=
\202\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\5\327\335Z\24=
7\343y\327W\241l\277\231\375\232\262\261
\177]Mur\275\271y\223\270\2020\2=
67\366EE~e
\226L\326\247\f\334Mi$b\v\377\255\351K\3
20ORR\225}Z\331k\344\213\337V\24=
5b.b_]\36\27_\375f\211\25"..., =
61449) =3D 9963
epoll_ctl(5, EPOLL_CTL_MOD, 9, & #123;EPOLLIN|EPOLLOUT|EPOLLERR|EPOLLHUP|
0x20,=
=
{u32=3D9, u64=3D9}}) =3D 0
time(NULL) =3D 1157770135
gettimeofday({1157770135, 505943}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D12, u64=3D12}}}, 1000, 1000) =3D 1
epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLERR|EPOLLHUP|0x20, {u32=3D12, =
u64=3D12}}) =3D 0
time(NULL) =3D 1157770135
gettimeofday({1157770135, 506101}, NULL) =3D 0
epoll_wait(5, {}, 1000, 1000) =3D 0
time(NULL) =3D 1157770136
gettimeofday({1157770136, 507274}, NULL) =3D 0
epoll_wait(5, {}, 1000, 1000) =3D 0
time(NULL) =3D 1157770137
gettimeofday({1157770137, 507277}, NULL) =3D 0
epoll_wait(5, {}, 1000, 1000) =3D 0
time(NULL) =3D 1157770138
gettimeofday({1157770138, 507259}, NULL) =3D 0
epoll_wait(5, {}, 1000, 881) =3D 0
time(NULL) =3D 1157770139
gettimeofday({1157770139, 391390}, NULL) =3D 0
time(NULL) =3D 1157770139
gettimeofday({1157770139, 391504}, NULL) =3D 0
epoll_wait(5, {}, 1000, 1000) =3D 0
time(NULL) =3D 1157770140
gettimeofday({1157770140, 391353}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D4, u64=3D4}}}, 1000, 1000) =3D 1
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
Right when the chunks stop is when the download freezes, at about 10% of=
a =
50mb file. Let me know if you need more/different parts of the trace. =
Thanks!
-Sam
On Fri, 08 Sep 2006 10:47:33 -0700, Brad Fitzpatrick <brad@danga.com> =
wrote:
[vbcol=seagreen]
> Hm. Can you get an strace on the main Perlbal process while this is
> happening?
>
> $ strace -s 500 -o perlbal.trace -p <pid-of-perlbal>
> ...... (wait)
> ^C
>
>
>
> On Fri, 8 Sep 2006, Sam G wrote:
>
GB[vbcol=seagreen]
d[vbcol=seagreen]
[vbcol=seagreen]
ad[vbcol=seagreen]
ts =
[vbcol=seagreen]
s =
[vbcol=seagreen]
=
[vbcol=seagreen]
e[vbcol=seagreen]
:IO[vbcol=seagreen]
rom[vbcol=seagreen]
t =
[vbcol=seagreen]
[vbcol=seagreen]
[vbcol=seagreen]
-- =
Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
| |
| Brad Fitzpatrick 2006-09-09, 1:12 am |
| That's very useful, thanks.
On Fri, 8 Sep 2006, Sam G wrote:
> This seems to be the bulk of what's happening:
>
> ===========
>
> <lots of large chunks of text scrolling by as file downloads...>
> ....
> <snip>
> ....
> epoll_ctl(5, EPOLL_CTL_MOD, 9, & #123;EPOLLIN|EPOLLOUT|EPOLLERR|EPOLLHUP|
0x20,
> {u32=9, u64=9}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 330342}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1000, 1000) = 1
> read(12,
> "\2100)\"\33\31\207\244\241\0254\210v\360W& #123;\321$\221\331^\302\237\22480\33\257
\35\2220\25\337f\17#e\7%\253\23\330\21\3
56\321\250fd\204\241%\372hD\374h\214\225
\16\232w\322@O\16m_!\375\237w)\20\n\256Y
F\353B\10|\231j7\23
> 1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\301\37V\30
7\371\216\354\234k
> \223\247\333\316'\f\235\226h< \344\344uD\25\251\253\4\364*\361\215\264
\234\377\202\222\27\262\6\257\223J\6\313
\344\300\331\222\
> 243\304U\211\304\257\206vO\341\322\307\3
46\307\270I\300\362\330>xH\267\32+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\215d\35\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
237,J\251\210/Ud
> g\377\231`KZ\34\342\302'\320\240T\177\3
21\304\7\320*\241T)\326\256I\264\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277\6\225\\\f\226\247\3!qi\341
`\323\rV\251.`w\26\27\17
> `\247\346 \232\257\356/b\205\223'
> ?\366\nz\242L\304\261\255\223\276-\231\361\371\314\31\303\303\367
> {\24ha(\374\34\315\365\270\212"..., 61449) = 61449
> time(NULL) = 1157770135
> gettimeofday({1157770135, 330707}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1000, 1000) = 1
> epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLERR|EPOLLHUP|0x20, {u32=12,
> u64=12}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 330867}, NULL) = 0
> epoll_wait(5, {{EPOLLOUT, {u32=9, u64=9}}}, 1000, 1000) = 1
> time(NULL) = 1157770135
> write(9,
> " Q\344\7\330,\301\355!k\3278\31:\256\371\
264< \330\352\310j\225\30\325\310\361\360D\35
3\353w\344L\3\341*\345\227\3460\204\354\
23Q\332\316- O\301\350\270w\206t\235v\365\300r;\367\3
77\220s\244\311\302\226\372\0\357\3025\3
> 60\266\336\341\0\377%O\3324\213\364\344\
201D\232si\5\301JS? \341|o\250\274\377\240F\364\32\250$\24\3
72\315\325q\233_\350at\324\363\320\343qG
\32\221\345\f\272\324\t\2524\\\232]^\301
\241\220\212\241R\372\3240\360*A\3709}\2
03@\22\
> 313\n(_\200H\263\335\243\261\342Q\33\16\
264\243_\230\372A:g*Y\331\324\325F\326N\
27,~\200\235\306_\222@\301\246\266\r\374
\202\216\311A\2mb\3\213+r\201\22K\323\37
4'\277\5l\353\10\355+< ~\35\\\272\320\277\323\34\37\345\361\335
\26
> 1\27\305\276\224\321> \222JKNjwo\336\224PmJ\246\1A\210\374\27w
\33\377\r\21\340\32\326\326f\332\255\214
T0%\253,!1\212\206\374\351UE\25\274\360*
>\310\236\262hcP[- ZW\27\0f\311+@U\305\214\2701e\10\320\5\3
3S\302K\352\366\346.\314\36
> 7:Z9\316j\313]K\342\356X\31\245S\5\251\t
8\223KXrZ\277\277\236I\352;T\200\327\r1\
240iO\21\31\301\10"...,
> 26868) = 26868
> write(9,
> "\2100)\"\33\31\207\244\241\0254\210v\360W& #123;\321$\221\331^\302\237\22480\33\257
\35\2220\25\337f\17#e\7%\253\23\330\21\3
56\321\250fd\204\241%\372hD\374h\214\225
\16\232w\322@O\16m_!\375\237w)\20\n\256Y
F\353B\10|\231j7\23
> 1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\301\37V\30
7\371\216\354\234k
> \223\247\333\316'\f\235\226h< \344\344uD\25\251\253\4\364*\361\215\264
\234\377\202\222\27\262\6\257\223J\6\313
\344\300\331\222\
> 243\304U\211\304\257\206vO\341\322\307\3
46\307\270I\300\362\330>xH\267\32+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\215d\35\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
237,J\251\210/Ud
> g\377\231`KZ\34\342\302'\320\240T\177\3
21\304\7\320*\241T)\326\256I\264\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277\6\225\\\f\226\247\3!qi\341
`\323\rV\251.`w\26\27\17
> `\247\346 \232\257\356/b\205\223'
> ?\366\nz\242L\304\261\255\223\276-\231\361\371\314\31\303\303\367
> {\24ha(\374\34\315\365\270\212"..., 61449) = 61449
> epoll_ctl(5, EPOLL_CTL_MOD, 9, {EPOLLIN|EPOLLERR|EPOLLHUP|0x20, {u32=9,
> u64=9}}) = 0
> epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLIN|EPOLLERR|EPOLLHUP|0x20, {u32=12,
> u64=12}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 505376}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1000, 1000) = 1
> read(12,
> "\\\270\t\311\260&\347y\300\7$*+\245M\364.\306\255\246\357\177\206F'\3038& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\220R\20\274\201b\
31\232r\370\263\240\331\305\30\323\3351Z
\372\276>\3768[eg\f\32
> 3\330\265\276K\200\tR& #91;\36\363\v\334\225\204\266\24)\351\34
\345\20h_\245x\206\232\336\217\261\1\362
> \303sj\214\251\353qQ\235g\244CJ\372\344\
343U\221? y*\373\1\341\274\203\265W\356\233\2=\331
\303B\264U\211\231\333\235\253|\217a\2
> 60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\276\17\352\212\3
0\313\"\376\347\307+\365\314\337? r\25745\354tj\23\306\250\27\30\255\213\2
649`\30\22\223\316\351\240.\"\362e\335\201\255L\305\335\207\301\2
> 70\266@\226\347\272\373\231G\267\207I\26
2\352\272\247\352\17\231.\32\345\202\244H\335\346{{\37\25{\310]\32\305\teJ\226& #91;\336X\232Wn\5\327\335Z\247\343y\327W
\241l\277\231\375\232\262\261\177]Mur\27
5\271y\223\270\2020\267\366EE~e
> \226L\326\247\f\334Mi$b\v\377\255\351K\3
20ORR\225}Z\331k\344\213\337V\245b.b_]\36\27_\375f\211\25"...,
> 61449) = 61449
> write(9,
> "\\\270\t\311\260&\347y\300\7$*+\245M\364.\306\255\246\357\177\206F'\3038& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\220R\20\274\201b\
31\232r\370\263\240\331\305\30\323\3351Z
\372\276>\3768[eg\f\32
> 3\330\265\276K\200\tR& #91;\36\363\v\334\225\204\266\24)\351\34
\345\20h_\245x\206\232\336\217\261\1\362
> \303sj\214\251\353qQ\235g\244CJ\372\344\
343U\221? y*\373\1\341\274\203\265W\356\233\2=\331
\303B\264U\211\231\333\235\253|\217a\2
> 60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\276\17\352\212\3
0\313\"\376\347\307+\365\314\337? r\25745\354tj\23\306\250\27\30\255\213\2
649`\30\22\223\316\351\240.\"\362e\335\201\255L\305\335\207\301\2
> 70\266@\226\347\272\373\231G\267\207I\26
2\352\272\247\352\17\231.\32\345\202\244H\335\346{{\37\25{\310]\32\305\teJ\226& #91;\336X\232Wn\5\327\335Z\247\343y\327W
\241l\277\231\375\232\262\261\177]Mur\27
5\271y\223\270\2020\267\366EE~e
> \226L\326\247\f\334Mi$b\v\377\255\351K\3
20ORR\225}Z\331k\344\213\337V\245b.b_]\36\27_\375f\211\25"...,
> 61449) = 9963
> epoll_ctl(5, EPOLL_CTL_MOD, 9, & #123;EPOLLIN|EPOLLOUT|EPOLLERR|EPOLLHUP|
0x20,
> {u32=9, u64=9}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 505943}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1000, 1000) = 1
> epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLERR|EPOLLHUP|0x20, {u32=12,
> u64=12}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 506101}, NULL) = 0
> epoll_wait(5, {}, 1000, 1000) = 0
> time(NULL) = 1157770136
> gettimeofday({1157770136, 507274}, NULL) = 0
> epoll_wait(5, {}, 1000, 1000) = 0
> time(NULL) = 1157770137
> gettimeofday({1157770137, 507277}, NULL) = 0
> epoll_wait(5, {}, 1000, 1000) = 0
> time(NULL) = 1157770138
> gettimeofday({1157770138, 507259}, NULL) = 0
> epoll_wait(5, {}, 1000, 881) = 0
> time(NULL) = 1157770139
> gettimeofday({1157770139, 391390}, NULL) = 0
> time(NULL) = 1157770139
> gettimeofday({1157770139, 391504}, NULL) = 0
> epoll_wait(5, {}, 1000, 1000) = 0
> time(NULL) = 1157770140
> gettimeofday({1157770140, 391353}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=4, u64=4}}}, 1000, 1000) = 1
>
> ===========
>
> Right when the chunks stop is when the download freezes, at about 10% of a
> 50mb file. Let me know if you need more/different parts of the trace.
> Thanks!
>
> -Sam
>
> On Fri, 08 Sep 2006 10:47:33 -0700, Brad Fitzpatrick <brad@danga.com>
> wrote:
>
>
>
>
> --
> Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
>
>
| |
| Brad Fitzpatrick 2006-09-09, 1:11 pm |
| Try increasing the server's "buffer_size_reproxy_url" setting. Still, it
shouldn't freeze, so something more is messed up.
I can't reproduce this here, even though I thought I'd be able to. I get
350 kB/second to my house from both my origin and reproxy-URL'd services,
which live on different hosts.
What's your perlbal configuration and network look like? What's the
latency between the three parties involved? (ignoring the first server
that issues the x-reproxy-url header)
BTW, the aio mode won't matter for this... it's a pure network operation.
No filesystem calls involved to do async.
When a download stalls, telnet into the Perlbal management port and type
"socks". What's the output? In particular, I'm wondering what state and
buffer sizes the different parties are at.
On Fri, 8 Sep 2006, Sam G wrote:
> This seems to be the bulk of what's happening:
>
> ===========
>
> <lots of large chunks of text scrolling by as file downloads...>
> ....
> <snip>
> ....
> epoll_ctl(5, EPOLL_CTL_MOD, 9, & #123;EPOLLIN|EPOLLOUT|EPOLLERR|EPOLLHUP|
0x20,
> {u32=9, u64=9}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 330342}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1000, 1000) = 1
> read(12,
> "\2100)\"\33\31\207\244\241\0254\210v\360W& #123;\321$\221\331^\302\237\22480\33\257
\35\2220\25\337f\17#e\7%\253\23\330\21\3
56\321\250fd\204\241%\372hD\374h\214\225
\16\232w\322@O\16m_!\375\237w)\20\n\256Y
F\353B\10|\231j7\23
> 1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\301\37V\30
7\371\216\354\234k
> \223\247\333\316'\f\235\226h< \344\344uD\25\251\253\4\364*\361\215\264
\234\377\202\222\27\262\6\257\223J\6\313
\344\300\331\222\
> 243\304U\211\304\257\206vO\341\322\307\3
46\307\270I\300\362\330>xH\267\32+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\215d\35\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
237,J\251\210/Ud
> g\377\231`KZ\34\342\302'\320\240T\177\3
21\304\7\320*\241T)\326\256I\264\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277\6\225\\\f\226\247\3!qi\341
`\323\rV\251.`w\26\27\17
> `\247\346 \232\257\356/b\205\223'
> ?\366\nz\242L\304\261\255\223\276-\231\361\371\314\31\303\303\367
> {\24ha(\374\34\315\365\270\212"..., 61449) = 61449
> time(NULL) = 1157770135
> gettimeofday({1157770135, 330707}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1000, 1000) = 1
> epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLERR|EPOLLHUP|0x20, {u32=12,
> u64=12}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 330867}, NULL) = 0
> epoll_wait(5, {{EPOLLOUT, {u32=9, u64=9}}}, 1000, 1000) = 1
> time(NULL) = 1157770135
> write(9,
> " Q\344\7\330,\301\355!k\3278\31:\256\371\
264< \330\352\310j\225\30\325\310\361\360D\35
3\353w\344L\3\341*\345\227\3460\204\354\
23Q\332\316- O\301\350\270w\206t\235v\365\300r;\367\3
77\220s\244\311\302\226\372\0\357\3025\3
> 60\266\336\341\0\377%O\3324\213\364\344\
201D\232si\5\301JS? \341|o\250\274\377\240F\364\32\250$\24\3
72\315\325q\233_\350at\324\363\320\343qG
\32\221\345\f\272\324\t\2524\\\232]^\301
\241\220\212\241R\372\3240\360*A\3709}\2
03@\22\
> 313\n(_\200H\263\335\243\261\342Q\33\16\
264\243_\230\372A:g*Y\331\324\325F\326N\
27,~\200\235\306_\222@\301\246\266\r\374
\202\216\311A\2mb\3\213+r\201\22K\323\37
4'\277\5l\353\10\355+< ~\35\\\272\320\277\323\34\37\345\361\335
\26
> 1\27\305\276\224\321> \222JKNjwo\336\224PmJ\246\1A\210\374\27w
\33\377\r\21\340\32\326\326f\332\255\214
T0%\253,!1\212\206\374\351UE\25\274\360*
>\310\236\262hcP[- ZW\27\0f\311+@U\305\214\2701e\10\320\5\3
3S\302K\352\366\346.\314\36
> 7:Z9\316j\313]K\342\356X\31\245S\5\251\t
8\223KXrZ\277\277\236I\352;T\200\327\r1\
240iO\21\31\301\10"...,
> 26868) = 26868
> write(9,
> "\2100)\"\33\31\207\244\241\0254\210v\360W& #123;\321$\221\331^\302\237\22480\33\257
\35\2220\25\337f\17#e\7%\253\23\330\21\3
56\321\250fd\204\241%\372hD\374h\214\225
\16\232w\322@O\16m_!\375\237w)\20\n\256Y
F\353B\10|\231j7\23
> 1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\301\37V\30
7\371\216\354\234k
> \223\247\333\316'\f\235\226h< \344\344uD\25\251\253\4\364*\361\215\264
\234\377\202\222\27\262\6\257\223J\6\313
\344\300\331\222\
> 243\304U\211\304\257\206vO\341\322\307\3
46\307\270I\300\362\330>xH\267\32+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\215d\35\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
237,J\251\210/Ud
> g\377\231`KZ\34\342\302'\320\240T\177\3
21\304\7\320*\241T)\326\256I\264\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277\6\225\\\f\226\247\3!qi\341
`\323\rV\251.`w\26\27\17
> `\247\346 \232\257\356/b\205\223'
> ?\366\nz\242L\304\261\255\223\276-\231\361\371\314\31\303\303\367
> {\24ha(\374\34\315\365\270\212"..., 61449) = 61449
> epoll_ctl(5, EPOLL_CTL_MOD, 9, {EPOLLIN|EPOLLERR|EPOLLHUP|0x20, {u32=9,
> u64=9}}) = 0
> epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLIN|EPOLLERR|EPOLLHUP|0x20, {u32=12,
> u64=12}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 505376}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1000, 1000) = 1
> read(12,
> "\\\270\t\311\260&\347y\300\7$*+\245M\364.\306\255\246\357\177\206F'\3038& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\220R\20\274\201b\
31\232r\370\263\240\331\305\30\323\3351Z
\372\276>\3768[eg\f\32
> 3\330\265\276K\200\tR& #91;\36\363\v\334\225\204\266\24)\351\34
\345\20h_\245x\206\232\336\217\261\1\362
> \303sj\214\251\353qQ\235g\244CJ\372\344\
343U\221? y*\373\1\341\274\203\265W\356\233\2=\331
\303B\264U\211\231\333\235\253|\217a\2
> 60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\276\17\352\212\3
0\313\"\376\347\307+\365\314\337? r\25745\354tj\23\306\250\27\30\255\213\2
649`\30\22\223\316\351\240.\"\362e\335\201\255L\305\335\207\301\2
> 70\266@\226\347\272\373\231G\267\207I\26
2\352\272\247\352\17\231.\32\345\202\244H\335\346{{\37\25{\310]\32\305\teJ\226& #91;\336X\232Wn\5\327\335Z\247\343y\327W
\241l\277\231\375\232\262\261\177]Mur\27
5\271y\223\270\2020\267\366EE~e
> \226L\326\247\f\334Mi$b\v\377\255\351K\3
20ORR\225}Z\331k\344\213\337V\245b.b_]\36\27_\375f\211\25"...,
> 61449) = 61449
> write(9,
> "\\\270\t\311\260&\347y\300\7$*+\245M\364.\306\255\246\357\177\206F'\3038& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\220R\20\274\201b\
31\232r\370\263\240\331\305\30\323\3351Z
\372\276>\3768[eg\f\32
> 3\330\265\276K\200\tR& #91;\36\363\v\334\225\204\266\24)\351\34
\345\20h_\245x\206\232\336\217\261\1\362
> \303sj\214\251\353qQ\235g\244CJ\372\344\
343U\221? y*\373\1\341\274\203\265W\356\233\2=\331
\303B\264U\211\231\333\235\253|\217a\2
> 60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\276\17\352\212\3
0\313\"\376\347\307+\365\314\337? r\25745\354tj\23\306\250\27\30\255\213\2
649`\30\22\223\316\351\240.\"\362e\335\201\255L\305\335\207\301\2
> 70\266@\226\347\272\373\231G\267\207I\26
2\352\272\247\352\17\231.\32\345\202\244H\335\346{{\37\25{\310]\32\305\teJ\226& #91;\336X\232Wn\5\327\335Z\247\343y\327W
\241l\277\231\375\232\262\261\177]Mur\27
5\271y\223\270\2020\267\366EE~e
> \226L\326\247\f\334Mi$b\v\377\255\351K\3
20ORR\225}Z\331k\344\213\337V\245b.b_]\36\27_\375f\211\25"...,
> 61449) = 9963
> epoll_ctl(5, EPOLL_CTL_MOD, 9, & #123;EPOLLIN|EPOLLOUT|EPOLLERR|EPOLLHUP|
0x20,
> {u32=9, u64=9}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 505943}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1000, 1000) = 1
> epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLERR|EPOLLHUP|0x20, {u32=12,
> u64=12}}) = 0
> time(NULL) = 1157770135
> gettimeofday({1157770135, 506101}, NULL) = 0
> epoll_wait(5, {}, 1000, 1000) = 0
> time(NULL) = 1157770136
> gettimeofday({1157770136, 507274}, NULL) = 0
> epoll_wait(5, {}, 1000, 1000) = 0
> time(NULL) = 1157770137
> gettimeofday({1157770137, 507277}, NULL) = 0
> epoll_wait(5, {}, 1000, 1000) = 0
> time(NULL) = 1157770138
> gettimeofday({1157770138, 507259}, NULL) = 0
> epoll_wait(5, {}, 1000, 881) = 0
> time(NULL) = 1157770139
> gettimeofday({1157770139, 391390}, NULL) = 0
> time(NULL) = 1157770139
> gettimeofday({1157770139, 391504}, NULL) = 0
> epoll_wait(5, {}, 1000, 1000) = 0
> time(NULL) = 1157770140
> gettimeofday({1157770140, 391353}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=4, u64=4}}}, 1000, 1000) = 1
>
> ===========
>
> Right when the chunks stop is when the download freezes, at about 10% of a
> 50mb file. Let me know if you need more/different parts of the trace.
> Thanks!
>
> -Sam
>
> On Fri, 08 Sep 2006 10:47:33 -0700, Brad Fitzpatrick <brad@danga.com>
> wrote:
>
>
>
>
> --
> Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
>
>
| |
|
| On Sat, 09 Sep 2006 09:36:58 -0700, Brad Fitzpatrick <brad@danga.com> =
wrote:
> Try increasing the server's "buffer_size_reproxy_url" setting. Still,=
it
> shouldn't freeze, so something more is messed up.
>
> I can't reproduce this here, even though I thought I'd be able to. I =
get
> 350 kB/second to my house from both my origin and reproxy-URL'd servic=
es,
> which live on different hosts.
>
> What's your perlbal configuration and network look like? What's the
> latency between the three parties involved? (ignoring the first serve=
r
> that issues the x-reproxy-url header)
There is very low latency between all three parties. The perlbal machine=
=
is on the same local network as the storage box, pulling data through =
Apache webdav. The downloading machine is geographically close and =
connected at high bandwidth to the datacenter which houses the first two=
=
machines.
>
> BTW, the aio mode won't matter for this... it's a pure network operati=
on.
> No filesystem calls involved to do async.
>
> When a download stalls, telnet into the Perlbal management port and ty=
pe
> "socks". What's the output? In particular, I'm wondering what state =
and
> buffer sizes the different parties are at.
Relevant Perlbal config:
CREATE POOL php_apaches
SET nodefile =3D /etc/perlbal/nodelist.dat
CREATE SERVICE balancer
SET listen =3D 10.10.10.251:80
SET role =3D reverse_proxy
SET enable_reproxy =3D true
SET pool =3D php_apaches
SET persist_client =3D on
SET persist_backend =3D on
SET verify_backend =3D on
ENABLE balancer
Perlbal machine IP: 10.10.10.251, storage IP: 10.10.30.101, client IP =
requesting download: 67.180.143.68.
Before download starts, everything idle:
socks
fd age
4 405805s Perlbal::TCPListener(R): open: listening on 10.10.10.251:=
80 =
for service 'balancer'
8 405805s Perlbal::TCPListener(R): open: listening on 127.0.0.1:600=
01 =
for service 'mgmt'
12 35s Perlbal::ClientManage(R): open to 127.0.0.1:38802
..
After download starts, is progressing:
socks
fd age
4 405813s Perlbal::TCPListener(R): open: listening on 10.10.10.251:=
80 =
for service 'balancer'
8 405813s Perlbal::TCPListener(R): open: listening on 127.0.0.1:600=
01 =
for service 'mgmt'
9 4s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791: =
localport=3D80; reqs=3D1; xfer_res; http://url/file_id=3Df_7926310; =
backend=3D10.10.30.101:80; responded
10 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4792: =
localport=3D80; reqs=3D2; persist_wait
11 4s Perlbal::BackendHTTP(R): open to 10.10.30.101:80: =
localport=3D50561; client=3D9; uses=3D0; xfer_res
12 43s Perlbal::ClientManage(R): open to 127.0.0.1:38802
13 4s Perlbal::BackendHTTP(R): open to 10.10.20.103:80: =
localport=3D55473; uses=3D4; bored; has_attention=3Dyes
14 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4793: =
localport=3D80; reqs=3D1; persist_wait
15 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4794: =
localport=3D80; reqs=3D1; persist_wait
..
socks
fd age
4 405815s Perlbal::TCPListener(R): open: listening on 10.10.10.251:=
80 =
for service 'balancer'
8 405815s Perlbal::TCPListener(R): open: listening on 127.0.0.1:600=
01 =
for service 'mgmt'
9 6s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791: =
localport=3D80; reqs=3D1; xfer_res; http://url/file_id=3Df_7926310; =
backend=3D10.10.30.101:80; responded
10 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4792: =
localport=3D80; reqs=3D2; persist_wait
11 6s Perlbal::BackendHTTP(): open to 10.10.30.101:80: =
localport=3D50561; client=3D9; uses=3D0; xfer_res
12 45s Perlbal::ClientManage(R): open to 127.0.0.1:38802
14 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4793: =
localport=3D80; reqs=3D1; persist_wait
15 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4794: =
localport=3D80; reqs=3D1; persist_wait
..
At this point the download is totally frozen:
socks
fd age
4 405818s Perlbal::TCPListener(R): open: listening on 10.10.10.251:=
80 =
for service 'balancer'
8 405818s Perlbal::TCPListener(R): open: listening on 127.0.0.1:600=
01 =
for service 'mgmt'
9 9s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791: =
localport=3D80; reqs=3D1; xfer_res; http://url/file_id=3Df_7926310; =
backend=3D10.10.30.101:80; responded
10 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4792: =
localport=3D80; reqs=3D2; persist_wait
11 9s Perlbal::BackendHTTP(): open to 10.10.30.101:80: =
localport=3D50561; client=3D9; uses=3D0; xfer_res
12 48s Perlbal::ClientManage(R): open to 127.0.0.1:38802
14 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4793: =
localport=3D80; reqs=3D1; persist_wait
15 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4794: =
localport=3D80; reqs=3D1; persist_wait
..
I cancel the download, and it returns to first state:
socks
fd age
4 405931s Perlbal::TCPListener(R): open: listening on 10.10.10.251:=
80 =
for service 'balancer'
8 405931s Perlbal::TCPListener(R): open: listening on 127.0.0.1:600=
01 =
for service 'mgmt'
12 161s Perlbal::ClientManage(R): open to 127.0.0.1:38802
..
Let me know what else I can get you.
-Sam
>
>
>
>
> On Fri, 8 Sep 2006, Sam G wrote:
>
20,[vbcol=seagreen]
80\33\257\35\2220\25\337f\17#e\7%\253\23
\330\21\356\321\250fd\204\241%\3=
72hD\374h\214\225\16\232w\322@O\16m_!\37
5\237w)\20\n\256YF\353B\10|\231j=
7\23[vbcol=seagreen]
\301\37V\307\371\216\354\234k[vbcol=seag
reen]
4\234\377\202\222\27\262\6\257\223J\6\31
3\344\300\331\222\[vbcol=seagreen]
7\32+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\215=
d\35\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
237=
,J\251\210/Ud[vbcol=seagreen]
264\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277\=
6\225\\\f\226\247\3!qi\341`\323\rV\251.`w\26\27\17[vbcol=seagreen]
\310\361\360D\353\353w\344L\3\341*\345\2
27\3460\204\354\23Q\332\316-O\30=
1\350\270w\206t\235v\365\300r;\367\377\2
20s\244\311\302\226\372\0\357\30=
25\3[vbcol=seagreen]
\274\377\240F\364\32\250$\24\372\315\325
q\233_\350at\324\363\320\343qG\3=
2\221\345\f\272\324\t\2524\\\232]^\301\2
41\220\212\241R\372\3240\360*A\3=
709}\203@\22\[vbcol=seagreen]
\325F\326N\27,~\200\235\306_\222@\301\24
6\266\r\374\202\216\311A\2mb\3\2=
13+r\201\22K\323\374'\277\5l\353\10\355
+<~\35\\\272\320\277\323\34\37\3=
45\361\335\26[vbcol=seagreen]
r\21\340\32\326\326f\332\255\214T0%\253,
!1\212\206\374\351UE\25\274\360*=[vbcol=
seagreen]
>\310\236\262hcP[- ZW\27\0f\311+@U\305\214\2701e\10\320\5\3
3S\302K\352\36=
6\346.\314\36[vbcol=seagreen]
200\327\r1\240iO\21\31\301\10"...,[vbcol=seagreen]
80\33\257\35\2220\25\337f\17#e\7%\253\23
\330\21\356\321\250fd\204\241%\3=
72hD\374h\214\225\16\232w\322@O\16m_!\37
5\237w)\20\n\256YF\353B\10|\231j=
7\23[vbcol=seagreen]
\301\37V\307\371\216\354\234k[vbcol=seag
reen]
4\234\377\202\222\27\262\6\257\223J\6\31
3\344\300\331\222\[vbcol=seagreen]
7\32+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\215=
d\35\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
237=
,J\251\210/Ud[vbcol=seagreen]
264\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277\=
6\225\\\f\226\247\3!qi\341`\323\rV\251.`w\26\27\17[vbcol=seagreen]
9,[vbcol=seagreen]
[vbcol=seagreen]
\3038& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\220=
R\20\274\201b\31\232r\370\263\240\331\30
5\30\323\3351Z\372\276>\3768[eg\=
f\32[vbcol=seagreen]
45x\206\232\336\217\261\1\362[vbcol=seag
reen]
\265W\356\233\2=3D\331\303B\264U\211\231
\333\235\253|\217a\2[vbcol=seagreen]
1f\276\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\306=
\250\27\30\255\213\2649`\30\22\223\316\3
51\240.\"\362e\335\201\255L\305\=
335\207\301\2[vbcol=seagreen]
345\202\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\5\327\335Z=
\247\343y\327W\241l\277\231\375\232\262\
261\177]Mur\275\271y\223\270\202=
0\267\366EE~e[vbcol=seagreen]
\245b.b_]\36\27_\375f\211\25"...,[vbcol=seagreen]
\3038& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\220=
R\20\274\201b\31\232r\370\263\240\331\30
5\30\323\3351Z\372\276>\3768[eg\=
f\32[vbcol=seagreen]
45x\206\232\336\217\261\1\362[vbcol=seag
reen]
\265W\356\233\2=3D\331\303B\264U\211\231
\333\235\253|\217a\2[vbcol=seagreen]
1f\276\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\306=
\250\27\30\255\213\2649`\30\22\223\316\3
51\240.\"\362e\335\201\255L\305\=
335\207\301\2[vbcol=seagreen]
345\202\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\5\327\335Z=
\247\343y\327W\241l\277\231\375\232\262\
261\177]Mur\275\271y\223\270\202=
0\267\366EE~e[vbcol=seagreen]
\245b.b_]\36\27_\375f\211\25"...,[vbcol=seagreen]
20,[vbcol=seagreen]
=
[vbcol=seagreen]
[vbcol=seagreen]
[vbcol=seagreen]
s[vbcol=seagreen]
/ =
[vbcol=seagreen]
[vbcol=seagreen]
,[vbcol=seagreen]
[vbcol=seagreen]
=
[vbcol=seagreen]
,[vbcol=seagreen]
[vbcol=seagreen]
but[vbcol=seagreen]
[vbcol=seagreen]
[vbcol=seagreen]
l =
[vbcol=seagreen]
[vbcol=seagreen]
U[vbcol=seagreen]
d[vbcol=seagreen]
il/[vbcol=seagreen]
[vbcol=seagreen]
-- =
Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
| |
|
| Quick addendum: I tried reproxying to an external URL, and had the same =
=
problem; download locked up after about 8MB of a 600MB file.
Also, the machine is 64-bit, if that is of any note.
-Sam
On Tue, 12 Sep 2006 21:06:26 -0700, Sam G <ceptorial@comcast.net> wrote:=
> On Sat, 09 Sep 2006 09:36:58 -0700, Brad Fitzpatrick <brad@danga.com> =
=
> wrote:
>
, =
[vbcol=seagreen]
=
[vbcol=seagreen]
[vbcol=seagreen]
er[vbcol=seagreen]
>
> There is very low latency between all three parties. The perlbal machi=
ne =
> is on the same local network as the storage box, pulling data through =
=
> Apache webdav. The downloading machine is geographically close and =
> connected at high bandwidth to the datacenter which houses the first t=
wo =
> machines.
>
[vbcol=seagreen]
ype[vbcol=seagreen]
=
[vbcol=seagreen]
>
> Relevant Perlbal config:
>
> CREATE POOL php_apaches
> SET nodefile =3D /etc/perlbal/nodelist.dat
>
> CREATE SERVICE balancer
> SET listen =3D 10.10.10.251:80
> SET role =3D reverse_proxy
> SET enable_reproxy =3D true
> SET pool =3D php_apaches
> SET persist_client =3D on
> SET persist_backend =3D on
> SET verify_backend =3D on
> ENABLE balancer
>
> Perlbal machine IP: 10.10.10.251, storage IP: 10.10.30.101, client IP =
=
> requesting download: 67.180.143.68.
>
> Before download starts, everything idle:
>
> socks
> fd age
> 4 405805s Perlbal::TCPListener(R): open: listening on =
> 10.10.10.251:80 for service 'balancer'
> 8 405805s Perlbal::TCPListener(R): open: listening on =
> 127.0.0.1:60001 for service 'mgmt'
> 12 35s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> .
>
> After download starts, is progressing:
>
> socks
> fd age
> 4 405813s Perlbal::TCPListener(R): open: listening on =
> 10.10.10.251:80 for service 'balancer'
> 8 405813s Perlbal::TCPListener(R): open: listening on =
> 127.0.0.1:60001 for service 'mgmt'
> 9 4s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791: =
> localport=3D80; reqs=3D1; xfer_res; http://url/file_id=3Df_7926310; =
> backend=3D10.10.30.101:80; responded
> 10 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4792: =
> localport=3D80; reqs=3D2; persist_wait
> 11 4s Perlbal::BackendHTTP(R): open to 10.10.30.101:80: =
> localport=3D50561; client=3D9; uses=3D0; xfer_res
> 12 43s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 13 4s Perlbal::BackendHTTP(R): open to 10.10.20.103:80: =
> localport=3D55473; uses=3D4; bored; has_attention=3Dyes
> 14 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4793: =
> localport=3D80; reqs=3D1; persist_wait
> 15 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4794: =
> localport=3D80; reqs=3D1; persist_wait
> .
> socks
> fd age
> 4 405815s Perlbal::TCPListener(R): open: listening on =
> 10.10.10.251:80 for service 'balancer'
> 8 405815s Perlbal::TCPListener(R): open: listening on =
> 127.0.0.1:60001 for service 'mgmt'
> 9 6s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791: =
> localport=3D80; reqs=3D1; xfer_res; http://url/file_id=3Df_7926310; =
> backend=3D10.10.30.101:80; responded
> 10 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4792: =
> localport=3D80; reqs=3D2; persist_wait
> 11 6s Perlbal::BackendHTTP(): open to 10.10.30.101:80: =
> localport=3D50561; client=3D9; uses=3D0; xfer_res
> 12 45s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 14 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4793: =
> localport=3D80; reqs=3D1; persist_wait
> 15 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4794: =
> localport=3D80; reqs=3D1; persist_wait
> .
>
> At this point the download is totally frozen:
>
> socks
> fd age
> 4 405818s Perlbal::TCPListener(R): open: listening on =
> 10.10.10.251:80 for service 'balancer'
> 8 405818s Perlbal::TCPListener(R): open: listening on =
> 127.0.0.1:60001 for service 'mgmt'
> 9 9s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791: =
> localport=3D80; reqs=3D1; xfer_res; http://url/file_id=3Df_7926310; =
> backend=3D10.10.30.101:80; responded
> 10 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4792: =
> localport=3D80; reqs=3D2; persist_wait
> 11 9s Perlbal::BackendHTTP(): open to 10.10.30.101:80: =
> localport=3D50561; client=3D9; uses=3D0; xfer_res
> 12 48s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 14 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4793: =
> localport=3D80; reqs=3D1; persist_wait
> 15 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4794: =
> localport=3D80; reqs=3D1; persist_wait
> .
>
>
>
> I cancel the download, and it returns to first state:
>
> socks
> fd age
> 4 405931s Perlbal::TCPListener(R): open: listening on =
> 10.10.10.251:80 for service 'balancer'
> 8 405931s Perlbal::TCPListener(R): open: listening on =
> 127.0.0.1:60001 for service 'mgmt'
> 12 161s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> .
>
>
> Let me know what else I can get you.
>
> -Sam
>
[vbcol=seagreen]
480\33\257\35\2220\25\337f\17#e\7%\253\2
3\330\21\356\321\250fd\204\241%\=
372hD\374h\214\225\16\232w\322@O\16m_!\3
75\237w)\20\n\256YF\353B\10|\231=
j7\23[vbcol=seagreen]
Q\301\37V\307\371\216\354\234k[vbcol=sea
green]
64\234\377\202\222\27\262\6\257\223J\6\3
13\344\300\331\222\[vbcol=seagreen]
67\32+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\21=
5d\35\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
23=
7,J\251\210/Ud[vbcol=seagreen]
\264\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277=
\6\225\\\f\226\247\3!qi\341`\323\rV\251.`w\26\27\17[vbcol=seagreen]
5\310\361\360D\353\353w\344L\3\341*\345\
227\3460\204\354\23Q\332\316-O\3=
01\350\270w\206t\235v\365\300r;\367\377\
220s\244\311\302\226\372\0\357\3=
025\3[vbcol=seagreen]
0\274\377\240F\364\32\250$\24\372\315\32
5q\233_\350at\324\363\320\343qG\=
32\221\345\f\272\324\t\2524\\\232]^\301\
241\220\212\241R\372\3240\360*A\=
3709}\203@\22\[vbcol=seagreen]
4\325F\326N\27,~\200\235\306_\222@\301\2
46\266\r\374\202\216\311A\2mb\3\=
213+r\201\22K\323\374'\277\5l\353\10\35
5+<~\35\\\272\320\277\323\34\37\=
345\361\335\26[vbcol=seagreen]
\r\21\340\32\326\326f\332\255\214T0%\253
,!1\212\206\374\351UE\25\274\360=
*>\310\236\262hcP[- ZW\27\0f\311+@U\305\214\2701e\10\320\5\3
3S\302K\352\3=
66\346.\314\36[vbcol=seagreen]
\200\327\r1\240iO\21\31\301\10"...,[vbcol=seagreen]
480\33\257\35\2220\25\337f\17#e\7%\253\2
3\330\21\356\321\250fd\204\241%\=
372hD\374h\214\225\16\232w\322@O\16m_!\3
75\237w)\20\n\256YF\353B\10|\231=
j7\23[vbcol=seagreen]
Q\301\37V\307\371\216\354\234k[vbcol=sea
green]
64\234\377\202\222\27\262\6\257\223J\6\3
13\344\300\331\222\[vbcol=seagreen]
67\32+\210\250&/ 8u\262\223|9\7cK\26\256\234\254\207j,e|1
\271\246.\304\21=
5d\35\327\305\342\321\267\303> \323*\265\23\16\211\365\350\346\223\316\
23=
7,J\251\210/Ud[vbcol=seagreen]
\264\"\244\376\231& M\310\243\254\240^h#\237N\345i\273\221V3
\253q\232\277=
\6\225\\\f\226\247\3!qi\341`\323\rV\251.`w\26\27\17[vbcol=seagreen]
=3D9,[vbcol=seagreen]
[vbcol=seagreen]
'\3038& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\22=
0R\20\274\201b\31\232r\370\263\240\331\3
05\30\323\3351Z\372\276>\3768[eg=
\f\32[vbcol=seagreen]
245x\206\232\336\217\261\1\362[vbcol=sea
green]
3\265W\356\233\2=3D\331\303B\264U\211\23
1\333\235\253|\217a\2[vbcol=seagreen]
#1f\276\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\30=
6\250\27\30\255\213\2649`\30\22\223\316\
351\240.\"\362e\335\201\255L\305=
\335\207\301\2[vbcol=seagreen]
\345\202\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\5\327\335=
Z\247\343y\327W\241l\277\231\375\232\262
\261\177]Mur\275\271y\223\270\20=
20\267\366EE~e[vbcol=seagreen]
V\245b.b_]\36\27_\375f\211\25"...,[vbcol=seagreen]
'\3038& \335h#\233\33z\216z\276l;\340_U\352\27%2
\33\347\217\220\251g'\22=
0R\20\274\201b\31\232r\370\263\240\331\3
05\30\323\3351Z\372\276>\3768[eg=
\f\32[vbcol=seagreen]
245x\206\232\336\217\261\1\362[vbcol=sea
green]
3\265W\356\233\2=3D\331\303B\264U\211\23
1\333\235\253|\217a\2[vbcol=seagreen]
#1f\276\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\30=
6\250\27\30\255\213\2649`\30\22\223\316\
351\240.\"\362e\335\201\255L\305=
\335\207\301\2[vbcol=seagreen]
\345\202\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\5\327\335=
Z\247\343y\327W\241l\277\231\375\232\262
\261\177]Mur\275\271y\223\270\20=
20\267\366EE~e[vbcol=seagreen]
V\245b.b_]\36\27_\375f\211\25"...,[vbcol=seagreen]
[vbcol=seagreen]
% =
[vbcol=seagreen]
..[vbcol=seagreen]
>
is[vbcol=seagreen]
w/ =
[vbcol=seagreen]
[vbcol=seagreen]
d,[vbcol=seagreen]
[vbcol=seagreen]
=
[vbcol=seagreen]
s,[vbcol=seagreen]
[vbcol=seagreen]
=
[vbcol=seagreen]
=
[vbcol=seagreen]
[vbcol=seagreen]
ll =
[vbcol=seagreen]
=
[vbcol=seagreen]
PU[vbcol=seagreen]
ed[vbcol=seagreen]
[vbcol=seagreen]
/[vbcol=seagreen]
>
>
>
-- =
Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
| |
| Brad Fitzpatrick 2006-09-16, 1:13 pm |
| We think we might be seeing this at work now too, so rest assured we're
working on it....
Thanks for the wonderful debug work you've done. That'll help a bunch.
Will let you know when I know more.
- Brad
On Tue, 12 Sep 2006, Sam G wrote:
> On Sat, 09 Sep 2006 09:36:58 -0700, Brad Fitzpatrick <brad@danga.com>
> wrote:
>
>
> There is very low latency between all three parties. The perlbal machine
> is on the same local network as the storage box, pulling data through
> Apache webdav. The downloading machine is geographically close and
> connected at high bandwidth to the datacenter which houses the first two
> machines.
>
>
> Relevant Perlbal config:
>
> CREATE POOL php_apaches
> SET nodefile = /etc/perlbal/nodelist.dat
>
> CREATE SERVICE balancer
> SET listen = 10.10.10.251:80
> SET role = reverse_proxy
> SET enable_reproxy = true
> SET pool = php_apaches
> SET persist_client = on
> SET persist_backend = on
> SET verify_backend = on
> ENABLE balancer
>
> Perlbal machine IP: 10.10.10.251, storage IP: 10.10.30.101, client IP
> requesting download: 67.180.143.68.
>
> Before download starts, everything idle:
>
> socks
> fd age
> 4 405805s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405805s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 12 35s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> .
>
> After download starts, is progressing:
>
> socks
> fd age
> 4 405813s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405813s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 9 4s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791:
> localport=80; reqs=1; xfer_res; http://url/file_id=f_7926310;
> backend=10.10.30.101:80; responded
> 10 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4792:
> localport=80; reqs=2; persist_wait
> 11 4s Perlbal::BackendHTTP(R): open to 10.10.30.101:80:
> localport=50561; client=9; uses=0; xfer_res
> 12 43s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 13 4s Perlbal::BackendHTTP(R): open to 10.10.20.103:80:
> localport=55473; uses=4; bored; has_attention=yes
> 14 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4793:
> localport=80; reqs=1; persist_wait
> 15 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4794:
> localport=80; reqs=1; persist_wait
> .
> socks
> fd age
> 4 405815s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405815s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 9 6s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791:
> localport=80; reqs=1; xfer_res; http://url/file_id=f_7926310;
> backend=10.10.30.101:80; responded
> 10 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4792:
> localport=80; reqs=2; persist_wait
> 11 6s Perlbal::BackendHTTP(): open to 10.10.30.101:80:
> localport=50561; client=9; uses=0; xfer_res
> 12 45s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 14 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4793:
> localport=80; reqs=1; persist_wait
> 15 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4794:
> localport=80; reqs=1; persist_wait
> .
>
> At this point the download is totally frozen:
>
> socks
> fd age
> 4 405818s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405818s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 9 9s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791:
> localport=80; reqs=1; xfer_res; http://url/file_id=f_7926310;
> backend=10.10.30.101:80; responded
> 10 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4792:
> localport=80; reqs=2; persist_wait
> 11 9s Perlbal::BackendHTTP(): open to 10.10.30.101:80:
> localport=50561; client=9; uses=0; xfer_res
> 12 48s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 14 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4793:
> localport=80; reqs=1; persist_wait
> 15 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4794:
> localport=80; reqs=1; persist_wait
> .
>
>
>
> I cancel the download, and it returns to first state:
>
> socks
> fd age
> 4 405931s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405931s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 12 161s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> .
>
>
> Let me know what else I can get you.
>
> -Sam
>
>
>
>
> --
> Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
>
>
| |
| Brad Fitzpatrick 2006-09-16, 1:13 pm |
| Sam,
When the download stalls, is the Perlbal consuming near 100% CPU as well?
It looks like it could be. The ClientProxy is in RW state (waiting for
readability and writability), and it should be writable non-stop when
it's stalled.
In ClientProxy.pm, find this part:
sub as_string {
my Perlbal::ClientProxy $self = shift;
my $ret = $self->SUPER::as_string;
if ($self->{backend}) {
my $ipport = $self->{backend}->{ipport};
$ret .= "; backend=$ipport";
} else {
$ret .= "; write_buf_size=$self->{write_buf_size}"
if $self->{write_buf_size} > 0;
}
And take the write_buf_size lines out of the else block. (not sure why we
only showed it mutually exclusive with having a backend....)
Also add something like:
$ret .= "; stalled=$self->{backend_stalled}";
And can you get me an strace of the Perlbal while it's stalled?
Is the PERL 64-bit? Which version of Sys::Syscall? Does its make test
succeed?
If it's not spinning CPU, then the question is why not: we want to know
about writability of the clientproxy but if we're not spinning, the epoll
support (Sys::Syscall) is broken. Historically we had problems with
64-bit, but that was fixed quite some time ago.
- Brad
On Tue, 12 Sep 2006, Sam G wrote:
> On Sat, 09 Sep 2006 09:36:58 -0700, Brad Fitzpatrick <brad@danga.com>
> wrote:
>
>
> There is very low latency between all three parties. The perlbal machine
> is on the same local network as the storage box, pulling data through
> Apache webdav. The downloading machine is geographically close and
> connected at high bandwidth to the datacenter which houses the first two
> machines.
>
>
> Relevant Perlbal config:
>
> CREATE POOL php_apaches
> SET nodefile = /etc/perlbal/nodelist.dat
>
> CREATE SERVICE balancer
> SET listen = 10.10.10.251:80
> SET role = reverse_proxy
> SET enable_reproxy = true
> SET pool = php_apaches
> SET persist_client = on
> SET persist_backend = on
> SET verify_backend = on
> ENABLE balancer
>
> Perlbal machine IP: 10.10.10.251, storage IP: 10.10.30.101, client IP
> requesting download: 67.180.143.68.
>
> Before download starts, everything idle:
>
> socks
> fd age
> 4 405805s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405805s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 12 35s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> .
>
> After download starts, is progressing:
>
> socks
> fd age
> 4 405813s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405813s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 9 4s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791:
> localport=80; reqs=1; xfer_res; http://url/file_id=f_7926310;
> backend=10.10.30.101:80; responded
> 10 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4792:
> localport=80; reqs=2; persist_wait
> 11 4s Perlbal::BackendHTTP(R): open to 10.10.30.101:80:
> localport=50561; client=9; uses=0; xfer_res
> 12 43s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 13 4s Perlbal::BackendHTTP(R): open to 10.10.20.103:80:
> localport=55473; uses=4; bored; has_attention=yes
> 14 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4793:
> localport=80; reqs=1; persist_wait
> 15 4s Perlbal::ClientProxy(R): open to 67.180.143.68:4794:
> localport=80; reqs=1; persist_wait
> .
> socks
> fd age
> 4 405815s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405815s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 9 6s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791:
> localport=80; reqs=1; xfer_res; http://url/file_id=f_7926310;
> backend=10.10.30.101:80; responded
> 10 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4792:
> localport=80; reqs=2; persist_wait
> 11 6s Perlbal::BackendHTTP(): open to 10.10.30.101:80:
> localport=50561; client=9; uses=0; xfer_res
> 12 45s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 14 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4793:
> localport=80; reqs=1; persist_wait
> 15 6s Perlbal::ClientProxy(R): open to 67.180.143.68:4794:
> localport=80; reqs=1; persist_wait
> .
>
> At this point the download is totally frozen:
>
> socks
> fd age
> 4 405818s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405818s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 9 9s Perlbal::ClientProxy(RW): open to 67.180.143.68:4791:
> localport=80; reqs=1; xfer_res; http://url/file_id=f_7926310;
> backend=10.10.30.101:80; responded
> 10 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4792:
> localport=80; reqs=2; persist_wait
> 11 9s Perlbal::BackendHTTP(): open to 10.10.30.101:80:
> localport=50561; client=9; uses=0; xfer_res
> 12 48s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> 14 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4793:
> localport=80; reqs=1; persist_wait
> 15 9s Perlbal::ClientProxy(R): open to 67.180.143.68:4794:
> localport=80; reqs=1; persist_wait
> .
>
>
>
> I cancel the download, and it returns to first state:
>
> socks
> fd age
> 4 405931s Perlbal::TCPListener(R): open: listening on 10.10.10.251:80
> for service 'balancer'
> 8 405931s Perlbal::TCPListener(R): open: listening on 127.0.0.1:60001
> for service 'mgmt'
> 12 161s Perlbal::ClientManage(R): open to 127.0.0.1:38802
> .
>
>
> Let me know what else I can get you.
>
> -Sam
>
>
>
>
> --
> Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
>
>
| |
|
| This is long, but you may want to scroll past the strace output onto the=
=
Syscall stuff.
On Thu, 14 Sep 2006 12:13:19 -0700, Brad Fitzpatrick <brad@danga.com> =
wrote:
> Sam,
>
> When the download stalls, is the Perlbal consuming near 100% CPU as we=
ll?
Nope; it doesn't appear to be taking any.
>
> It looks like it could be. The ClientProxy is in RW state (waiting fo=
r
> readability and writability), and it should be writable non-stop when
> it's stalled.
>
> In ClientProxy.pm, find this part:
>
> sub as_string {
> my Perlbal::ClientProxy $self =3D shift;
>
> my $ret =3D $self->SUPER::as_string;
> if ($self->{backend}) {
> my $ipport =3D $self->{backend}->{ipport};
> $ret .=3D "; backend=3D$ipport";
> } else {
> $ret .=3D "; write_buf_size=3D$self->{write_buf_size}"
> if $self->{write_buf_size} > 0;
> }
>
>
> And take the write_buf_size lines out of the else block. (not sure why=
we
> only showed it mutually exclusive with having a backend....)
>
> Also add something like:
>
> $ret .=3D "; stalled=3D$self->{backend_stalled}";
Here is what I have changed it to:
sub as_string {
my Perlbal::ClientProxy $self =3D shift;
my $ret =3D $self->SUPER::as_string;
if ($self->{backend}) {
my $ipport =3D $self->{backend}->{ipport};
$ret .=3D "; backend=3D$ipport";
}
$ret .=3D "; write_buf_size=3D$self->{write_buf_size}"
if $self->{write_buf_size} > 0;
$ret .=3D "; stalled=3D$self->{backend_stalled}";
$ret .=3D "; highpri" if $self->{high_priority};
$ret .=3D "; lowpri" if $self->{low_priority};
...
>
> And can you get me an strace of the Perlbal while it's stalled?
Okay, this is a big chunk, but I'm not too sure which part you might wan=
t:
read(14, =
" \306\341=3D\7#(\320\274\354\37r\226\37\2
21\352l\376!\347\220\210\265\37=
4\364\0279-\223\234\277\310qT\340\26396E\0264B{%\32\217\356z{C\256_6\241=
\n\t\215^'\ffn\366\3423\202/\315?:\2602\363\277\27\240\374\205\261`\363=
\246\357\313~u\264 =
\222\323& #91;M4\3ig\203\361\5\352f0\251\0L\307I\3
12\261\212\t\23\361\24\30\3=
74\360ej\2545lCJJ\300\30\241\211\257\363
A\264|)\202(V\353\3373&\260E\347=
\313\207\371\332\370\270\344\370\356z\25
7g\233\271\26\177\243B\32.\240\f=
\220\226\216\276\212\327\364P\360\376\27
5o]\314\223\211@\260\255\345\256=
\354\r\376\225W\371\235\263\232\324\343>\240e\223\366\375P\250\315\"\263=
\322\237\236n$\205\21\205\353I\22:\326\2
41\262\343\3748s\264\260\221\244=
\27\307CM\326\217\31V\345\271\332w\335\0
029\237\21\210\341\232\303\216?\=
301\10\4\342\220\315\261\201\362\260\213
\265cM\211\f\321u\211\360\317F\3=
73\222\335\1\300\313u\27\2T\213L\26\205\
227l\323_\207\3277\363zB\344\254=
L\302\215\4\212\347\26\300\314)\345\30\3
03\27\313>U\3124\230\245\270\324=
S\7\263\227\335\261\362~\373\33\350\305"..., =
61449) =3D 7165
time(NULL) =3D 1158283301
gettimeofday({1158283301, 60893}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
"\31&\20\250a\206H/ _l\377\177)\20Q`y5\370\206\353\323XB\261
\262\372\333\=
360\315~\224\34\355}\244\363\360\7\22\37
4Y\202C\321\324\"E;\326E\253:\22=
3\364S\315\363\307!*\27& \n\274rE\214p\212\351o6\372\251\214\375\
364x\201=
\241\364\252\364\350t\264\r. \364Q\v\375c\221\271\366\256)\372\235E\3
32`\=
312(\264\36\343$\317\316\" \205\215+\342\5\224v%\337\34U\305\372oh\
360\20=
1\2A\205\303\345\316\323\346\331\210\272
\277\244zb\321\302k\256\177\223\=
376\325rR\1)\331\5\215\344\2370p\366z\16
\261\3750\32\23\210x\335\204\rK\=
370`\303\243\" M\273\246w\253\346f\373@\3260\305o\1\306
7\vQ\331q\267V'\3=
2F2\233:> \337\360\274B\341\215$\307R\300\317~\367
\f\310\346\\z\333\254>^=
'f\267%\353W_\222\216\vo|\345\332<m\20z\25\366\265\335\334>\354\311\237=
\343Z'C\317OI\17#KO;\314\305)\347\310\2
55\25\325\370O\312\325\177R\2161=
#\0249\327\25\250\231> \346\254@}RXkt\343Hym\331\365\314\346\35
4x\4 =
\214\36\232\365\374\2513\35\335\330\305\
256-\n\211\1\33\213\245\234\233\=
337\275\177\373\337\tMS\275\2451dq\233H\
2445\2c\v\220Zz\240y"..., =
61449) =3D 5792
time(NULL) =3D 1158283301
gettimeofday({1158283301, 61201}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
" \363o\266p\23\355\7\201\340u\17v\345\365
\27=3D6\327\t\225v,\224P\271\36=
4V\237l,\255h\215\217\24.\231T\350.Pe\0\312\03392r\321CK\213\334\241\30\=
21R\345e\223\325wPA\320\27\362A\215\251\
222\237>\"\336\305\227d\302AY\23=
1)#\275~\305W\10Y\300\n\" \32^\277*W\177\257y\330\362\203!\265\256
\371\30=
5\315\246mc\373$. !\255'\7z\2304\\o\34\354vvS\17\226\34\2
50\24\203\237\3=
00e\204\303;a\244\320epaz\370\207\\$\24\
f\207\261\226\34\277\267Ux\24!\2=
75\215\fH\35!\320T\376\370\34LRsf\235\22
6\337\4\201\214R_\251@\276{\336\=
205y\322AS\16\370\267\227+i\220\20\31SsV
p\327Q\227$\244}fO\367\314\213p~=
\233\373\204\327\341\313&\342\27=3D\250U.\3228\27\233\221f\343g\231Rv=3D=
\204\334\24\232\247\306=3DZ\354n\235\342
e_\233\271\262\341\316\267\365\3=
17\217i\345\262\32ly\2032u\33|\314\376(\
273-X\2079\343\211cJ\352]s8,\276=
\307e\26\314^&i\371& #123;\304l\355\262\2701'x\6\225\361(\33
6\343Y\365\177\32=
7\267\201|& #123;O\203\274\372\325\344B\6\357\224r\3
65go\27\3179\23z\274\277> =
=
\304\337 \343\310. \334\245\362\324\326\266\300\n\3260F\200
JJ`~\5"..., =
61449) =3D 7165
time(NULL) =3D 1158283301
gettimeofday({1158283301, 61511}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
"hv?\21\375\5`\360\25\\\25\\\f\362?\177\350\371\275\352M\343\341\26\205<=
\334Y9\314\376\326\f\340\235\217\353'\3
6\33G\324\352\244/(\340\326\37w\=
345\205B?/- \276\253\252\227vOJ\270aG\253J\365~\262\
323\310s+=3DfrM\367\3=
64\310l\v\314\20\267\337k\320*|& \217\236\204Ed\323G\211\315\302\35\0270\
=
236\241\310Q\374=3D\262\36\331\" Y\0=3D\267N0\345)\204\376\242\32ZQ\2460l
=
^\351\3076\25\f\r\317\270\216\33\350\216
\327\34\361\\Y\261d\17\21\342\30=
2\373\361\223\376\27\275D\271\272\205\34
6M\301\342YD\6\342O\332\333\337b=
\242\371\2754J\361&\10\255s\362fo<G\214/\213\215\3041\311\215>D\\\274X\2=
70\243\241K\26\312\371f\350\24\211\324\2
60\212\223xO\201\"\31\345f\201\3=
27N\361\3328\24\3\273\336\360\16\362x$D\
301\363/Y)\220`\226b\210\222\334=
\f\227\354. \322A4\344\276\5j\234IG'\333\312\366\25
1\216\342\277\26j/\21=
5\n0\224\325\276\346i\366\21\211\206\v\2
05\217\231ms\24\321T1^\372>\236\=
352[\220-[\211\257l\232t\356y{\27\264\255iz\343\342,\353E-\347A\233\364\=
353`\214Pk]K\36\223\tA\36\324\360\205\32
1\270\343HP =
\311(J1;\265"..., 61449) =3D 5717
time(NULL) =3D 1158283301
gettimeofday({1158283301, 61843}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
epoll_ctl(5, EPOLL_CTL_MOD, 14, {EPOLLERR|EPOLLHUP|0x20, {u32=3D14, =
u64=3D14}}) =3D 0
time(NULL) =3D 1158283301
gettimeofday({1158283301, 62018}, NULL) =3D 0
epoll_wait(5, {{EPOLLOUT, {u32=3D11, u64=3D11}}}, 1000, 1000) =3D 1
time(NULL) =3D 1158283301
write(11, =
" En\305\212\203J\2522\2631f\320\365\31\26
7\354\275\24\371\337a%\226,T(2\=
305\355'\246/ =
\26I\334\267\37ar\305\337\314\362\312qSS
7A\27\362P\233\234\207L>\30\255\=
35\323\262\3!\334\21\5\363\367g\234\177\
247\3-\353\222\22\217\265\322\20=
64*\271d\276{- \26\32\202y\236\253\371\346c|\231\260\35
1C\355\263\324\352=
\360\341? \377*\267l\274xL\344d\37w\354\270\372Z\2
61\342\214\10\233V\275*=
'\\\356\304\34Q\332|\274{I1-\326j\17\f\326qI/\336^\247\232\4F=3D\215+\3=
62\343\203- \237cWNh\207\25\332\240Kd\255=3D\320\236
\332\3267\6\324\23003=
T\376p\266\261\34483\213\37\205\365\220|
\371\32\2229\235j_\\~\24\322\211=
!a\221\277\241j\22\213\217\300\27\331& #123;\370\2=3Dv\315\267,\347S\301\246\2=
74wM\32\177\224G\2615\r\376\v=3D\212\346
]\356'Ar\26\251\30|\200(\222W\3=
11\247ox\23\347N\336i\2521\32r\370\333D5
\325\7\2431\3239\337X\235\320\35=
4\206\360\226\256M\317T\342d\364\267<b>\274\325#\r\r\222e\254\25\355Jx\3=
0U\376\347n\344\361\301JI\330\21\355i\21
=
R\326\32n`\366\315j\f\261\361\323\263\31
5\217\223yMbT*\322^5\246\305\362=
\366WC\237"..., =
5611) =3D 5611
write(11, =
"\346~\325\273\2667\336}\311\2723& #123;\251O\210sL+\343\335\35J\240\253\24
3\3=
4\311=3DZkJw\215\212\340\7\224$\257\305\
33\323\305\v\344\212\251\231k\37=
5\263\\\16\1A_w\0333\320\271\200e4O\374\
f\224\354\256\363\232XA\35\0244,=
Mw\325>\322\203t\254u\17c\251\315?\274\266\"gK\224\213\325\\tM><\240\254=
_'I\335q\253\264\343$& #91;Y\310\24Ya\344\4\273\0176\2526\313$\
320\353H\26I%=
\236& #123;\354\211]8\211\352m\32\315\2506\331
\3\3\16G0\nh\310\355\224x\270\23=
1\345\362\320\33\317\370D\345wm&3\346u\31\202h\5\253\342\370#[88\312\255=
v\253\313\207\324\376T\20627\363>\267\217\220Jp\256\34\263\224\222?;\31\=
335\303 =
0\354\304\r\257\312\313\2745\20Tr;\223\2
21\361\3671\326\334\336\320\324\=
370l. \223j\37P\367+\f\277cwA\340\16e\367\f\22
6!\315\24\200oX\33Y#YX\354\=
327\37\343\374\226~8\r\375s\325\224.\245C\241U\246!\227H\16\366Y\313\374=
8\373\314l\21\371\350B& #123;\177\351\243\5\212\275\234\200\303\
310\373%\326\2=
57\223\352+V\3551G\206\306\306G\306\211J
\357\372\351>\17\363\231\221\261=
\372\271\270\230OO\335\261\301\362\245x\
0h\35\350"..., =
7718) =3D 7718
write(11, =
" \250\01674\340\261q\271\215\272Y+\350\25
3\363VYr\340V\r\334\242\217\314=
A\35]\260\251P\223\17'\255'\350\226\34
0\357\37\207\362|\344G\201\357j\=
351\337\324g\v;p=3De\" \374\264\16}\371\4\224\22\t\25\211\5\340
\322\377\3=
41\237'\17\225\201uP!\v\305M\306\362\34
0\262\224\231\222\354\2526\22 =
\376VjX*(\222@OK@^? \310\205\200jR\25v#\363\202\22\272|\213\
0374m\rS\31\2=
71v\225\22Cu\341\315\325\0274\340\355in[\24\\q#\324mN\235\303!\347\232\2=
61;\310\363\7\333\357\267\246nZq\2`\30\2
5&\240\262!\3\n\320\20\274\23Eu6=
\371\364\274V\23\234\223\360\33\306P\200
u%\246\25)\3633\263\n\336\3535\3=
23sE\21\251\f\206\22\376d!\24^\327\373\2
01\256\245\20?q\340gJ\253\206A\1=
779\02106\255#\216\220X\313\2\202^\10N\2
57\244\332\245\275\4\231n\370@@\=
375 =
5\4\240\265\304\315jgj\\\5l\314\30U\373\
250\36\237\367\250\313w\32\312\3=
41\303Tmn\241\203& p\366\362\267\343\271\33\363\306^\263n\3
5T0AN(\266u^\3=
34\2740\370!\24J\206\246m^H\337&D\274\217\225\324\311.N\342H\333a\343|\3=
61|\251;\346\266\224\361`\314\333-\4\20\321\352;\343\256"..., =
7718) =3D 7718
write(11, =
" \274\360\256]5\6a)\363\310\375c^\321\336
\307\220\275tE6\325f\376\364\37=
0\370W\371\317M\355\207\r\261\232\306\34
3\202\1\276\216\347\224\362\267\=
26\352\3725Ps\237\233:,\366tH\273\263pZ\
235\224@~1\261I_\256m\330~t%\\\3=
72\7\204\330O? \360_h\343QK\345\302\2r\331\351\317\221Z
\22\376\240\30<O\2=
17#+\301\v]e%0\343xl<e{}\243\225\225\226{\356\216\211\"\261\27\5x\220\35=
3\227\265\t\3236\265_\207\257\270\363<\226\333 =
g\307\264\3209\177\247Y\276\303#- \352S\323^\10)wQWs\301n\266\244\371\277=
\23+<\203\256\332\242- 9\324\250\355i\306\204\21\24\16PXM\247\f
\n:\242\35=
0\264\205\3737\324\375\311\t\251\356C\vA
VZ\212x\375\30\337\240s\252\313]=
j\245N\327\317!HJ\323wS\237\267\357\20\1
\v\373Y\313\232W\357\\\227#\336\=
215\357~]~\36k:~\240\235Ng\310\333;\267\
203\226\306\34g\371\5m&\250\2058=
A\312n*C\271\204\n\360\226f)\227\225H\31
7\344\202\211k\255\33\365\205u\2=
6\346\307\354$\242\345\241\204u\30\n\334
\2703l\247\336\207v1.\342\33\243=
L\212`\314p!\366`hj%\246\351v+\205b3Q\37
1\360\f\214AZ\272\361\221\37\t&\=
327\337B"..., =
7718) =3D 7718
write(11, =
"\277I=3D\330\212\355MN\232<\266\207\"\206\252[\352J\344Vrh\205\375\202\=
244\337\214\266\325/7> \205\234~\306\367\3\212]\314\333\364\16\
220\274_\3=
55oGbV\6wN\214J6N\37\266\356\206\345\236
n\320\205\341`\330\234\242L\1\21=
\302\270\v\270G)^mp\16H\255 =
4X\322\34\33\226\37\271\317\360\206P\251
\244\237b8\376\2307)\260p\207\32=
0\242& \324w_\6\344\236\24N\2004\23)\246\200Tl\
267W_\373\372\213[\240\240=
]& #123;\f\375;\5\6\30\n3\347K\213E\365\216
aIE\224\334Ci1\254\212P\346e\372\fk=
\272\267sQX\20b\3731\305- \306\231\345$\345\37\364Tq8nT\t\27\1\360
,\207*\=
215W\253\367O\337\237\311\224o\271\361o\
331\2676\307\346f\275@\262\317>i=
\335\345]\37Y\203g\f\7x\3126\326\r\22\21
2]5\261\322\250\211\247\335Qf\26=
\356\260\276\200\22\2036\305\27#\0370\23
5{\343g\274\205L\243\320\334\31\=
357\357LM\323\307\256\305\316<P\226|2\30\215?-x:\371\237d\36\373>\347\35=
\322\205\26\363\r\231\353\254\251\26\211
j\200d\1C\\\24\215\213!t\303j\35=
6\30
3\2E\343M\215\10G\254\235\260\311\23_\24
2\3537\353\320\325\314\214\260\0=
164l\347\354\377\212\276\354"..., =
7718) =3D 7718
write(11, =
"n\0{\277\212\33\327]m\2434.5\225\31\373\250>\255V\306\301[nZ\234\6uRzJ\=
352\243A!\241j\21\311\372l\36\346!\16en\
360&2\244\321\4\266\251O\v\n\365=
bd\221\374\201\230\377B\16=3D\357R@\226\
\1x~\206\332\200\24$h\233\264\26=
1\
365z\202\352\353\307\244\212\306B\317\34
1\321\264\3156\311\0176X\204\201=
\355\2211\217\fG\251o\352C\262\376.& #91;\17\32\375\316\357b\220\266L(*\6\264
=
S\31:\324\334\321\242\327\252\300\214\23
x\331\306\260\315\322\364f\315\3=
21\207\274
\345\337q\271I5\235#e\200C|\214\303\232=
3D#\30OCV\367O\310q2\202\370~\33=
g\220W\362:Dr\273\241\207j\235V9W\304[O\271\2o\177\r\220\336\271@\374h\2=
51\313\325+\23\265`\316\24\323\7\31)\204
\20~\233\214#\260WhXA\210\211\24=
6\365\210\36
3Fwa~\256\323Vk_\321\374\374\25Ub\\\262K
b\322\324\243G\214h\346\350\342\=
5\313f~\37\223\311G\250\242Z#\256\331M{H\5\v\276E\303\366\334z\325\177A\=
255\351\266\346\264d\10\226\254\210\234\
260\256\222\204\35\271M\240\215\=
317\16[\23
6\255\3225\246\24\250\16\253\270_\353p!\
253c=3D\213j\10F\306I<\2759'DF\=
334.\205\16\253\17\221\3444"..., =
44715) =3D 44715
write(11, =
"\374\245V\270\257\301\36\"xQ9\33\2559\342<\217\203\0\10<\357}cu\212\n\3=
65\17\272\234\254xl\26i\372?NN\264\37\301-\346\241\227\353\330J\264\376\=
240\23\352?7;S> \367'\351\345\r\25\304\17\214\245\2613)
\247\3H\245\277\2=
41\177i\333i!\377\302g\211\n\243\206\376
j(b\325\352\211\216e\34h\303e\32=
3\2603\314TZ\21F\321\212?\5#|\33\231_\266:9\351\227 =
\21\2762\2625\345\317\301\242n\263\352u)
\345\314\17\22RQ\211y\216\261`\2=
75\360L-l\7i{\366R/\363\210k\3
67\350\3108\346\277n\344z1zn\315\251D`\3
558\203%O\34\335\210\t\2E\352Z\2=
34PT\231\254(v\223&&\7<\365\224\34/\200\331\320\n\n\254X\331\250\200=3D\=
26\201\350\353\343\7\230u\240\274%h0zT\3
46;>\350\233O&\232V\261/I)mm\330=
\276\343\35\
222ye\252\2540\361\3735\3327\344\214`\34
0\213\3444\34\320\25N\263\220\26=
3\225EN\1@L\312\377\220K`< \372\373D\v\336_\310\376\266\314)S\232\3
36\324=
S> 0\342\227\210\206\r\324\324\370\302\243\
357\251\333\246\230(cG\316\366=
\31s\302\2
42\204\351e9\364\366\226\362\356\350.\364*w\366\25\265\260/\313\367\317~=
\n\376\\'\337\253\265\216"..., =
9017) =3D 9017
write(11, =
"\327\333\374\347H\222\22\4S\" \273\360O\337\225'\333\31\370\27r)M\244
j\=
377E\271B\372\236\\S\17\16\246\1\354\201
\241H}a'8\4J\316\256\301\300\21=
7y\366\306\26\361\263\10\22\253? \215\260\331\212\350\224p0\363\320\222\1
=
6\244Av\337\26j\2658>\23\214\252W\310jI\3659-\206\323\r\27\266\245J\352\=
273\20X~\221q\246e#\212t\301\371\345-,\323L\210\264(2\233\241^il\264\333=
\v8 =
\232\341\20#$\246im#`\334\261\342!\\3\20
6\372\266\301\356\325\264\236\27=
1zB\22
1\340s& \260\230\336\r\207\326\200\333\37\257\26
4|k\347\334T3#\273\203\32=
50T\264s\305z;d\227\313\26\306\31\332\21
2\25=3D\37D\300(\310)\3\326_'DP=
\246\304\341\240\200b\322\204t\253\233?\377\214\227\214\364\vJ\326\276\3=
43\332\36*\n
\244F2\370sJ\267> \345'\207Z8\224\312\203\2456o0\202),\21
0\242\fq8\266\3=
76\314# =
x\26\237\305ZY\26\317\240+\225a\336\274\
'\235\306LC\213\365\211n\23\336\=
341\20\255K\353\334Q\3174\0\240e\361\"\311h8\343\222\223\251\337\353(\24=
0\
222sq\265M\274\f&\16<C\342\375\363\307=3D\362\354\373^ =
n\336ge*\16CT\305\370\254\0036Mt)O\257\2
50\177"..., 8688) =3D 8065
epoll_ctl(5, EPOLL_CTL_MOD, 14, {EPOLLIN|EPOLLERR|EPOLLHUP|0x20, {u32=3D=
14, =
u64=3D14}}) =3D 0
time(NULL) =3D 1158283301
gettimeofday({1158283301, 170607}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
" \332el\213\375\r:\375\346\304\366\240$\3
11\343\320^\22?\351wr1bS$~U\10\=
334\216\253\316\26\310,~\350x\352\271\27
4\257\302\200\307}jt7i\310\201\2=
23:\350\34\200\247\346\r:o\21\22\25\256\
364\344\250x`j\333\213\310\261M\=
'
\30:I\265K\261;\371\203\303\361\310\313A
\264\267P\261l\276x\314Sxoo\232\=
225\2246\266\224EzQk\221\271\270\206\236
\370\324]\260\27\354\273\207\25\=
347\275@\342g\312C& h\335O\\\351\377\272\265+\372\304\233u|\
300y\371\305\=
v\352\327a
\17\3510+H\356\307\21\371n\274S\360`\337
\22U>\216\277\\\303x\363\260\300=
^\300/ \263P\347\v\205B\227\214\17Xl\323\357\33
6\243;\252q\365k\354iXV,\2=
24\211X\315G\374\16P\223~\330Q\236\262l\
36p\16\223\306\30=3D\25\325\334~=
\273\263l\23
4M\240XO\344e\250\353\230P\34n2Z\315\17G
\22,\334\\\336t\320\31\345o\242\=
306p\355\252\375\203\24\226\351\362G\347
`\213)\225\261\213\370\306\310\2=
05\317n\321>\304\265\tR? \232}I\360\322\354\377\274\364\236~\273\
371.\242=
[W\265\323
z\255\36\317\f\336\374\342\26}\254\274\3
37Z\37\217\213w\22t\300\244r\330=
\2367\fy\250\271\374\217"..., =
61449) =3D 43285
time(NULL) =3D 1158283301
gettimeofday({1158283301, 170955}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
" \363\314\3111\364\35\277\345\214Z\217\32
4D\203w.6\213E\207\252&&S?\214\=
334\354\276R\331>\37\30\255\235\270.\\\275\376\225\\\374\27\370DY\r[B\35=
7\323l\206\314\34K6\320\34\210T\363t\353
\244\335\247\230\261+m\317}\362\=
2
54\353d\343\325\263*? \222z\2159@8DU3\243\220\372\36561\364\7k
d:<;\1\274(=
\322\260\223\370\226\311D\n\215J]\3723\3
11|\225\271X\323qM\221\264\233y\=
207\373\27\331B3\211\342\324\365\357\355
HY7\362\274[#';f<_\356\360*\250=
\240~\336\
325oT\333F\374\"{@Q. \315$$\246\v\37\217'\232\21\375\366q\20
\2632\226\21=
7\307\20\352'\31K\350\241Y\\0gMW\30\212
\275\v\266iK\361\200\375\333\306=
\332\2067s#\345\326\272\237&\31*|<\371`\337:^M\16\322\3356/\377\210b\354=
\340\352\3
74[3? \2030\203\24\330\342\26(\25\242\236I\315
\212\3578\213!\n\22\215\363=
\216\370bmnX\314\362\5& #91;\2278\237\\\262\347\7\277\330\240\23
3\244\306a2\3=
5En\317\7VU\262\34c\355\360\254\2241\332
\370\6\206\356h\"\345\210\235\34=
7`\231QM\0
\201\367Q\236\257\365\345\2\274\303~\311
\311\16OH\213\233\275\364^k\27\3=
6\264\27f0\313\5z`\311\326"..., =
61449) =3D 7033
time(NULL) =3D 1158283301
gettimeofday({1158283301, 171370}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
" \21\355\351\344\243,%\252T\7\245X0\245j\
201\34\275\335\261\366\312\206\=
0\23\356\243\246\220\6\367\224Hb\314\34\
33\303\6]BLA(~z\v\33\253\260gc\1=
77\336,\270\275\222\314\\w)K\330\224\211
\273f\366Q~\266\241c2\300u\316\3=
0
2\331\302V\317G\371\263\301Q\36Z]\357R\2
01\232\222g\257\326\363(4\\\225V=
S\255\263\257\325\263\256\22367z\22\2230
qB\231\347@\246\206+>!\2712iQ\22=
4\361\275\265\217h\370x\270iE\302W&Fqn\3o?R\303<\347Y\227\210\311\"sJ5*\=
10@\245\30
1\246Z\201\231Nm\r\"Hw\251\352\367\321\vH:<\231T\256\4\245\240\247/pq<+\=
352)\237\265\322\rG\314n\314i\357#\311\2
16m\230\220'^\25\215\310G\242)^=
\3\265\266\223%t\20 =
rq\37\2\241\202. G\354\364Tc\342\21\23\362\251L\212\33\n\
10\225
,\210C\273v\nQ\202rF\334\267T\202*:e\n\3
22\262W\351\263;.\213k\345\10\31=
0\3632l\324\202~Q\231_\233L\207\354?\221-.FmV\353N\315Q\266\37\371Oh\31\=
254\247]\272\324/=3Dm6\36\274\0325& #123;\257t%\202\331\315\177:%Z\265\0250a
\2=
57\32\200}\3
36\347\240\317=3D? UT3v\250\324\205\253N'Q\34\367Mh\34M\23
1%0\227GB4mI\3=
46\274\352\336-\364Z\37\0\n"..., =
61449) =3D 5792
time(NULL) =3D 1158283301
gettimeofday({1158283301, 171699}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
"\300j\350\207G& \354\2100$\5\203\302\226\320`22\2\243\v\
0321K\225N\260\2=
46\321\201\347\360\347\231\357~\353\356\
206Bv\2007\227\236\232/\225\312\=
213\32W\337\226*\370\313\223\302A\223z\2
60Iw\035174\374\223\335$J`>\375\=
3
33\210xr\344fg\r\343\206\324\371>\370\276\305\376{iU^\271\4F\204m|kzd\30=
1\266\230SEa\36\255\367Xt\327\370|\207\3
27\355\310\2n\332\245dV\316\307L=
\324jW\331h\322\216\6\275\n5\231\265\0\2
7\255\357\212\262s\213\35\v\353\=
201\207~\3
45\302\17\262\234\237\220\312\355\261\34
\264\377f\371G\230c\363;\243D\36=
5E'\241\306`\26~\320\271\203\35\227,'\
276\231I\346\202\303\216c_\344\7=
#\366\253\323\337M\277E\326\264\20\37\fH
\202\362\306i\2254\17\3217\375m\=
346\306.m+
!\25\31\234\373E\376e\314\214\246a\ft\6\
243\352\225\353\32\240\245\240, =
=
W\3os\16c\210\304\340\355\35\335\333\212
\36112\\\374Rd=3D\322\205k4\231\=
205\252;\201\205B=3D\356\273\227W\241x=3
D\233\307\215N\304\3373T\237\277=
\224\27\225\361\
250kp\315\302\2Zh\234e\260\1m\350X\310\3
57\344\257\251\210\247B\31?\354\=
313\303\310\315\322\205\366"..., =
61449) =3D 7033
time(NULL) =3D 1158283301
gettimeofday({1158283301, 172014}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
"Y-\4(\367\16Z& \26)\273\211\3672\354\256\307LL\243E\251
\214X\216p\205\33=
6m\t\314a\216\6o\221\17\223Q\255_\263?M%\325Y\243*\320+\"\361\260g4\232\=
216k'\355.s\230\342\347\2215XN? \2\314\212\222\261\261%\353\372\253\200\
=
3
5\6\351\fe4\234\235\372\246\205\244\335I
T,k\n\vc\0\17\307W\310{S\305\377=
\32\366\336s\362\336]\254R(D5nGx\22x\223
c0\257\327A6\216Q\202D;\221\245Z=
\357,\261\237~\323\37\276\233\0\325#\234
IBH%\235V\237\224K\277Q\344\340\=
27\331\213
\255\245f\270\31+jv9\3033\306R\342\276\2
43\232\375\256(1\35\301tU\0018y\=
31v\251H\253\10\36\37\4\221-s\300\312\246`\347\321>\315c\2348r\25\2\235\=
202\241\214\315\371\363\254b\277& #91;]\374\237\372\302\337eL\233\257\357\
357=
>\352\216\
324\1\205\324\37=3D\27Z\221\346\22\212g\
16\240\235\325\16\311xk\213\7?\2=
06\321J(\273\343v7\2\377\347^nTK\343\350
H\3166\202\216\240L\210\16\224H\=
247\241QI\305T. EA\337xS\347\322\327aa;\311\36\350\260\2
15\276\240\366\27=
6P\355p\212\
200a\2\246\334\266e\357sM\214\302\377\34
\321:3\323\np\264\322#Sh;\32\365=
\263\242\223\365\23405\265"..., =
61449) =3D 5585
time(NULL) =3D 1158283301
gettimeofday({1158283301, 172329}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
"\nnmq\240h'\250B\201\306]\27kZ&\304s8S&\273:\237\\\217\0\223~^7\370\24=
W\224\326\217.s\376\317\334\370k>\323\266\206\205[pz)\267\345\364\226\tP=
\232\251\246S\v\" \233u\321\366\334\307\237\366\363\305A\3
30 =
a\0h\321D\37\
254,\206(?%\35\2MF\272\205. \337\230`\212\26\356\366\351\247\336\307
?\373=
\332\332\320\344\243\202\243\213\333\335
\242\206\231\23g\276\313\351\351=
\353\205\27\3\26k/ ~\347_\327\337\3741\235\364\200M\243+\37
\315#\220Ta\2\=
262\366\31
vT\t. \221\314\f(L\272\261\363\234|\221T\237\1
6g\35\302\7M\311gU\226q\343=
D\177\256\243\252\234?\212& #91;\330\305\217\261\333\322\355\205\240
\10H\203#=
\0\"\332\201_\253\37n?#\344< \234\370\35U\356|\251\255\266\300\2774\3
77\3=
31\6\213\3
34w\30\346<[\33\234b\6KTx\267\242\237\1\270{\277\300\246\373\177\221\203=
YS\322\3707\300+\336\246-& #91;\350\24\4~\345Q\253\24\212\251\377Lr
\354\32V\3=
47\356\233b\22)\354W\337\300\235\245\377
\242\327\316\223\276\226\371\356=
\275F\362\
305(\225\371\203\354\10\25Xj\6\300.\21x.\310\26j\31\242\256\20U\303)\252=
\200g6\334;\200\255\274v"..., =
61449) =3D 5792
time(NULL) =3D 1158283301
gettimeofday({1158283301, 172641}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
" \5$l\212U\364\303:!\366\27\272\10i\27U\2
72\240\216\204q@\3042\235`\210\=
245F\4\247\345\\4\36\361\3609[C\20\232\255\335q\345\21\"PQ\267,\211\220\=
262\323C\201\240~\" 5x%\272\306\2\261Lz\20\263\211\36_\343\n
-KExd\214\347=
\
277(\27\0\5\23o\276h\263'g\32/\377t&X\6\304`\n0*I\216\211\244\255\255p\=
270*\2523\203I\352 =
\243\246\215\10\223\225\334u\303\313\247
2\210\224#\275a\236\270\347\236o=
5\254 =
\35zRh\272\223\245\243\314tb\200\273\374
\300R\221\10\177\
240\301\5\330\331\274\240\211\305\206\02
04\0373q\232VW\237\244K\316Y\377=
!\246\210\205\3:& #91;\233a\367\2770\326\237X\314W\3431w|\
273\6,\35f\32\3730\=
274wU\3219\26\315~.v\302ln;+2\"\330\25l\327\253\341n\272NY}\275-7\377\37=
2\355\220\
\w\" \335\10\266#n\354v\247DO\353|\200\310Q\2
60&\253}\341\250\373\355\232=
\373\275X\201\1\205\5\246zN\224'\32\253
U2\6\1Z\263\346\327\3079\206\350=
\241\17G,\204O\315\206\336\331a\34\\H\27
2m\223\317y\352qv;\333\307\\\275=
\326\367s7
\347M\326\232\203\360\243\251& u\362\16\16\277\352\271g\30\201\r\326\37
0\=
306N\300\265;\240\275^&\355"..., =
61449) =3D 7033
time(NULL) =3D 1158283301
gettimeofday({1158283301, 172965}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
"FH/\306f\353\361\343\365r\244J_\316\264j[\36\276\24\263\273,\2048\333\3=
67k3H\322~\355\271\254? \313\253\332\31\31\367\337E\262:x\274\23
\366\241;=
\241*\25\347\345\27\352\200H2\253\346\25
5\344\211\377\321\375;1\232%\223=
< \201\237j\201\356\275d\3113)\346\240\337
\21\37\3377\230\250\330\353lJ\2=
567\311\245\355\301\360&\350\335]\27M\236\232\v\32-!\356\207\237~\347\31=
0c\215)\242\2546\345\314U& #91;\373\235\331\262\240\270\332\301\315
?%?\271~6S=
r& #91;3\17\227\20\265r\310\0004\365\253\31
1\300~}\205\224\345q\252h\vt.V\371=
\3552\212\267%s\213v\200V\335\16\233\240
\261\205\27ag\306\3713g\214\253\=
351\275\f\207\373\23\217\217\177\207\367
\301\226\250\262\211\306I\265\31=
6|\241*\275R\374p\16\324^\267\326\364\32
6\37\302pt\217\357'\237\233\f\3=
2>\3217j\tZGl\207\267S\\/\267\256\361f&Z\224\215y\342\273\261\263\"\323*=
\251\235> ~\222\214\345sP\231\314N\230\237+\373:V\
371\201~\254.\363\255_\=
235H\322\270\336\214\3\313\\\320& \306\357\362\323\274C_F\2147\344c\263\2=
1W|\3271\207:\217\273k\207>\27\275\240\270\305WQX<7x\337"..., =
61449) =3D 5585
time(NULL) =3D 1158283301
gettimeofday({1158283301, 173269}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, =
" \204\224\263\200:w\277\251n\377b\366K\26
\267\30\24\221\243['\203Z\0oK]=
v\325\354\226\340\261nM\213j\30\312\357\
326\311\207\277AJ+\324\344,^C\f\=
370\233\230\25V\301q\r\213~/ \304\364\261\271\300\232\305\1\\'\336\2
72\0=
\5\277\362\22\225\363\245< \v\300\202\347\332\327\311\342D\316\221,
m\217Y=
\32\337\34\311\331\340\26\33\t\254\204m\
226\351\276\246\t\25\216,q\223\2=
31\316& #123;\271\262\275X\\)_\177V\r\f\357\346]
;\305\241q\33\30\266\16\307\02=
76\374\6\0063\377\241\211\200\264\31\32`
\t\326\372\216+\265\273\214V\372=
m\0261\253\365\253\232lV\211\311\260\313
\254\334\333\306\307\346\23\26\3=
3\25\204 =
\313\330\254n}2\350. \256\3568\327\222\v\250\264\5\321\257\23
7m\203l\33\2=
13vT\v\36\6\243\320\254\336\201\212\27\2
5\30D\237J\242BEsnR\306\3407\27\=
325\31'\362\202U\220k\271*\333E>\276\306$\375\f\351\332\243\37\236\"\22=
6\306)U\270J:x\227\357\261S\312\3504|j\2
5\31Lv\305\26\35\263\2229\23T\35=
5\276\347j}\242\341\31\362\360\35\245TiK
J\331\320 =
X\17\274,\316-\376\344yT\266\345\353\215\n>Z\4\273R\\\355\v\214\223\375"=
...., =
61449) =3D 5792
time(NULL) =3D 1158283301
gettimeofday({1158283301, 173584}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
read(14, "\272\241\10\327\243\211\333\f| =
\245\354sC4`\320\4\262\366%\2+\362\367 =
\231\322\360Q\226\273\7\223\311\302\31\3
73\25\220_\327x\355\226\3265]>\3=
61\331\r- \351I\vC\306yX\367q\16\377\\\220\31\370J
\252\225\254~\310\241^A=
\3
77\215\236\222\25\320rx\27\244\216y\37\2
51\331\350m\7V6\0108\226\242:\27=
3u\331\n\266LhY(cPB\234WV\340hZ3\343\343
\226\240\230Xo\207\266\313W\331!=
\220\361\360*\266\262E\334}a\247\351O\35
7\377\331'\274\200\241\25*\31\2=
51\342\306
S\244\237\3650y\305~\17\36\336{\333\234+0s\272\37\271>\20\t6\324\177\306=
\4t\216\\\327\370\256\3517\222\311]\7\35
4\266\254=3D\23\366\323.\313\345=
\220\177\260\214\1\37\367\315\351UQ\374\
363\262\213\222@\262t)C\250e\366=
\266\360U\31
6\353\326\274\24r\1\2\26%\232k)\305\225\
266K_\203\316\261n\177A)\213q\21=
3\251\361\334\26\223\343\235;\17\226\243
1\223\230\303P\333rf!\347.\341\2=
25\221)\366\271\235\207\244\357\343\323\
250\204\4H\223\3434\271\221\365\=
242\26.:\2
23\202'4\232]& OO\275\273\32\253\33\227f\326\344\277\36
2?\371>j\336\363<=
\v\317\35\3774\370\232\233"..., =
61449) =3D 7033
time(NULL) =3D 1158283301
gettimeofday({1158283301, 173903}, NULL) =3D 0
epoll_wait(5, {{EPOLLIN, {u32=3D14, u64=3D14}}}, 1000, 1000) =3D 1
epoll_ctl(5, EPOLL_CTL_MOD, 14, {EPOLLERR|EPOLLHUP|0x20, {u32=3D14, =
u64=3D14}}) =3D 0
time(NULL) =3D 1158283301
gettimeofday({1158283301, 174076}, NULL) =3D 0
epoll_wait(5, {}, 1000, 1000) =3D 0
time(NULL) =3D 1158283302
gettimeofday({1158283302, 173663}, NULL) =3D 0
epoll_wait(5, {}, 1000, 1000) =3D 0
time(NULL) =3D 1158283303
gettimeofday({1158283303, 173662}, NULL) =3D 0
epoll_wait(5, {}, 1000, 1000) =3D 0
time(NULL) =3D 1158283304
gettimeofday({1158283304, 173634}, NULL) =3D 0
epoll_wait(5, {}, 1000, 1000) =3D 0
time(NULL) =3D 1158283305
gettimeofday({1158283305, 173755}, NULL) =3D 0
epoll_wait(5, {}, 1000, 604) =3D 0
time(NULL) =3D 1158283305
gettimeofday({1158283305, 777796}, NULL) =3D 0
time(NULL) =3D 1158283305
>
> Is the PERL 64-bit?
Yes:
# PERL -v
This is perl, v5.8.5 built for x86_64-linux-thread-multi
Copyright 1987-2004, Larry Wall
Perl may be copied only under the terms of either the Artistic License o=
r =
the
GNU General Public License, which may be found in the PERL 5 source kit.=
Complete documentation for Perl, including FAQ lists, should be found on=
this system using `man perl' or `perldoc perl'. If you have access to t=
he
Internet, point your browser at http://www.perl.com/, the PERL Home Page=
..
> Which version of Sys::Syscall? Does its make test
> succeed?
Hm.. that's interesting. I installed everything through CPAN (except =
Perlbal itself), and afterwards Perlbal seemed to work fine, so I didn't=
=
give it much mind. However, checking my /root/.cpan/build/ directory, I =
=
found Sys-Syscall-0.21, and going in there and typing make test, I got t=
he =
following:
[root@perlbal Sys-Syscall-0.21]# make test
PERL_DL_NONLAZY=3D1 /usr/bin/perl "-MExtUtils::Command::MM" "-e" =
"test_harness(0, 'blib/lib', 'blib/arch')" t/*.t
t/00-use.........ok
t/01-epoll.......ok 12/20# Failed test (t/01-epoll.t at line 61)
Can't use an undefined value as a symbol reference at t/01-epoll.t line =
62.
t/01-epoll.......NOK 13# Looks like you planned 20 tests but only ran 13=
..
# Looks like your test died just after 13.
t/01-epoll.......dubious
Test returned status 255 (wstat 65280, 0xff00)
DIED. FAILED tests 13-20
Failed 8/20 tests, 60.00% okay
t/02-sendfile....couldn't start listening at t/02-sendfile.t line 64.
t/02-sendfile....NOK 2# Failed test (t/02-sendfile.t at line 60)
# 'ERROR: unknown command: i
# '
# doesn't match '(?-xism:^OK)'
# Child said: ERROR: unknown command: i
# Looks like you failed 1 tests of 2.
t/02-sendfile....dubious
Test returned status 1 (wstat 256, 0x100)
DIED. FAILED test 2
Failed 1/2 tests, 50.00% okay
Failed Test Stat Wstat Total Fail Failed List of Failed
------------------------------------------------------------------------=
-------
t/01-epoll.t 255 65280 20 15 75.00% 13-20
t/02-sendfile.t 1 256 2 1 50.00% 2
Failed 2/3 test scripts, 33.33% okay. 9/23 subtests failed, 60.87% okay.=
make: *** [test_dynamic] Error 1
[root@perlbal Sys-Syscall-0.21]#
Now granted, I'm not positive this is the Syscall currently being used; =
=
but it probably is.
Hmm... I tried in the Danga-Socket-1.53 folder as well, and got the =
following results:
[root@perlbal2 Danga-Socket-1.53]# make test
PERL_DL_NONLAZY=3D1 /usr/bin/perl "-MExtUtils::Command::MM" "-e" =
"test_harness(0, 'blib/lib', 'blib/arch')" t/*.t
t/00-use..........ok
t/05-postloop.....ok
t/10-events.......ok 2/34couldn't create socket at t/10-events.t line 67=
..
# Looks like you planned 34 tests but only ran 2.
# Looks like your test died just after 2.
t/10-events.......dubious
Test returned status 255 (wstat 65280, 0xff00)
DIED. FAILED tests 3-34
Failed 32/34 tests, 5.88% okay
t/12-closerace....# Failed test (t/12-closerace.t at line 24)
t/12-closerace....NOK 1Can't call method "accept" on an undefined value =
at =
t/12-closerace.t line 27.
# Looks like you planned 7 tests but only ran 2.
# Looks like your test died just after 2.
t/12-closerace....dubious
Test returned status 255 (wstat 65280, 0xff00)
DIED. FAILED tests 1, 3-7
Failed 6/7 tests, 14.29% okay
Failed Test Stat Wstat Total Fail Failed List of Failed
------------------------------------------------------------------------=
-------
t/10-events.t 255 65280 34 64 188.24% 3-34
t/12-closerace.t 255 65280 7 11 157.14% 1 3-7
Failed 2/4 test scripts, 50.00% okay. 38/59 subtests failed, 35.59% okay=
..
make: *** [test_dynamic] Error 255
[root@perlbal2 Danga-Socket-1.53]#
The rest of the packages, though, seem to make test fine.
I only would figure that CPAN would either tell me at end of install =
(since things scroll by so fast during actual install that it's hard to =
=
notice) or not install the software... it straight up didn't install =
IO::AIO.
Think this might be it? Any suggestions on how I can get these tests to =
=
pass?
Thanks very much,
-Sam
>
> If it's not spinning CPU, then the question is why not: we want to kn=
ow
> about writability of the clientproxy but if we're not spinning, the ep=
oll
> support (Sys::Syscall) is broken. Historically we had problems with
> 64-bit, but that was fixed quite some time ago.
>
> - Brad
>
>
-- =
Using Opera's revolutionary e-mail client: http://www.opera.com/mail/
| |
| Brad Fitzpatrick 2006-09-16, 1:13 pm |
| The results below show that Perlbal is getting confused with an empty
epoll set, almost certainly caused by a failing Sys::Syscall.
Which distro/version is this? I'll try and reproduce, then get make test
to succeed (fixing any issues in the process).
Or, if you have any box you could get me access to, I can get you my ssh
key. I wouldn't mess with production stuff, nor would I need root, just
need a temp area, emacs, strace, and maybe gcc.
On Thu, 14 Sep 2006, Sam G wrote:
> This is long, but you may want to scroll past the strace output onto the
> Syscall stuff.
>
> On Thu, 14 Sep 2006 12:13:19 -0700, Brad Fitzpatrick <brad@danga.com>
> wrote:
>
>
> Nope; it doesn't appear to be taking any.
>
>
> Here is what I have changed it to:
>
> sub as_string {
> my Perlbal::ClientProxy $self = shift;
>
> my $ret = $self->SUPER::as_string;
> if ($self->{backend}) {
> my $ipport = $self->{backend}->{ipport};
> $ret .= "; backend=$ipport";
> }
>
> $ret .= "; write_buf_size=$self->{write_buf_size}"
> if $self->{write_buf_size} > 0;
> $ret .= "; stalled=$self->{backend_stalled}";
>
> $ret .= "; highpri" if $self->{high_priority};
> $ret .= "; lowpri" if $self->{low_priority};
> ...
>
>
> Okay, this is a big chunk, but I'm not too sure which part you might want:
>
> read(14,
> " \306\341=\7#(\320\274\354\37r\226\37\221
\352l\376!\347\220\210\265\374\364\0279-\223\234\277\310qT\340\26396E\0264B{%\32\217\356z& #123;C\256_6\241\n\t\215^'\ffn\366\3423
\202/\315? :\2602\363\277\27\240\374\205\261`\363\2
46\357\313~u\264
> \222\323& #91;M4\3ig\203\361\5\352f0\251\0L\307I\3
12\261\212\t\23\361\24\30\374\360ej\2545
lCJJ\300\30\241\211\257\363A\264|)\202(V
\353\3373& \260E\347\313\207\371\332\370\270\344\37
0\356z\257g\233\271\26\177\243B\32. \240\f\220\226\216\276\212\327\364P\360\
376
\275o]\314\223\211@\260\255\345\256\354\
r\376\225W\371\235\263\232\324\343>\240e\223\366\375P\250\315\" \263\322\237\236n$\205\21\205\353I\22:\3
26\241\262\343\3748s\264\260\221\244\27\
307CM\326\217\31V\345\271\332w\335\0029\
237\21\210\341\232\303\216?\301\
10\4\342\220\315\261\201\362\260\213\265
cM\211\f\321u\211\360\317F\373\222\335\1
\300\313u\27\2T\213L\26\205\227l\323_\20
7\3277\363zB\344\254L\302\215\4\212\347\
26\300\314)\345\30\303\27\313> U\3124\230\245\270\324S\7\263\227\335\26
1\362~\373\33\350\305"...
,
> 61449) = 7165
> time(NULL) = 1158283301
> gettimeofday({1158283301, 60893}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=14, u64=14}}}, 1000, 1000) = 1
> read(14,
> "\31&\20\250a\206H/ _l\377\177)\20Q`y5\370\206\353\323XB\261
\262\372\333\360\315~\224\34\355}\244\36
3\360\7\22\374Y\202C\321\324\"E;\326E\253:\223\364S\315\363\307!*\27& \n\274rE\214p\212\351o6\372\251\214\375\
364x\201\241\364\252\364\350t\264\r.\364Q\v\3
75c\221\271\366\256)\372\235E\332`\312(\
264\36\343$\317\316\" \205\215+\342\5\224v%\337\34U\305\372oh\
360\201\2A\205\303\345\316\323\346\331\2
10\272\277\244zb\321\302k\256\177\223\37
6\325rR\1)\331\5\215\344\2370p\366z\16\2
61\3750\32\23\210x\335\204\rK\370`
\303\243\" M\273\246w\253\346f\373@\3260\305o\1\306
7\vQ\331q\267V'\32F2\233:> \337\360\274B\341\215$\307R\300\317~\367
\f\310\346\\z\333\254>^'f\267%\353W_\222\216\vo|\345\332<m\20z\25\366\265\335\334> \354\311\237\343Z'C\317OI\17#KO;\314\30
5)\347\310\255\
25\325\370O\312\325\177R\2161#\0249\327\
25\250\231> \346\254@}RXkt\343Hym\331\365\314\346\35
4x\4
> \214\36\232\365\374\2513\35\335\330\305\
256- \n\211\1\33\213\245\234\233\337\275\177\
373\337\tMS\275\2451dq\233H\2445\2c\v\22
0Zz\240y"...,
> 61449) = 5792
> time(NULL) = 1158283301
> gettimeofday({1158283301, 61201}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=14, u64=14}}}, 1000, 1000) = 1
> read(14,
> " \363o\266p\23\355\7\201\340u\17v\345\365
\27=6\327\t\225v,\224P\271\364V\237l,\25
5h\215\217\24.\231T\350. Pe\0\312\03392r\321CK\213\334\241\30\21R
\345e\223\325wPA\320\27\362A\215\251\222
\237>\" \336\305\227d\302AY\231)#\275~\305W\10Y\
300\n\"\32^\277*W\177
\257y\330\362\203!\265\256\371\305\315\2
46mc\373$. !\255'\7z\2304\\o\34\354vvS\17\226\34\2
50\24\203\237\300e\204\303;a\244\320epaz
\370\207\\$\24\f\207\261\226\34\277\267U
x\24!\275\215\fH\35!\320T\376\370\34LRsf
\235\226\337\4\201\214R_\251@\276{\336\205y\3
22AS\16\370\267\227+i\220\20\31SsVp\327Q
\227$\244}fO\367\314\213p~\233\373\204\3
27\341\313&\342\27=\250U. \3228\27\233\221f\343g\231Rv=\204\334\24
\232\247\306=Z\354n\235\342e_\233\271\26
2\341\316\267\365\317\217i\345\262\32ly\
2032u\33|\314\376(\273-X\2079\
343\211cJ\352]s8,\276\307e\26\314^&i\371& #123;\304l\355\262\2701'x\6\225\361(\33
6\343Y\365\177\327\267\201|{O\203\274\372\325\344B\6\357\22
4r\365go\27\3179\23z\274\277>
> \304\337 \343\310. \334\245\362\324\326\266\300\n\3260F\200
JJ`~\5"...,
> 61449) = 7165
> time(NULL) = 1158283301
> gettimeofday({1158283301, 61511}, NULL) = 0
> epoll_wait(5, {{EPOLLIN, {u32=14, u64=14}}}, 1000, 1000) = 1
> read(14,
> "hv?\21\375\5`\360\25\\\25\\\f\362?\177\350\371\275\352M\343\341\26\205< \334Y9\314\376\326\f\340\235\217\353'\3
6\33G\324\352\244/(\340\326\37w\345\205B?/- \276\253\252\227vOJ\270aG\253J\365~\262\
323\310s+=frM\367\364\310l\v\314\20\267\
337k\320*|&\217\23
6\204Ed\323G\211\315\302\35\0270\236\241
\310Q\374=\262\36\331\" Y\0=\267N0\345)\204\376\242\32ZQ\2460l^\
351\3076\25\f\r\317\270\216\33\350\216\3
27\34\361\\Y\261d\17\21\342\302\373\361\
223\376\27\275D\271\272\205\346M\301\342
YD\6\342O\332\333\337b\242\371\2
754J\361&\10\255s\362fo<G\214/\213\215\3041\311\215> D\\\274X\270\243\241K\26\312\371f\350\24
\211\324\260\212\223xO\201\" \31\345f\201\327N\361\3328\24\3\273\336\
360\16\362x$D\301\363/Y)\220`\226b\210\222\334\f\227\354.\322A4\344\276\5j\234IG'\333\312\366\
251\216\342\277\26j/ \215\n0\224\325\276\346i\366\21\21 | | |