[tor-dev] :(

Mon Jul 14 21:49:59 UTC 2014

Maybe having 12 tabs open while downloading TBB did it?
On Jul 14, 2014 4:46 PM, <vmon at riseup.net> wrote:

> Interesting! It is not a fundamental error per say, if you are a server
> you can't handle more than some number of connections anyway (you can
> increase that if you are root), so the client need to wait. You need a
> ddos defence mechanism against that (e.g. iptables) independent of what
> kind of server you are running.
>
> However, I put a defence mechanism against a ST client being able to
> open too many connections on the client side barring it by this formula:
>
> min(8, and ceilling of (MAX - count)/no of circ)
>
> I wonder how does it get bypassed :
>
> chop.cc:722
>
>     // If we're the client and we had no target connection, try
>     // reopening new connections.  If we're the server, we have to
>     // just twiddle our thumbs and hope the client does that.
>     if (no_target_connection) {
>       log_debug(this, "number of open connections on this circuit %u,
> golobally %u", (unsigned int)downstreams.size(), (unsigned int)
> conn_count());
>       if (config->mode != LSN_SIMPLE_SERVER &&
>           (int)downstreams.size() < min(MAX_CONN_PER_CIRCUIT,
> ((int)(MAX_GLOBAL_CONN_COUNT - conn_count() + (int)circuit_count() -
> 1)/(int)circuit_count()))) //min(8, and ceilling of (MAX - count)/no of
> circ)
>         circuit_reopen_downstreams(this);
>
> If you start many ST clients though that won't be effective and you are
> basically ddosing the server.
>
> vmon
>
> Noah Rahman <selimthegrim at gmail.com> writes:
>
> > 7477.6308 [debug] http_server_JS_transmit: SERVER found the applicable
> > HTTP response template with size 10399
> > 7477.6324 [debug] conn_do_flush: <1102.35442> flushing 6349 bytes to
> > peer [enabled=6]
> > 7477.6324 [debug] send_targeted: <1102.35442> transmitted block 4
> > <d=488 p=3 f=DAT>
> > T:7477.6324: ckt 1102 <ntp 5 outq 0>: send 4 <d=488 p=3 f=DAT>
> > 7477.6324 [debug] send_targeted: <1102> efficiency: 24.813380
> > 7477.6325 [debug] downstream_flush_cb: <1102.35442> 0 bytes still to
> > transmit (reached EOF) (received EOF)
> > 7477.6326 [debug] drop_downstream: <1102> dropped connection
> > <1102.35442> to 127.0.0.1:51874, now 0
> > 7477.6326 [debug] circuit_arm_axe_timer: <1102> axe after 1800000
> > milliseconds
> > 7477.6326 [debug] close: <0.35442> closing connection; 736 remaining
> > 7477.6326 [debug] close_cleanup_cb: cleaning up 0 circuits and 1
> > connections
> > 7477.6380 [info] server_listener_cb: 127.0.0.1:5000: new connection to
> > server from 127.0.0.1:51875
> > 7477.6381 [debug] conn_create: <0.35443> new connection
> > 7477.6381 [debug] downstream_flush_cb: <0.35443> 0 bytes still to
> > transmit (no circuit) (never received)
> > 7477.6387 [debug] downstream_read_cb: <0.35443> 836 bytes available
> > 7477.6387 [debug] http_server_receive: <0.35443> SERVER received
> > request header of length 832
> > 7477.6388 [debug] http_server_receive: Cookie:
> >
> 1o9Pt2B-kM=37XmMDPvsABcxKIT2I5nqNQOkkUKqhR7sAAAAFAT4AAAEAAAAAAAAAFgMBAQYQAAECAQAhhD7ExjZhmIiu2IaFGdGrT1arN52cDxVTXFe07egCZNbiKmf6yS9s9hRlJ489X2wZ5S7c00ORL9GU907NN3DqOG9EtcichBTz3V6MdLVVNxrCqWwMOiJIbCZ277f2pO;
> >
> F=QJ3or_CLfT-VVLEGeopox1nLiFoPjpMXXWmFMHl9OW4GQ49L5Z5Y8KNph2d8mQ3ViIjMzMPctvOzUoxcBhx2er_
> >
> VIPfhqAh3s;ybTJK4VpoL=cH_avl8ZEIiw3Q_WZdqvCPF6EE;3Bqa=OFSbR36AqM3s7pr2N2e9Fv_
> >
> IoJSQUvmnySI6bBC1VpTKXzv2hJ2W6P1hdRtxQrJmWWukBcWsKLUwFAMBAAEBFgMBACiF_LOpLxeA7Y1c;
> > n-5Sytb5R=2sQrFg4MK8c;Xz_=Z_ALz5YDp938ckzYjAAAAAA;AAAAAAA=AAAAAAAAA..
> >
> > 7477.6389 [debug] transmit_soon: <0.35443> must send within 100
> > milliseconds
> > 7477.6389 [debug] verify_and_extract: retrieved circ id 3075444694
> > 7477.6389 [debug] recv_handshake: <0.35443> found circuit to
> > 127.0.0.1:5001
> > 7477.6389 [debug] add_downstream: <1102> added connection <1102.35443>
> > to 127.0.0.1:51875, now 1
> > 7477.6390 [debug] recv: <1102.35443> circuit to 127.0.0.1:5001
> > 7477.6390 [debug] recv: <1102.35443> 350 bytes available
> > 7477.6390 [debug] recv: <1102.35443> receiving block 5 <d=318 p=0
> > f=DAT r=0>
> > T:7477.6390: ckt 1102 <ntp 5 outq 0>: recv 5 <d=318 p=0 f=DAT r=0>
> > 7477.6391 [debug] recv: Data received:
> > 7477.6391 [debug] remove_next: next_to_process=5 data=0xe140740 op=DAT
> > 7477.6391 [debug] remove_next: next_to_process=6 data=(nil) op=XXX
> > 7477.6391 [debug] process_queue: <1102> processed 1 blocks
> > 7477.6392 [debug] upstream_flush_cb: <1102> 0 bytes still to transmit
> > 7477.6850 [debug] upstream_read_cb: <1102> 51 bytes available
> > 7477.6851 [debug] send: <1102> 51 bytes to send
> > 7477.6851 [debug] pick_connection: <1102> target block size 83 bytes
> > 7477.6851 [debug] pick_connection: <1102.35443> has been connected for
> > 0 secs
> > 7477.6851 [debug] transmit_room: <1102.35443> checking available
> > capacity for type 3
> > 7477.6852 [debug] pick_connection: <1102.35443> offers 115 bytes
> > (http)
> > 7477.6852 [debug] pick_connection: <1102> no req: 9 avg des:
> > 712.111111 avg act: 663.333333
> > 7477.6852 [debug] pick_connection: <1102> minabove 115 for
> > <1102.35443> maxbelow 0 for <1102.0>
> > 7477.6853 [debug] get_payload: contentType = 3, initTypePayload = 1,
> > typePayloadCount = 613
> > 7477.6853 [debug] get_payload: first payload size=9647, best payload
> > size=3162, num candidate=100
> >
> > 7477.6853 [debug] pick_appropriate_cover_payload: SERVER found the
> > next HTTP response template with size 3162
> > 7477.6854 [debug] http_server_transmit: coping body of 3014 size
> > 7477.6854 [debug] http_server_transmit: SERVER embeding data1 with
> > length 83 into type 3
> > 7477.6857 [debug] http_server_transmit: SERVER FileSteg sends resp
> > with hdr len 148 body len 106
> > 7477.6858 [debug] conn_do_flush: <1102.35443> flushing 3309 bytes to
> > peer [enabled=6]
> > 7477.6858 [debug] send_targeted: <1102.35443> transmitted block 5
> > <d=51 p=0 f=DAT>
> > T:7477.6858: ckt 1102 <ntp 6 outq 0>: send 5 <d=51 p=0 f=DAT>
> > 7477.6858 [debug] send_targeted: <1102> efficiency: 24.809808
> > 7477.6859 [debug] downstream_flush_cb: <1102.35443> 0 bytes still to
> > transmit (reached EOF) (received EOF)
> > 7477.6860 [debug] drop_downstream: <1102> dropped connection
> > <1102.35443> to 127.0.0.1:51875, now 0
> > 7477.6860 [debug] circuit_arm_axe_timer: <1102> axe after 1800000
> > milliseconds
> > 7477.6860 [debug] close: <0.35443> closing connection; 736 remaining
> > 7477.6860 [debug] close_cleanup_cb: cleaning up 0 circuits and 1
> > connections
> > 7477.7882 [info] server_listener_cb: 127.0.0.1:5000: new connection to
> > server from 127.0.0.1:51876
> > 7477.7882 [debug] conn_create: <0.35444> new connection
> > 7477.7883 [debug] downstream_flush_cb: <0.35444> 0 bytes still to
> > transmit (no circuit) (never received)
> > 7477.7890 [debug] downstream_read_cb: <0.35444> 425 bytes available
> > 7477.7891 [debug] http_server_receive: <0.35444> SERVER received
> > request header of length 421
> > 7477.7891 [debug] http_server_receive: Cookie:
> >
> 1o9Pt0=f_eWs3tuUJLpu8g2aiE1m2BwMF6jib99twQLIAAAAGAAAAAQEAAAAA;AAAAAAAAA=A;
> > AAAAAAAAA=AAAAAAAA.
> >
> > 7477.7891 [debug] transmit_soon: <0.35444> must send within 100
> > milliseconds
> > 7477.7892 [debug] verify_and_extract: retrieved circ id 3075444694
> > 7477.7892 [debug] recv_handshake: <0.35444> found circuit to
> > 127.0.0.1:5001
> > 7477.7892 [debug] add_downstream: <1102> added connection <1102.35444>
> > to 127.0.0.1:51876, now 1
> > 7477.7892 [debug] recv: <1102.35444> circuit to 127.0.0.1:5001
> > 7477.7893 [debug] recv: <1102.35444> 33 bytes available
> > 7477.7893 [debug] recv: <1102.35444> receiving block 6 <d=0 p=1 f=DAT
> > r=0>
> > T:7477.7893: ckt 1102 <ntp 6 outq 0>: recv 6 <d=0 p=1 f=DAT r=0>
> > 7477.7893 [debug] remove_next: next_to_process=6 data=0xe1683d0 op=DAT
> > 7477.7893 [debug] remove_next: next_to_process=7 data=(nil) op=XXX
> > 7477.7894 [debug] process_queue: <1102> processed 1 blocks
> > lliseconds
> > 7477.8125 [debug] verify_and_extract: retrieved circ id 4060828808
> > 7477.8125 [debug] circuit_create: <1103> new circuit
> > 7477.8125 [info] circuit_open_upstream: <1103> trying to connect to
> > 127.0.0.1:5001
> > 7477.8126 [info] circuit_open_upstream: <1103> connection to
> > 127.0.0.1:5001 failed: Too many open files7477.8047 [info]
> > server_listener_cb: 127.0.0.1:5000: new connection to server from
> > 127.0.0.1:51877
> > 7477.8048 [debug] conn_create: <0.35445> new connection
> > [warn] Error from accept() call: Too many open files
> > 7477.8048 [debug] downstream_flush_cb: <0.35445> 0 bytes still to
> > transmit (no circuit) (never received)
> > 7477.8054 [debug] downstream_read_cb: <0.35445> 506 bytes available
> > 7477.8054 [debug] http_server_receive: <0.35445> SERVER received
> > request header of length 502
> > 7477.8054 [debug] http_server_receive: Cookie:
> >
> 1o9=Pt6QwYewJ9F6kjH;fGyxKq9Ti=cPKqah0wQFhNNL-wAAAAHAB0ABwEAAAAA;AA=AAFQMBABjR-
> > 87YPxS9nJMDyQOhg3303;SW3kO=0Q03gAAAAAAA;AAA=AAAAAAAA;AAAAAA=AAAA;AAA=..
> >
> > 7477.8055 [debug] transmit_soon: <0.35445> must send within 100
> > milliseconds
> > 7477.8055 [debug] verify_and_extract: retrieved circ id 3075444694
> > 7477.8055 [debug] recv_handshake: <0.35445> found circuit to
> > 127.0.0.1:5001
> > 7477.8056 [debug] add_downstream: <1102> added connection <1102.35445>
> > to 127.0.0.1:51877, now 2
> > 7477.8056 [debug] recv: <1102.35445> circuit to 127.0.0.1:5001
> > 7477.8056 [debug] recv: <1102.35445> 68 bytes available
> > 7477.8056 [debug] recv: <1102.35445> receiving block 7 <d=29 p=7 f=DAT
> > r=0>
> > T:7477.8057: ckt 1102 <ntp 7 outq 0>: recv 7 <d=29 p=7 f=DAT r=0>
> > 7477.8057 [debug] recv: Data received:
> > 7477.8057 [debug] remove_next: next_to_process=7 data=0xe1683d0 op=DAT
> > 7477.8057 [debug] remove_next: next_to_process=8 data=(nil) op=XXX
> > 7477.8058 [debug] process_queue: <1102> processed 1 blocks
> > 7477.8058 [debug] upstream_flush_cb: <1102> 0 bytes still to transmit
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > 7477.8095 [info] upstream_event_cb: <1102> EOF from upstream
> > 7477.8095 [debug] send: <1102> 0 bytes to send
> > 7477.8095 [debug] pick_connection: <1102> target block size 32 bytes
> > 7477.8095 [debug] pick_connection: <1102.35444> has been connected for
> > 0 secs
> > 7477.8096 [debug] transmit_room: <1102.35444> checking available
> > capacity for type 5
> > 7477.8096 [debug] pick_connection: <1102.35444> offers 65 bytes (http)
> > 7477.8096 [debug] pick_connection: <1102> no req: 10 avg des:
> > 647.300000 avg act: 603.500000
> > 7477.8097 [debug] pick_connection: <1102.35445> has been connected for
> > 0 secs
> > 7477.8097 [debug] transmit_room: <1102.35445> checking available
> > capacity for type 5
> > 7477.8097 [debug] pick_connection: <1102.35445> offers 71 bytes (http)
> > 7477.8097 [debug] pick_connection: <1102> no req: 11 avg des:
> > 594.272727 avg act: 555.090909
> > 7477.8098 [debug] pick_connection: <1102> minabove 65 for <1102.35444>
> > maxbelow 0 for <1102.0>
> > 7477.8098 [debug] http_server_JS_transmit: sbuflen = 33
> >
> > 7477.8098 [debug] get_payload: contentType = 5, initTypePayload = 1,
> > typePayloadCount = 1548
> > 7477.8099 [debug] get_payload: first payload size=46676, best payload
> > size=20041, num candidate=100
> >
> > 7477.8099 [debug] http_server_JS_transmit: SERVER found the applicable
> > HTTP response template with size 20041
> > 7477.8119 [debug] conn_do_flush: <1102.35444> flushing 8060 bytes to
> > peer [enabled=6]
> > 7477.8119 [debug] send_targeted: <1102.35444> transmitted block 6 <d=0
> > p=1 f=FIN>
> > T:7477.8119: ckt 1102 <ntp 8 outq 0>: send 6 <d=0 p=1 f=FIN>
> > 7477.8119 [debug] send_targeted: <1102> efficiency: 24.809808
> > 7477.8120 [debug] send: <1102> 1 dead cycles
> > [warn] Error from accept() call: Too many open files
> > 7477.8121 [debug] downstream_flush_cb: <1102.35444> 0 bytes still to
> > transmit (reached EOF) (received EOF)
> > 7477.8121 [debug] drop_downstream: <1102> dropped connection
> > <1102.35444> to 127.0.0.1:51876, now 1
> > 7477.8121 [debug] close: <0.35444> closing connection; 737 remaining
> > 7477.8122 [debug] close_cleanup_cb: cleaning up 0 circuits and 1
> > connections
> > 7477.8123 [info] server_listener_cb: 127.0.0.1:5000: new connection to
> > server from 127.0.0.1:51879
> > 7477.8123 [debug] conn_create: <0.35446> new connection
> > [warn] Error from accept() call: Too many open files
> > [warn] Error from accept() call: Too many open files
> > 7477.8124 [debug] downstream_read_cb: <0.35446> 443 bytes available
> > 7477.8124 [debug] http_server_receive: <0.35446> SERVER received
> > request header of length 439
> > 7477.8124 [debug] http_server_receive: Cookie:
> > iFQ=L8srwNz_kQgBW4weYMYT;sLEmEhA8VZ=9NBYIXNQa0AAAAAAAAA;A=AEAAAAAA;A=AA;
> > AAAAAAAAAA=AAAAA;AAA=AAAA..
> >
> > 7477.8125 [debug] transmit_soon: <0.35446> must send within 100 mi
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.torproject.org/pipermail/tor-dev/attachments/20140714/bde6d608/attachment-0001.html>