[tor-dev] :(

vmon at riseup.net vmon at riseup.net
Mon Jul 14 21:45:50 UTC 2014 

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

More information about the tor-dev mailing list