memory leak issue in rails and phusion passenger
memory-leaks, passenger, ruby-on-rails
Solution
- First of all, hot fix the immediate production problem, implement a watchdog - http://dev.mensfeld.pl/2012/08/simple-rubyrails-passenger-memory-consumption-limit-monitoring/ and then hunt for the leak, or bloat (https://blog.engineyard.com/2009/thats-not-a-memory-leak-its-bloat)
- That process you showed looks like a regular worker, try killing the offending process under controlled conditions, see what happens, probably nothing bad.
- See if you can correlate this happening with a certain (often long running) controller action, or apache restarts/reloads (have this problem on regular basis, 1 in 20 processes goes bonkers after restart).
- Extend rails logs so they contain PIDs (https://gist.github.com/krutten/1091611 for example) and make a simple script that dumps memory use into a file every minute or so (make sure you don't fill your disk) - this will enable you to know exactly when a process started bloating and then trace in the logs what it was doing before/as this happened
Problem
The rails site was running so slow that I had to reboot the os, but after only 1 hour after rebooting ubuntu, the system was incredible slow again, so I checked the passenger memory statistics: ``` ------ Passenger processes ------ PID VMSize Private Name --------------------------------- 1076 215.8 MB 0.3 MB PassengerWatchdog 1085 2022.3 MB 4.4 MB PassengerHelperAgent 1089 109.4 MB 6.4 MB Passenger spawn server 1093 159.2 MB 0.8 MB PassengerLoggingAgent 1883 398.1 MB 110.1 MB Rack: /home/guarddog/public_html/guarddog.com/current 1906 1174.6 MB 885.9 MB Rack: /home/guarddog/public_html/guarddog.com/current 3648 370.1 MB 131.9 MB Rack: /home/guarddog/public_html/guarddog.com/current 14830 370.6 MB 83.0 MB Rack: /home/guarddog/public_html/guarddog.com/current 15124 401.2 MB 113.9 MB Rack: /home/guarddog/public_html/guarddog.com/current 15239 413.5 MB 127.7 MB Rack: /home/guarddog/public_html/guarddog.com/current 15277 400.5 MB 113.6 MB Rack: /home/guarddog/public_html/guarddog.com/current 15285 357.1 MB 70.1 MB Rack: /home/guarddog/public_html/guarddog.com/current ### Processes: 12 ### Total private dirty RSS: 1648.10 MB ``` It boggles my mind how that one rack process is using 885.9 MB of private dirty RSS memory after one hour of rebooting the OS when usage was down to 100 mb total. Now one hour later it's at 1648.10 mb. The site is so slow the page won't even load. I assume it's a memory leak so I added this line of code throughout the application: ``` puts "Object count: #{ObjectSpace.count_objects}" ``` But I do not know how to interpret the data it gives me: ``` Object count: {:TOTAL=>2379635, :FREE=>318247, :T_OBJECT=>35074, :T_CLASS=>6707, :T_MODULE=>1760, :T_FLOAT=>174, :T_STRING=>1777046, :T_REGEXP=>2821, :T_ARRAY=>75160, :T_HASH=>64227, :T_STRUCT=>774, :T_BIGNUM=>7, :T_FILE=>7, :T_DATA=>55075, :T_MATCH=>10, :T_COMPLEX=>1, :T_RATIONAL=>63, :T_NODE=>37652, :T_ICLASS=>4830} ``` Note I only running that ObjectSpace.count_objects on my local machine since my ubuntu server is so slow it cannot even load the page. Here's some other OS statistics: ``` $ cat /proc/meminfo MemTotal: 6113156 kB MemFree: 3027204 kB Buffers: 103540 kB Cached: 261544 kB SwapCached: 0 kB Active: 2641168 kB Inactive: 248316 kB Active(anon): 2524652 kB Inactive(anon): 328 kB Active(file): 116516 kB Inactive(file): 247988 kB Unevictable: 0 kB Mlocked: 0 kB SwapTotal: 6287356 kB SwapFree: 6287356 kB Dirty: 36 kB Writeback: 0 kB AnonPages: 2524444 kB Mapped: 30108 kB Shmem: 568 kB Slab: 77268 kB SReclaimable: 48528 kB SUnreclaim: 28740 kB KernelStack: 4648 kB PageTables: 43044 kB NFS_Unstable: 0 kB Bounce: 0 kB WritebackTmp: 0 kB CommitLimit: 9343932 kB Committed_AS: 5179468 kB VmallocTotal: 34359738367 kB VmallocUsed: 293056 kB VmallocChunk: 34359442172 kB HardwareCorrupted: 0 kB AnonHugePages: 0 kB HugePages_Total: 0 HugePages_Free: 0 HugePages_Rsvd: 0 HugePages_Surp: 0 Hugepagesize: 2048 kB DirectMap4k: 46848 kB DirectMap2M: 5195776 kB df Filesystem 1K-blocks Used Available Use% Mounted on /dev/mapper/roadrunner-root 134821120 22277596 105695012 18% / udev 3047064 4 3047060 1% /dev tmpfs 1222632 252 1222380 1% /run none 5120 0 5120 0% /run/lock none 3056576 88 3056488 1% /run/shm none 102400 0 102400 0% /run/user /dev/sda1 233191 29079 191671 14% /boot ``` On a side note, if I run "kill -9 1906" to kill that one rack process consuming so much memory, would that help?