Out of memory message
I run the relay Logforme (855BC2DABE24C861CD887DB9B2E950424B49FC3). Yesterday I saw new messages in the log file: Dec 06 09:28:13.000 [notice] We're low on memory. Killing circuits with over-long queues. (This behavior is controlled by MaxMemInQueues.) Dec 06 09:28:16.000 [notice] Removed 1040388096 bytes by killing 1 circuits; 14631 circuits remain alive. Do I read that correctly as one circuit using 1GB of memory? Here's the first lines from the top command: top - 09:40:41 up 31 days, 1:51, 1 user, load average: 0.53, 0.62, 0.66 Tasks: 95 total, 3 running, 92 sleeping, 0 stopped, 0 zombie %Cpu(s): 10.2 us, 2.0 sy, 0.0 ni, 83.2 id, 0.0 wa, 0.0 hi, 4.5 si, 0.0 st KiB Mem: 3950828 total, 3833092 used, 117736 free, 49696 buffers KiB Swap: 3212284 total, 1296392 used, 1915892 free, 99168 cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2680 debian-t 20 0 4134m 2.8g 24m R 63.5 73.4 27199:00 tor The relay is running on a dedicated debian box with 4GB of ram. It usually only uses about 0.5GB but now it is maxed out. The relay and the box is so far working fine, I just wonder if this is some kind of attack or if anything is wrong and if there is anything I should do about it.
On Sun, Dec 07, 2014 at 09:52:47AM +0100, Logforme wrote:
I run the relay Logforme (855BC2DABE24C861CD887DB9B2E950424B49FC3). Yesterday I saw new messages in the log file: Dec 06 09:28:13.000 [notice] We're low on memory. Killing circuits with over-long queues. (This behavior is controlled by MaxMemInQueues.) Dec 06 09:28:16.000 [notice] Removed 1040388096 bytes by killing 1 circuits; 14631 circuits remain alive.
Do I read that correctly as one circuit using 1GB of memory?
Wow! Never thought I'd see that in practice.
The relay and the box is so far working fine, I just wonder if this is some kind of attack or if anything is wrong and if there is anything I should do about it.
Actually what you're seeing is a defense to an attack: Rob explains it well at https://blog.torproject.org/blog/new-tor-denial-service-attacks-and-defenses Of course, it's also possible that this behavior occurred naturally in some way. Has anybody else here seen messages like this? --Roger
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On 07.12.2014 12:20, Roger Dingledine wrote:
Has anybody else here seen messages like this?
Some days ago I had a message like that on my relay JPsi2 (F6EC46933CE8D4FAD5CCDAA8B1C5A377685FC521). Tor's memory consumption is rather high there lately. On December 1st, the tor process' memory consumption went up and up until the Linux kernel decided to kill it. Monit has subsequently restarted it, and it settles at roughly 1.7 GB since then. The logs of the corresponding days have already been rotated out, so I cannot post the exact messages I'm afraid. On my other relay Bazinga (B198C0B4B8C551F174FBB841A172616E3DB3124D), the tor process typically uses 0.7 GB memory and did not experience anything like that. Both relays are running at 100 Mbit/s and have 2 GB memory. -----BEGIN PGP SIGNATURE----- Version: GnuPG v1 iQIcBAEBAgAGBQJUhEI5AAoJEJe61A/xrcOQb6AP/1QmzXkXD8i6kXIyYH1ME4nz UrjeIhVRVaAXHqnzsc4V5VOYMN1cifjTYtVph5nZUiEaq1j1TqM0fvHE8D9u7Tlk 2Okp1/KmvCNCWx/bsyZYqTeXMSBtqDqPVDtBd/4k+hRG2dnnp9JbaRZJk03nrY9m AQnF0kOp5Eg6Cl0qcOViLzxJBcdboYFeQoGGV5s0mgjXJLubhGsFIAuZXH7Luszn RdxcRXM9R0iOsRgHyyZ+QXNVdWFWcuDjfm9HxQhUFlBFYoJj2QBbpm+KXNODJatZ iimW9sZ+y9VJ+Hgfztf01GQwpu6E0CjzpdNzjz748Z57Jy026yYXmYzLh8XTDrlv yQ6PwHtzqLvnBuEzvnTxG+IbixVL+qyUXW3jvu/ECCVT3lZHkHjHLI/MNbpkVif/ oM9m5ZnDqIAEcQwbY4Z340938jtlXVlhNFTMBluTZPtG2Fpn96hixuN4QoEhJv6z 9OZLpEPtJWpdxb9RHchmjSUekxHHC4lATEDmBPOa53vm4xByepV5qe5/C1hxSUGl TGi3T1tPswmqotB7V3BKsf0CdOYtoAEmZrLJzCJ3sZD1MgY05rx9vS6f9jRlRIBi WFP14EgoVOgpKxp216WVr8PKxjX2q5pVSHqAkswq8l/cis7sj9ln9c0/H3OIhHAZ +onzOLff/vDzlOrbjcQu =8PfV -----END PGP SIGNATURE-----
On 2014-12-07 12:20, Roger Dingledine wrote:
Has anybody else here seen messages like this?
I looked through the old log files and found the following memory messages: Dec 06 03:33:06.000 [notice] Removed 334229280 bytes by killing 1 circuits; 16401 circuits remain alive. Dec 06 05:27:25.000 [notice] Removed 476998896 bytes by killing 1 circuits; 15628 circuits remain alive. Dec 06 06:08:35.000 [notice] Removed 536296464 bytes by killing 1 circuits; 16215 circuits remain alive. Dec 06 06:56:58.000 [notice] Removed 583650144 bytes by killing 1 circuits; 15617 circuits remain alive. Dec 06 07:55:57.000 [notice] Removed 857511072 bytes by killing 1 circuits; 15423 circuits remain alive. Dec 06 09:28:16.000 [notice] Removed 1040388096 bytes by killing 1 circuits; 14631 circuits remain alive. To me it looks like an attacker that ramped up over a 6 hour period and then stopped building new circuits. Since the tor process still uses all available memory (more than 24 hours later) I guess the attacker still holds some circuits open. To what end I can't understand. He failed to crash the relay but wants to occupy my RAM? :)
On Sun, Dec 07, 2014 at 01:43:46PM +0100, Logforme wrote:
To me it looks like an attacker that ramped up over a 6 hour period and then stopped building new circuits. Since the tor process still uses all available memory (more than 24 hours later) I guess the attacker still holds some circuits open.
Careful with your conclusion there -- because of memory fragmentation, the process can still hold the memory even when Tor has freed the memory. That happens because some part of the memory page is in use and some is freed, but since not all of it is freed the allocator doesn't take it back. Some quick searches point to https://www.ibm.com/developerworks/community/blogs/kevgrig/entry/linux_nativ... as what looks like a nice summary of the issue. --Roger
On 2014-12-10 08:31, Roger Dingledine wrote:
Careful with your conclusion there -- because of memory fragmentation, the process can still hold the memory even when Tor has freed the memory. htop currently shows 3622/3858 Mem used and 1545/3136 Swap used. (if I remember correctly it's usually less than 1000 Mem and 0 Swap used). So the attacker (intentional or accidental) actually managed to make Tor take all free memory on the machine before the MaxMemInQueues function stepped in. And now I have no way to release that memory short of restarting tor. If I used the machine for something apart from tor it would have been a successful attack. Guess I need to set the MaxMemInQueues parameter to something other than 0, maybe 2GB? What's the "reasonable default" for MaxMemInQueues? Some percentage of total RAM?
https://gitweb.torproject.org/tor.git/commit/?id=17ecd04fde2fd98b0cca3afb251... On 10 December 2014 at 17:57, Logforme <m7527@abc.se> wrote:
On 2014-12-10 08:31, Roger Dingledine wrote:
Careful with your conclusion there -- because of memory fragmentation, the process can still hold the memory even when Tor has freed the memory. htop currently shows 3622/3858 Mem used and 1545/3136 Swap used. (if I remember correctly it's usually less than 1000 Mem and 0 Swap used). So the attacker (intentional or accidental) actually managed to make Tor take all free memory on the machine before the MaxMemInQueues function stepped in. And now I have no way to release that memory short of restarting tor. If I used the machine for something apart from tor it would have been a successful attack. Guess I need to set the MaxMemInQueues parameter to something other than 0, maybe 2GB? What's the "reasonable default" for MaxMemInQueues? Some percentage of total RAM?
tor-relays mailing list tor-relays@lists.torproject.org https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-relays
On Wed, Dec 10, 2014 at 2:31 AM, Roger Dingledine <arma@mit.edu> wrote:
On Sun, Dec 07, 2014 at 01:43:46PM +0100, Logforme wrote:
To me it looks like an attacker that ramped up over a 6 hour period and then stopped building new circuits. Since the tor process still uses all available memory (more than 24 hours later) I guess the attacker still holds some circuits open.
Careful with your conclusion there -- because of memory fragmentation, the process can still hold the memory even when Tor has freed the memory. That happens because some part of the memory page is in use and some is freed, but since not all of it is freed the allocator doesn't take it back.
Some quick searches point to https://www.ibm.com/developerworks/community/blogs/kevgrig/entry/linux_nativ... as what looks like a nice summary of the issue.
--Roger
If this *is* memory fragmentation, one possible reason why it would have started appearing recently might be that we turned the freelist code off by default in 0.2.5, on the theory that it should be safer to do that than not. https://trac.torproject.org/projects/tor/ticket/11476 has more background here. I don't think it's the likeliest explanation, but it's worth examining. Are the people experiencing this issue using similar allocators? -- Nick
On 2014-12-15 19:43, Nick Mathewson wrote:
On Wed, Dec 10, 2014 at 2:31 AM, Roger Dingledine <arma@mit.edu> wrote:
On Sun, Dec 07, 2014 at 01:43:46PM +0100, Logforme wrote:
To me it looks like an attacker that ramped up over a 6 hour period and then stopped building new circuits. Since the tor process still uses all available memory (more than 24 hours later) I guess the attacker still holds some circuits open. Careful with your conclusion there -- because of memory fragmentation, the process can still hold the memory even when Tor has freed the memory. That happens because some part of the memory page is in use and some is freed, but since not all of it is freed the allocator doesn't take it back.
Some quick searches point to https://www.ibm.com/developerworks/community/blogs/kevgrig/entry/linux_nativ... as what looks like a nice summary of the issue.
--Roger If this *is* memory fragmentation, one possible reason why it would have started appearing recently might be that we turned the freelist code off by default in 0.2.5, on the theory that it should be safer to do that than not.
https://trac.torproject.org/projects/tor/ticket/11476 has more background here. I don't think it's the likeliest explanation, but it's worth examining.
Are the people experiencing this issue using similar allocators?
I don't build Tor myself, I use the latest debian package: 0.2.5.10-1~d70. No idea how that is built. I have not restarted Tor so it is still hogging all ram + swap (relay works fine so no reason to restart). If there is anything I can run to get more information about what has happened (code dump maybe?), I'm happy to do so.
participants (5)
-
Logforme -
Nick Mathewson -
Random Tor Node Operator -
Roger Dingledine -
usprey