Relay asymmetry between tx and rx in presence of high amount of circuits
Hi
I observed an asymmetry between tx and rx on Doedelkiste08 E388F7BD196F5195AEF114552585152EA6942329
.
- normal is 20-30 GB/hour in each direction but this time it is 101 GB/hour on tx and 13 GB/hour rx.
- the whole thing was framed by some 100k open circuits.
- one bug was captured.
- during that effect the memory went from normal 3.3 GB to 10 GB until restart of the Tor daemon
Tor 0.4.8.9 running on FreeBSD with Libevent 2.1.12-stable, OpenSSL LibreSSL 3.7.3, Zlib 1.2.13, Liblzma 5.4.1, Libzstd 1.5.5 and BSD 1302001 as libc.
Special columns
G GB Bytestx / hour
H GB Bytesrx / hour
I ConnIp4rx / hour
J ConnIp6rx / hour
K ConnIp4tx / hour
L ConnIp6tx / hour
Day 2024-01-10
YYYY MM DD hh mm circs G H I J K L
----------------------------------------------
2024 01 10 00 55 19396 21 21 5523 311 1265 340
2024 01 10 01 55 52167 24 22 11822 494 1874 417
2024 01 10 02 55 86601 22 22 9141 667 2965 640
2024 01 10 03 55 87786 21 20 9013 621 3194 745
2024 01 10 04 55 475880 24 23 14957 2151 3463 789
2024 01 10 05 55 602250 63 23 17184 2961 3082 675
2024 01 10 06 55 683559 101 13 4192 372 3327 554 <--- 101 GBtx 13 GBrx
2024 01 10 07 55 584892 101 13 8604 435 3004 573 <--- 101 GBtx 13 GBrx
2024 01 10 08 55 512506 101 12 10954 716 3532 584 <--- 101 GBtx 12 GBrx
2024 01 10 09 55 515670 101 13 11107 703 2831 423 <--- 101 GBtx 13 GBrx
2024 01 10 10 55 509373 101 12 12487 693 2580 456 <--- 101 GBtx 12 GBrx
2024 01 10 11 55 433452 101 12 11618 778 2614 509 <--- 101 GBtx 12 GBrx
2024 01 10 12 55 459210 101 12 11142 690 2683 468 <--- 101 GBtx 12 GBrx
2024 01 10 13 55 445861 101 13 12718 1123 2196 341 <--- 101 GBtx 13 GBrx
2024 01 10 14 55 129114 64 23 15763 2258 2370 414
2024 01 10 15 55 107969 28 26 9466 971 2480 460
2024 01 10 16 55 117238 23 22 10619 903 3253 580
2024 01 10 17 55 119758 26 25 11640 955 3726 673
2024 01 10 18 55 112535 27 26 10459 864 3241 649
2024 01 10 19 55 111949 24 23 11207 943 3601 671
2024 01 10 20 55 118081 25 24 10740 816 3422 636
2024 01 10 21 55 43387 25 23 12064 638 2587 513
2024 01 10 22 55 45630 26 26 8244 468 1634 304
2024 01 10 23 55 79891 33 31 14421 711 2386 382
Jan 10 05:29:27.000 [notice] We're low on memory (cell queues total alloc: 1854500736 buffer total alloc: 145281024, tor compress total alloc: 0 (zlib: 0, zstd: 0, lzma: 0), rendezvous cache total alloc: 147652723). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 10 05:29:27.000 [notice] Removed 216594576 bytes by killing 16262 circuits; 719620 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
Jan 10 05:29:37.000 [notice] We're low on memory (cell queues total alloc: 1817612016 buffer total alloc: 188672000, tor compress total alloc: 0 (zlib: 0, zstd: 0, lzma: 0), rendezvous cache total alloc: 147706369). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 10 05:29:37.000 [notice] Removed 223153920 bytes by killing 12759 circuits; 707641 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
Jan 10 05:29:50.000 [notice] We're low on memory (cell queues total alloc: 1843384752 buffer total alloc: 155586560, tor compress total alloc: 0 (zlib: 0, zstd: 0, lzma: 0), rendezvous cache total alloc: 147736526). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 10 05:29:50.000 [notice] Removed 215864352 bytes by killing 13793 circuits; 693209 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
...
Jan 10 07:01:43.000 [notice] We're low on memory (cell queues total alloc: 1848156288 buffer total alloc: 138866688, tor compress total alloc: 9630543 (zlib: 43264, zstd: 9587151, lzma: 0), rendezvous cache total alloc: 151793907). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 10 07:01:43.000 [notice] Removed 217691232 bytes by killing 17176 circuits; 671565 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
Jan 10 07:02:00.000 [notice] We're low on memory (cell queues total alloc: 1877210544 buffer total alloc: 107673600, tor compress total alloc: 9760383 (zlib: 173056, zstd: 9587151, lzma: 0), rendezvous cache total alloc: 151770912). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 10 07:02:00.000 [notice] Removed 215662800 bytes by killing 17873 circuits; 664505 circuits remain alive. Also killed 0 non-linked directory connections. Killed 1 edge connections
Jan 10 07:02:00.000 [warn] connection_edge_about_to_close: Bug: (Harmless.) Edge connection (marked at src/core/or/circuitlist.c:2747) hasn't sent end yet? (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] tor_bug_occurred_: Bug: src/core/or/connection_edge.c:1086: connection_edge_about_to_close: This line should not have been reached. (Future instances of this warning will be silenced.) (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: Tor 0.4.8.9: Line unexpectedly reached at connection_edge_about_to_close at src/core/or/connection_edge.c:1086. Stack trace: (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x281cee7eebfc <log_backtrace_impl+0x5c> at /usr/local/bin/tor (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x281cee7fd024 <tor_bug_occurred_+0x1c4> at /usr/local/bin/tor (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x281cee64d022 <connection_exit_about_to_close+0x82> at /usr/local/bin/tor (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x281cee649651 <tor_mainloop_free_all+0x691> at /usr/local/bin/tor (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x281cee649218 <tor_mainloop_free_all+0x258> at /usr/local/bin/tor (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x2825113c733d <event_base_assert_ok_nolock_+0xbdd> at /usr/local/lib/libevent-2.1.so.7 (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x2825113c31ac <event_base_loop+0x54c> at /usr/local/lib/libevent-2.1.so.7 (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x281cee648d6a <do_main_loop+0x10a> at /usr/local/bin/tor (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x281cee635ae8 <tor_run_main+0x128> at /usr/local/bin/tor (on Tor 0.4.8.9 )
Jan 10 07:02:00.000 [warn] Bug: 0x281cee634464 <tor_main+0x54> at /usr/local/bin/tor (on Tor 0.4.8.9 )
Jan 10 07:03:21.000 [notice] We're low on memory (cell queues total alloc: 1878572784 buffer total alloc: 115148800, tor compress total alloc: 259680 (zlib: 259584, zstd: 0, lzma: 0), rendezvous cache total alloc: 151802305). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 10 07:03:22.000 [notice] Removed 215030640 bytes by killing 19693 circuits; 688440 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
Jan 10 07:03:36.000 [notice] We're low on memory (cell queues total alloc: 1882048608 buffer total alloc: 111587328, tor compress total alloc: 259680 (zlib: 259584, zstd: 0, lzma: 0), rendezvous cache total alloc: 151820909). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 10 07:03:36.000 [notice] Removed 214973616 bytes by killing 14621 circuits; 684012 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
Jan 10 07:03:57.000 [notice] We're low on memory (cell queues total alloc: 1883993760 buffer total alloc: 105201664, tor compress total alloc: 4455067 (zlib: 346112, zstd: 4108779, lzma: 0), rendezvous cache total alloc: 151853380). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
...
Jan 11 18:56:46.000 [notice] We're low on memory (cell queues total alloc: 1654239312 buffer total alloc: 426717184, tor compress total alloc: 0 (zlib: 0, zstd: 0, lzma: 0), rendezvous cache total alloc: 65574750). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 11 18:56:46.000 [notice] Removed 214757664 bytes by killing 13902 circuits; 854250 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
Jan 11 18:57:09.000 [notice] We're low on memory (cell queues total alloc: 1807050960 buffer total alloc: 281556992, tor compress total alloc: 0 (zlib: 0, zstd: 0, lzma: 0), rendezvous cache total alloc: 65565646). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 11 18:57:10.000 [notice] Removed 222395232 bytes by killing 16123 circuits; 830074 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
Jan 11 18:58:55.000 [notice] We're low on memory (cell queues total alloc: 1868207088 buffer total alloc: 297957376, tor compress total alloc: 0 (zlib: 0, zstd: 0, lzma: 0), rendezvous cache total alloc: 65590037). Killing circuits withover-long queues. (This behavior is controlled by MaxMemInQueues.)
Jan 11 18:58:55.000 [notice] Removed 299982672 bytes by killing 24949 circuits; 842791 circuits remain alive. Also killed 0 non-linked directory connections. Killed 0 edge connections
Jan 11 19:44:37.000 [notice] No circuits are opened. Relaxed timeout for circuit 809594 (a Measuring circuit timeout 3-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [3 similar message(s) suppressed in last 3000 seconds]
Jan 11 19:55:47.000 [notice] Heartbeat: Tor's uptime is 41 days 8:00 hours, with 752697 circuits open. I've sent 24792.07 GB and received 23055.17 GB. I've received 8142351 connections on IPv4 and 765946 on IPv6. I've made 2448992 connections with IPv4 and 412798 with IPv6.
Jan 11 19:55:47.000 [notice] While bootstrapping, fetched this many bytes: 420 (server descriptor upload); 616425 (consensus network-status fetch); 11896 (authority cert fetch); 6573653 (microdescriptor fetch)
Jan 11 19:55:47.000 [notice] While not bootstrapping, fetched this many bytes: 1173362587 (server descriptor fetch); 25800 (server descriptor upload); 57166841 (consensus network-status fetch); 1773 (authority cert fetch); 22640766 (microdescriptor fetch)
Jan 11 19:55:47.000 [notice] Circuit handshake stats since last time: 8/8 TAP, 6477916/7691976 NTor.
Jan 11 19:55:47.000 [notice] Since startup we initiated 0 and received 0 v1 connections; initiated 0 and received 0 v2 connections; initiated 0 and received 17329 v3 connections; initiated 1 and received 78 v4 connections; initiated 1090033 and received 6158419 v5 connections.
Jan 11 19:55:47.000 [notice] Heartbeat: DoS mitigation since startup: 1062 circuits killed with too many cells, 3739248 circuits rejected, 1240 marked addresses, 7 marked addresses for max queue, 633 same address concurrent connections rejected, 0 connections rejected, 17 single hop clients refused, 20365797 INTRODUCE2 rejected.
Jan 11 20:55:47.000 [notice] Heartbeat: Tor's uptime is 41 days 9:00 hours, with 65342 circuits open. I've sent 24839.98 GB and received 23063.91 GB. I've received 8159587 connections on IPv4 and 768038 on IPv6. I've made 2451655 connections with IPv4 and 413461 with IPv6.
...
Jan 11 20:55:47.000 [notice] Heartbeat: DoS mitigation since startup: 1062 circuits killed with too many cells, 3744298 circuits rejected, 1245 marked addresses, 7 marked addresses for max queue, 633 same address concurrent connections rejected, 75 connections rejected, 17 single hop clients refused, 20365797 INTRODUCE2 rejected.
...
Jan 11 21:55:47.000 [notice] Heartbeat: Tor's uptime is 41 days 10:00 hours, with 42592 circuits open. I've sent 24844.89 GB and received 23067.80 GB. I've received 8167429 connections on IPv4 and 768372 on IPv6. I've made 2454157 connections with IPv4 and 414023 with IPv6.