UPD: this question was regarding an older version of Tor (0.2.4.24). With a newer version (which was 0.2.7.2-alpha for me) the problem disappeared.
I am running Tor (0.2.4.24) relay on Raspberry Pi (Raspbian). Once every 5-10 days the Tor daemon disappears and I have to restart it manually. I looked into the recent occurrence and found the following.
Atlas says there were bursts of activity before the disappearance:
The bursts occupied the entire relay bandwidth (80k).
dmesg
says there were too many connections:[Thu Jan 29 16:24:22 2015] smsc95xx 1-1.1:1.0 eth0: kevent 2 may have been dropped ... several lines like this ... [Thu Jan 29 16:40:02 2015] TCP: TCP: Possible SYN flooding on port 80. Sending cookies. Check SNMP counters. [Thu Jan 29 16:50:49 2015] net_ratelimit: 3123 callbacks suppressed
This repeated several times before
oom_killer
was invoked and killedtor
. (80 is my dir port.)The last heartbeat lines in the Tor log before the killing were:
Jan 30 13:59:14.000 [notice] Heartbeat: Tor's uptime is 6 days 6:00 hours, with 2110 circuits open. I've sent 2.17 GB and received 4.69 GB. Jan 30 13:59:14.000 [notice] Average packaged cell fullness: 59.734% Jan 30 13:59:14.000 [notice] TLS write overhead: 15% Jan 30 13:59:14.000 [notice] Circuit handshake stats since last time: 21494/483370 TAP, 26089/56472 NTor.
Before the bursts started, the log was saying:
Jan 29 13:59:14.000 [notice] Heartbeat: Tor's uptime is 5 days 6:00 hours, with 140 circuits open. I've sent 1.17 GB and received 1.28 GB. Jan 29 13:59:14.000 [notice] Average packaged cell fullness: 71.691% Jan 29 13:59:14.000 [notice] TLS write overhead: 9% Jan 29 13:59:14.000 [notice] Circuit handshake stats since last time: 9509/9531 TAP, 2044/2045 NTor.
Note the difference in TAP and NTor values in just one day.
So two questions:
Was it an attack? Or was it just a normal burst of load?
How to configure Tor relay in Raspbian to avoid it dying like this? Would it help configuring parameters such as
MaxOnionQueueDelay
andMaxMemInQueues
?
Continued
After making the initial post, I have enabled full debug log and started the relay. It took it about a month to crash. This time, bandwidth utilization did not show anything very suspicious:
But the debug log before the crash is:
pi@raspberrypi ~ $ tail -n5000 /var/log/tor/debug.log.1 | grep info
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 3976204747 on connection from 83.150.17.132:9001. Dropping.
Mar 04 16:04:13.000 [info] onion_pending_add(): New create (tap). Queues now ntor=0 and tap=48.
Mar 04 16:04:13.000 [info] onion_pending_add(): New create (tap). Queues now ntor=0 and tap=49.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2234508755 on connection from 37.187.103.91:9001. Dropping.
Mar 04 16:04:13.000 [info] onion_pending_add(): New create (tap). Queues now ntor=0 and tap=49.
Mar 04 16:04:13.000 [info] onion_pending_add(): New create (tap). Queues now ntor=0 and tap=50.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 4119 on connection from 78.47.40.27:31337. Dropping.
Mar 04 16:04:13.000 [info] onion_pending_add(): New create (tap). Queues now ntor=0 and tap=49.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 4200846799 on connection from 92.222.162.54:9001. Dropping.
Mar 04 16:04:13.000 [info] onion_pending_add(): New create (tap). Queues now ntor=0 and tap=50.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2147509313 on connection from 131.188.24.14:9001. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2385798363 on connection from 37.187.124.132:9001. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2219568803 on connection from 198.50.191.95:443. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 4229259436 on connection from 77.37.240.142:443. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2147502825 on connection from 31.11.241.132:9001. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2147505465 on connection from 85.176.225.121:9001. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2147506490 on connection from 213.185.227.85:9001. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2147508804 on connection from 94.23.20.190:9001. Dropping.
Mar 04 16:04:13.000 [info] channel_register(): Channel 0xb0a12af8 (global ID 649941) in state opening (1) registered with no identity digest
Mar 04 16:04:13.000 [info] onion_next_task(): Processing create (tap). Queues now ntor=0 and tap=49.
Mar 04 16:04:13.000 [info] onion_pending_add(): New create (tap). Queues now ntor=0 and tap=50.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2147515156 on connection from 212.129.42.9:443. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 3358448687 on connection from 82.223.11.56:9001. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 2259723728 on connection from 5.9.123.81:9001. Dropping.
Mar 04 16:04:13.000 [info] command_process_destroy_cell(): unknown circuit 3130707707 on connection from 109.169.45.226:9001. Dropping.
Mar 04 16:04:13.000 [info] onion_pending_add(): New create (tap). Queues now ntor=0 and tap=50.
There are many TAP connections and unknown circuits that are dropped. There is nothing like this in the beginning of the log on the same day. This behavior looks abnormal to me, I lack the knowledge of Tor to interpret it so far (Tor gurus, ahoy!). To be continued.