On 12 Feb (19:44:02 UTC), David Goulet wrote:
Wow... 1599323088 bytes is insane. This should _not_ happen for only 1 circuit. We actually have checks in place to avoid this but it seems they either totally failed or we have a edge case.
Can you tell me what scheduler were you using (look for "Scheduler" in the notice log).
Any warnings in the logs that you could share or everything was normal?
Finally, if you can share the OS you are running this relay and if Linux, the kernel version.
Don't know if it's relevant but my relay was hit in similar fashion in December. Running 0.2.9.14 (no KIST) on Linux at the time (no other related log messages, MaxMemInQueues=1GB reduced from 2GB after OOM termination):
Dec 15 15:28:52 Tor[]: assign_to_cpuworker failed. Ignoring. Dec 15 15:48:16 Tor[]: assign_to_cpuworker failed. Ignoring. Dec 15 16:39:44 Tor[]: We're low on memory. Killing circuits with over-long queues. (This behavior is controlled by MaxMemInQueues.) Dec 15 17:39:45 Tor[]: Removed 442695264 bytes by killing 1 circuits; 18766 circuits remain alive. Also killed 0 non-linked directory connections. Dec 15 19:03:22 Tor[]: We're low on memory. Killing circuits with over-long queues. (This behavior is controlled by MaxMemInQueues.) Dec 15 19:03:23 Tor[]: Removed 1060505952 bytes by killing 1 circuits; 19865 circuits remain alive. Also killed 0 non-linked directory connections.
More recently (and more reasonably, MaxMemInQueues=512MB), running 0.3.2.9:
Feb 4 20:12:39 Tor[]: Scheduler type KIST has been enabled. Feb 6 08:12:41 Tor[]: Heartbeat: Tor's uptime is 1 day 11:59 hours. I've sent 29.00 MB and received 364.99 MB. Feb 6 14:04:43 Tor[]: We're low on memory. Killing circuits with over-long queues. (This behavior is controlled by MaxMemInQueues.) Feb 6 14:04:43 Tor[]: Removed 166298880 bytes by killing 2 circuits; 20213 circuits remain alive. Also killed 0 non-linked directory connections. Feb 6 14:11:17 Tor[]: Heartbeat: Tor's uptime is 1 day 17:59 hours, with 20573 circuits open. I've sent 910.29 GB and received 902.58 GB. Feb 6 14:11:17 Tor[]: Circuit handshake stats since last time: 1876499/3018306 TAP, 4322015/4322131 NTor. Feb 6 14:11:17 Tor[]: Since startup, we have initiated 0 v1 connections, 0 v2 connections, 1 v3 connections, and 23846 v4 connections; and received 6 v1 connections, 7844 v2 connections, 11906 v3 connections, and 214565 v4 connections. Feb 6 14:12:41 Tor[]: Heartbeat: Tor's uptime is 1 day 17:59 hours. I've sent 31.62 MB and received 420.63 MB. Feb 6 14:22:50 Tor[]: We're low on memory. Killing circuits with over-long queues. (This behavior is controlled by MaxMemInQueues.) Feb 6 14:22:50 Tor[]: Removed 181501584 bytes by killing 2 circuits; 19078 circuits remain alive. Also killed 0 non-linked directory connections. Feb 6 15:01:50 Tor[]: We're low on memory. Killing circuits with over-long queues. (This behavior is controlled by MaxMemInQueues.) Feb 6 15:01:50 Tor[]: Removed 105918912 bytes by killing 1 circuits; 19679 circuits remain alive. Also killed 0 non-linked directory connections. Feb 6 15:46:24 Tor[]: Channel padding timeout scheduled 157451ms in the past. Feb 6 19:30:36 Tor[]: new bridge descriptor 'Binnacle' (fresh): $4F0DB7E687FC7C0AE55C8F243DA8B0EB27FBF1F2~Binnacle at 108.53.208.157 Feb 6 20:11:17 Tor[]: Heartbeat: Tor's uptime is 1 day 23:59 hours, with 18045 circuits open. I've sent 1043.74 GB and received 1034.65 GB. Feb 6 20:11:17 Tor[]: Circuit handshake stats since last time: 260970/368918 TAP, 3957087/3957791 NTor.
Perhaps this indicates some newer KIST mitigation logic is effective.