Raspberry Pi 3: Tor killed & restart

Support Relay Operator
1

My Tor relay restarted due to some unknown problem:

Aug 22 04:59:49 rasptor Tor[682]: Auto-discovered IPv6 address [2001:a61:3043:501:30e4:5b28:5dda:33a6]:9001 has not been found reachable. However, IPv4 address is reachable. Publishing server descriptor without IPv6 address. [2 similar message(s) suppressed in last 2400 seconds]
Aug 22 05:52:22 rasptor Tor[682]: No circuits are opened. Relaxed timeout for circuit 127544 (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. [17 similar message(s) suppressed in last 3540 seconds]
Aug 22 06:00:07 rasptor Tor[682]: Auto-discovered IPv6 address [2001:a61:3043:501:30e4:5b28:5dda:33a6]:9001 has not been found reachable. However, IPv4 address is reachable. Publishing server descriptor without IPv6 address. [2 similar message(s) suppressed in last 2460 seconds]
Aug 22 06:12:21 rasptor systemd[1]: tor@default.service: Main process exited, code=killed, status=9/KILL
Aug 22 06:12:21 rasptor systemd[1]: tor@default.service: Failed with result 'signal'.
Aug 22 06:12:21 rasptor systemd[1]: tor@default.service: Consumed 1d 7h 20min 34.459s CPU time.
Aug 22 06:12:21 rasptor systemd[1]: tor@default.service: Scheduled restart job, restart counter is at 2.
Aug 22 06:12:21 rasptor systemd[1]: Stopped tor@default.service - Anonymizing overlay network for TCP.
Aug 22 06:12:21 rasptor systemd[1]: tor@default.service: Consumed 1d 7h 20min 34.459s CPU time.
Aug 22 06:12:21 rasptor systemd[1]: Starting tor@default.service - Anonymizing overlay network for TCP

The relevant parts of the Tor log are obviously

Main process exited, code=killed, status=9/KILL
Failed with result 'signal'.

journalctl seems to report a blocked task and a memory issue, if I understand this correctly.

I guess this will be recurring periodically. The Tor process is the only process that uses a high amount of memory.

How can I change the setup so this won’t happen anymore?

Maybe working as Directory Authority causes this high memory consumption?

For now I wait to see whether it happens again, and if so, then I’d disable the Directory service feature?

Aug 22 06:09:39 rasptor kernel: INFO: task kworker/1:2:11456 blocked for more than 120 seconds.
Aug 22 06:12:21 rasptor kernel:       Tainted: G         C         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
Aug 22 06:12:21 rasptor kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 22 06:12:21 rasptor kernel: task:kworker/1:2     state:D stack:0     pid:11456 ppid:2      flags:0x00000008
Aug 22 06:12:21 rasptor kernel: Workqueue: events_freezable mmc_rescan
Aug 22 06:12:21 rasptor kernel: Call trace:
Aug 22 06:12:21 rasptor kernel:  __switch_to+0xe8/0x168
Aug 22 06:12:21 rasptor kernel:  __schedule+0x37c/0xd60
Aug 22 06:12:21 rasptor kernel:  schedule+0x64/0x108
Aug 22 06:12:21 rasptor kernel:  __mmc_claim_host+0xe0/0x210
Aug 22 06:12:21 rasptor kernel:  mmc_get_card+0x3c/0x58
Aug 22 06:12:21 rasptor kernel:  mmc_sd_detect+0x28/0xa0
Aug 22 06:12:21 rasptor kernel:  mmc_rescan+0x94/0x328
Aug 22 06:12:21 rasptor kernel:  process_one_work+0x148/0x3b8
Aug 22 06:12:21 rasptor kernel:  worker_thread+0x32c/0x450
Aug 22 06:12:21 rasptor kernel:  kthread+0x11c/0x128
Aug 22 06:12:21 rasptor kernel:  ret_from_fork+0x10/0x20
Aug 22 06:12:21 rasptor kernel: INFO: task kworker/1:2:11456 blocked for more than 241 seconds.
Aug 22 06:12:21 rasptor kernel:       Tainted: G         C         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
Aug 22 06:12:21 rasptor kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 22 06:12:21 rasptor kernel: task:kworker/1:2     state:D stack:0     pid:11456 ppid:2      flags:0x00000008
Aug 22 06:12:21 rasptor kernel: Workqueue: events_freezable mmc_rescan
Aug 22 06:12:21 rasptor kernel: Call trace:
Aug 22 06:12:21 rasptor kernel:  __switch_to+0xe8/0x168
Aug 22 06:12:21 rasptor kernel:  __schedule+0x37c/0xd60
Aug 22 06:12:21 rasptor kernel:  schedule+0x64/0x108
Aug 22 06:12:21 rasptor kernel:  __mmc_claim_host+0xe0/0x210
Aug 22 06:12:21 rasptor kernel:  mmc_get_card+0x3c/0x58
Aug 22 06:12:21 rasptor kernel:  mmc_sd_detect+0x28/0xa0
Aug 22 06:12:21 rasptor kernel:  mmc_rescan+0x94/0x328
Aug 22 06:12:21 rasptor kernel:  process_one_work+0x148/0x3b8
Aug 22 06:12:21 rasptor kernel:  worker_thread+0x32c/0x450
Aug 22 06:12:21 rasptor kernel:  kthread+0x11c/0x128
Aug 22 06:12:21 rasptor kernel:  ret_from_fork+0x10/0x20
Aug 22 06:12:21 rasptor kernel: kthreadd invoked oom-killer: gfp_mask=0x2dc2(GFP_KERNEL|__GFP_HIGHMEM|__GFP_NOWARN|__GFP_ZERO), order=0, oom_score_adj=0
Aug 22 06:12:21 rasptor kernel: CPU: 0 PID: 2 Comm: kthreadd Tainted: G         C         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
Aug 22 06:12:21 rasptor kernel: Hardware name: Raspberry Pi 3 Model B Plus Rev 1.3 (DT)
Aug 22 06:12:21 rasptor kernel: Call trace:
Aug 22 06:12:21 rasptor kernel:  dump_backtrace+0xa0/0x100
Aug 22 06:12:21 rasptor kernel:  show_stack+0x20/0x38
Aug 22 06:12:21 rasptor kernel:  dump_stack_lvl+0x48/0x60
Aug 22 06:12:21 rasptor kernel:  dump_stack+0x18/0x28
Aug 22 06:12:21 rasptor kernel:  dump_header+0x48/0x230
Aug 22 06:12:21 rasptor kernel:  oom_kill_process+0x140/0x2e8
Aug 22 06:12:21 rasptor kernel:  out_of_memory+0xe4/0x358
Aug 22 06:12:21 rasptor kernel:  __alloc_pages+0xaec/0xe68
Aug 22 06:12:21 rasptor kernel:  __alloc_pages_bulk+0x368/0x6e0
Aug 22 06:12:21 rasptor kernel:  __vmalloc_node_range+0x1f4/0x7a8
Aug 22 06:12:21 rasptor kernel:  copy_process+0x544/0x15b0
Aug 22 06:12:21 rasptor kernel:  kernel_clone+0x9c/0x448
Aug 22 06:12:21 rasptor kernel:  kernel_thread+0x84/0xc0
Aug 22 06:12:21 rasptor kernel:  kthreadd+0x148/0x1d0
Aug 22 06:12:21 rasptor kernel:  ret_from_fork+0x10/0x20
Aug 22 06:12:21 rasptor kernel: Mem-Info:
Aug 22 06:12:21 rasptor kernel: active_anon:188602 inactive_anon:1104 isolated_anon:0
                                 active_file:517 inactive_file:106 isolated_file:0
                                 unevictable:4551 dirty:0 writeback:0
                                 slab_reclaimable:4748 slab_unreclaimable:10744
                                 mapped:3590 shmem:55787 pagetables:678
                                 sec_pagetables:0 bounce:0
                                 kernel_misc_reclaimable:0
                                 free:11061 free_pcp:226 free_cma:8182
Aug 22 06:12:21 rasptor kernel: Node 0 active_anon:754408kB inactive_anon:755288kB active_file:2268kB inactive_file:424kB unevictable:18204kB isolated(anon):0kB isolated(file):0kB mapped:14>
Aug 22 06:12:21 rasptor kernel: DMA free:44244kB boost:0kB min:16384kB low:20480kB high:24576kB reserved_highatomic:0KB active_anon:3536kB inactive_anon:755288kB active_file:1236kB inactive>
Aug 22 06:12:21 rasptor kernel: lowmem_reserve[]: 0 0 0 0
Aug 22 06:12:21 rasptor kernel: DMA: 20*4kB (UEC) 2355*8kB (UEC) 701*16kB (UEC) 95*32kB (UEC) 18*64kB (UEC) 19*128kB (UE) 7*256kB (UE) 3*512kB (UE) 2*1024kB (UE) 1*2048kB (U) 0*4096kB = 441>
Aug 22 06:12:21 rasptor kernel: 58657 total pagecache pages
Aug 22 06:12:21 rasptor kernel: 260 pages in swap cache
Aug 22 06:12:21 rasptor kernel: Free swap  = 200kB
Aug 22 06:12:21 rasptor kernel: Total swap = 204796kB
Aug 22 06:12:21 rasptor kernel: 242688 pages RAM
Aug 22 06:12:21 rasptor kernel: 0 pages HighMem/MovableOnly
Aug 22 06:12:21 rasptor kernel: 10413 pages reserved
Aug 22 06:12:21 rasptor kernel: 65536 pages cma reserved
Aug 22 06:12:21 rasptor kernel: Tasks state (memory values in pages):
Aug 22 06:12:21 rasptor kernel: [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
Aug 22 06:12:21 rasptor kernel: [    230]     0   230     6905      416    65536      192          -250 systemd-journal
Aug 22 06:12:21 rasptor kernel: [    250]     0   250     6577      296    65536      576         -1000 systemd-udevd
Aug 22 06:12:21 rasptor kernel: [    430]     0   430     1673      320    45056       32             0 cron
Aug 22 06:12:21 rasptor kernel: [    431]   100   431     2266      416    53248      128          -900 dbus-daemon
Aug 22 06:12:21 rasptor kernel: [    434]   996   434    58829      224    81920      192             0 polkitd
Aug 22 06:12:21 rasptor kernel: [    448]     0   448     6351      448    69632      192             0 systemd-logind
Aug 22 06:12:21 rasptor kernel: [    491]     0   491    65633      800   155648      480             0 NetworkManager
Aug 22 06:12:21 rasptor kernel: [    492]     0   492     4317      672    69632      320             0 wpa_supplicant
Aug 22 06:12:21 rasptor kernel: [    500]     0   500    80858      160   122880      480             0 ModemManager
Aug 22 06:12:21 rasptor kernel: [    539]     0   539    28004      288   106496     2272             0 unattended-upgr
Aug 22 06:12:21 rasptor kernel: [    584]     0   584     4083      480    65536      320         -1000 sshd
Aug 22 06:12:21 rasptor kernel: [    679]     0   679     1405      224    45056        0             0 agetty
Aug 22 06:12:21 rasptor kernel: [    682]   106   682   218256   134865  1658880    13888             0 tor
Aug 22 06:12:21 rasptor kernel: [   7598]   107  7598    21068     4489    73728        0             0 ntpd
Aug 22 06:12:21 rasptor kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/,task=tor,pid=682,uid=106
Aug 22 06:12:21 rasptor kernel: Out of memory: Killed process 682 (tor) total-vm:873024kB, anon-rss:529184kB, file-rss:3584kB, shmem-rss:6692kB, UID:106 pgtables:1620kB oom_score_adj:0
2

Just thought I’d add, that option is to mirror the relay directory list. Directory authorities are the authorities that monitor and regulate relays.

3

A Pi3 is a bit of a meager solution to run a bridge it only has 1 Gbyte of memory, personally I would never run a bridge from a residential situation, I did run Snowflake from a Pi3 and it’s already hard on the CPU with about 8-10 concurrent connections during busy times. Perhaps running Snowflake with a maximum of 16 connections (-capacity 16) is a better use for your hardware, otherwise consider to upgrade to a Pi5 (with 8 Gbyte), that one is much harder to bring on its knees.

4

I remember I’ve tweaked iptables and torrc on a RPi 1 due to the number of connections that were overwhelming the RPi 1.

I’m running a regular non-exit relay (no bridge) and so far (it’s < 2 weeks old) the CPU seems to be sufficient.
The memory seems to be a problem, and possibly could be fixed by not mirroring the directory (because I use RAM for what I suppose is the directory data). The requirements for running a relay are basically met by the RPi3 – however a part of the RAM goes to some tpmfs to avoid writes on the Flash memory.

5

Right, my other post reflects that correctly, but here that’s misleading. Of course my relay only works as a directory mirror, not as a Directory Authority.

6

Not being a directory mirror saves lots of memory (since I put the accumulating data into a tmpfs) and seems to fix the issue at the cost of losing this feature.