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@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
Maybe having 12 tabs open while downloading TBB did it? On Jul 14, 2014 4:46 PM, vmon@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@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