Perlbal reproxied downloads stalling
Web Server forum
Back To The Forum Home!Search!Private Messaging System

Web Server Talk Web Server Talk > Web Servers reviews > Perlbal > Perlbal reproxied downloads stalling




Pages (2): [1] 2 »   Last Thread   Next Thread Next
  Show Printable Version Email this Page Subscribe to this Thread      Post New Thread    Post A Reply      

    Perlbal reproxied downloads stalling  
Sam G


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-08-06 12:11 PM

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/






[ Post a follow-up to this message ]



    Re: Perlbal reproxied downloads stalling  
Brad Fitzpatrick


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-08-06 06: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/
>
>






[ Post a follow-up to this message ]



    Re: Perlbal reproxied downloads stalling  
Sam G


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-09-06 06:12 AM

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, {u
32=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\232W
n\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\232W
n\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) =3
D 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/






[ Post a follow-up to this message ]



    Re: Perlbal reproxied downloads stalling  
Brad Fitzpatrick


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-09-06 06: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|
0x
20,
> {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{\321$\221\331^\302\237\224
 80\33\257\35\2220\25\337f\17#e\7%\253\23
\330\21\356\321\250fd\204\241%\372hD
 \374h\214\225\16\232w\322@O\16m_!\375\23
7w)\20\n\256YF\353B\10|\231j7\23
>  1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\301\
37V\307\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\353\353w\344L\3\341*\345\227\34
60\204\354\23Q\332\316-O\301\350\270
 w\206t\235v\365\300r;\367\377\220s\244\3
11\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\372\315\325q\233
_\350at\324\363\320\343qG\32\221\345
 \f\272\324\t\2524\\\232]^\301\241\220\21
2\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\325F
 \326N\27,~\200\235\306_\222@\301\246\266
\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\21\
 340\32\326\326f\332\255\214T0%\253,!1\21
2\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.\31
4\36
>  7:Z9\316j\313]K\342\356X\31\245S\5\251\t
8\223KXrZ\277\277\236I\352;T\200\3
27\r1\240iO\21\31\301\10"...,
> 26868) = 26868
> write(9,
> "\2100)\"\33\31\207\244\241\0254\210v\360W{\321$\221\331^\302\237\224
 80\33\257\35\2220\25\337f\17#e\7%\253\23
\330\21\356\321\250fd\204\241%\372hD
 \374h\214\225\16\232w\322@O\16m_!\375\23
7w)\20\n\256YF\353B\10|\231j7\23
>  1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\301\
37V\307\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, 
3;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_\24
5x\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\23
5\253|\217a\2
> 60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\27
6\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\306\250\27\3
0\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\2
02\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\
 5\327\335Z\247\343y\327W\241l\277\231\37
5\232\262\261\177]Mur\275\271y\223\2
70\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_\24
5x\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\23
5\253|\217a\2
> 60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\27
6\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\306\250\27\3
0\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\2
02\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\
 5\327\335Z\247\343y\327W\241l\277\231\37
5\232\262\261\177]Mur\275\271y\223\2
70\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|
0x
20,
> {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/
>
>






[ Post a follow-up to this message ]



    Re: Perlbal reproxied downloads stalling  
Brad Fitzpatrick


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-09-06 06: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|
0x
20,
> {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{\321$\221\331^\302\237\224
 80\33\257\35\2220\25\337f\17#e\7%\253\23
\330\21\356\321\250fd\204\241%\372hD
 \374h\214\225\16\232w\322@O\16m_!\375\23
7w)\20\n\256YF\353B\10|\231j7\23
>  1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\301\
37V\307\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\353\353w\344L\3\341*\345\227\34
60\204\354\23Q\332\316-O\301\350\270
 w\206t\235v\365\300r;\367\377\220s\244\3
11\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\372\315\325q\233
_\350at\324\363\320\343qG\32\221\345
 \f\272\324\t\2524\\\232]^\301\241\220\21
2\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\325F
 \326N\27,~\200\235\306_\222@\301\246\266
\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\21\
 340\32\326\326f\332\255\214T0%\253,!1\21
2\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.\31
4\36
>  7:Z9\316j\313]K\342\356X\31\245S\5\251\t
8\223KXrZ\277\277\236I\352;T\200\3
27\r1\240iO\21\31\301\10"...,
> 26868) = 26868
> write(9,
> "\2100)\"\33\31\207\244\241\0254\210v\360W{\321$\221\331^\302\237\224
 80\33\257\35\2220\25\337f\17#e\7%\253\23
\330\21\356\321\250fd\204\241%\372hD
 \374h\214\225\16\232w\322@O\16m_!\375\23
7w)\20\n\256YF\353B\10|\231j7\23
>  1\363\337QnA\210R\365\337\\5,:\3737W\341
pI\206\273\227~\2472\361\316Q\301\
37V\307\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, 
3;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_\24
5x\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\23
5\253|\217a\2
> 60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\27
6\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\306\250\27\3
0\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\2
02\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\
 5\327\335Z\247\343y\327W\241l\277\231\37
5\232\262\261\177]Mur\275\271y\223\2
70\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_\24
5x\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\23
5\253|\217a\2
> 60\224v> \335\354\212\316\334\252eU\226\3\n\n65\3
4\30\230zf\2\253\375#1f\27
6\17\352\212\30\313\"\376\347\307+\365\314\337?r\25745\354tj\23\306\250\27\3
0\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\2
02\244H\335\346{{\37\25{\310]\32\305\teJ\226[\336X\232Wn\
 5\327\335Z\247\343y\327W\241l\277\231\37
5\232\262\261\177]Mur\275\271y\223\2
70\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|
0x
20,
> {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/
>
>






[ Post a follow-up to this message ]



    Re: Perlbal reproxied downloads stalling  
Sam G


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-13-06 06:11 AM

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
[vbcol=seagreen]
>
>
>
>
> 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=[/vbcol
]
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\2
32Wn\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\2
32Wn\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/






[ Post a follow-up to this message ]



    Re: Perlbal reproxied downloads stalling  
Sam G


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-13-06 12:11 PM

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/






[ Post a follow-up to this message ]



    Re: Perlbal reproxied downloads stalling  
Brad Fitzpatrick


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-16-06 06: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/
>
>






[ Post a follow-up to this message ]



    Re: Perlbal reproxied downloads stalling  
Sam G


View Ip Address Report This Message To A Moderator Edit/Delete Message


 
09-16-06 06:13 PM

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\3
2=
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\35
2=
\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{\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\2
3=
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\f
k=
\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\6
uRzJ\=
 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\2
1=
 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=
4