Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ActionView's memory leak #22580

Closed
panasyuk opened this issue Dec 14, 2015 · 4 comments

Comments

Projects
None yet
4 participants
@panasyuk
Copy link

commented Dec 14, 2015

The problem

I noticed that Rails (4.2.3) running on Ruby 2.1.5 has leak in the ActionView::Template class. My Rails applications are eating RAM slowly (it tooks weeks and even months) bite to bite. The reserved memory amount could grow from 130MB to 1.2GB with time (actually i didn't tested if the app could eat more).

Possible Cause

I believe that problem is somehow related to #14301.
This happens when calling ActionView::Template#compile. It evaluates the passed module and defines new method which is responsible for rendering of respective view (see this line). That method's name is in the following format: _app_views_tv_channels__index_json_jbuilder___2694669448214811169_110696640.
Next #compile defines finalizer for the method. The finalizer does the following: it calls #undef_method on the module. Obviously that behavior removes the defined method, but the method's name is still in the symbols storage!

Experiment

Ruby implements method definition along with adding the method name symbol to the symbols storage:

Symbol.all_symbols.size # => 3215
module TestModule; end
Symbol.all_symbols.last # => :TestModule
Symbol.all_symbols.size # => 3216
TestModule.module_eval <<-SRC
def test_method
  puts "test!"
end
SRC
# => :test_method
Symbol.all_symbols.last # => :test_method
Symbol.all_symbols.size # => 3217

Following snippet will undefine test_method. But Ruby 2.1.5 won't clear the method name from the symbols storage:

TestModule.module_exec{ undef_method :test_method } # => TestModule
Symbol.all_symbols.last # => :test_method
Symbol.all_symbols.size # => 3217

Ruby can garbage-collect the unused symbols only from the version 2.2.

Real-life experiment

I added this code to the ApplicationController:

after_action :log_symbols
private
    def log_symbols
      $debug_logger.info "Symbols: #{Symbol.all_symbols.size}"
    end

And started watching the logs:
tail -f symbols.log

...
I, [2015-12-14T17:05:19.144664 #61247]  INFO -- : Symbols: 31854
I, [2015-12-14T17:05:19.890261 #61247]  INFO -- : Symbols: 31861
I, [2015-12-14T17:05:20.250041 #61246]  INFO -- : Symbols: 31757
I, [2015-12-14T17:05:20.251309 #61247]  INFO -- : Symbols: 31861
I, [2015-12-14T17:05:21.059873 #61247]  INFO -- : Symbols: 31974
I, [2015-12-14T17:05:21.324260 #61289]  INFO -- : Symbols: 31664
I, [2015-12-14T17:05:22.172001 #61247]  INFO -- : Symbols: 32208
I, [2015-12-14T17:05:22.303216 #61280]  INFO -- : Symbols: 31850
I, [2015-12-14T17:05:23.035653 #61280]  INFO -- : Symbols: 32176
I, [2015-12-14T17:05:23.569141 #61289]  INFO -- : Symbols: 31664
I, [2015-12-14T17:05:23.590562 #61247]  INFO -- : Symbols: 32208
I, [2015-12-14T17:05:23.742453 #61280]  INFO -- : Symbols: 32300
...

Per-process filtering:
tail -f symbols.log | grep 61247

...
I, [2015-12-14T17:06:14.015410 #61247]  INFO -- : Symbols: 32935
I, [2015-12-14T17:06:18.511491 #61247]  INFO -- : Symbols: 32935
I, [2015-12-14T17:06:20.662393 #61247]  INFO -- : Symbols: 32938
I, [2015-12-14T17:06:21.308758 #61247]  INFO -- : Symbols: 32940
I, [2015-12-14T17:06:26.289432 #61247]  INFO -- : Symbols: 32940
I, [2015-12-14T17:06:26.379743 #61247]  INFO -- : Symbols: 32940
I, [2015-12-14T17:06:27.685183 #61247]  INFO -- : Symbols: 32940
I, [2015-12-14T17:06:28.571531 #61247]  INFO -- : Symbols: 32940
I, [2015-12-14T17:06:32.004714 #61247]  INFO -- : Symbols: 32940
I, [2015-12-14T17:06:32.164350 #61247]  INFO -- : Symbols: 32940
I, [2015-12-14T17:06:32.481172 #61247]  INFO -- : Symbols: 32942
I, [2015-12-14T17:06:34.674952 #61247]  INFO -- : Symbols: 32942
I, [2015-12-14T17:06:35.635048 #61247]  INFO -- : Symbols: 32947
I, [2015-12-14T17:06:37.552127 #61247]  INFO -- : Symbols: 32947
I, [2015-12-14T17:06:39.477075 #61247]  INFO -- : Symbols: 32948
I, [2015-12-14T17:06:44.700503 #61247]  INFO -- : Symbols: 32948
I, [2015-12-14T17:06:45.728125 #61247]  INFO -- : Symbols: 32948
I, [2015-12-14T17:06:47.260915 #61247]  INFO -- : Symbols: 32948
I, [2015-12-14T17:06:49.810442 #61247]  INFO -- : Symbols: 32948
I, [2015-12-14T17:06:51.132631 #61247]  INFO -- : Symbols: 33060
...

I had symbols count growing more an more. Next i logged last symbols and got these ones:

...
_app_views_cameras__index_json_jbuilder__3879325446027068324_95729280
_app_views_cameras__index_json_jbuilder__3879325446027068324_101662240
_app_views_cameras__index_json_jbuilder__3879325446027068324_78997760
_app_views_tv_channels__index_json_jbuilder___3960928945761218658_92908200
_app_views_tv_channels__index_json_jbuilder___3960928945761218658_99421540
...

Basing on this i calculated: each 100 processed requests were increasing RAM usage by at least 6-9KB.

@why-el

This comment has been minimized.

Copy link
Contributor

commented Dec 23, 2015

Are you dependent on ruby 2.1? If not I'd suggest you update to ruby 2.2. Rails 5 is pulling the trigger on all but ruby 2.2, so even we could ensure the method symbol is deleted from the symbol storage now, that would simply mean we are replicating (and perhaps breaking) functionality that Ruby 2.2 already fixed.

@matthewd

This comment has been minimized.

Copy link
Member

commented Dec 23, 2015

Yeah, if this is fixed by upgrading to ruby 2.2, I don't think there's much we can do about it now... any change on our side seems too invasive to justify backporting to 4.2. 😕

@matthewd matthewd closed this Dec 23, 2015

@panasyuk

This comment has been minimized.

Copy link
Author

commented Dec 24, 2015

@matthewd This issue affects many Rails applications all over the world. Upgrading to Ruby 2.2 (or to Rails 5) will be a big problem for tons of projects (especially for long term ones). For instance Debian will have Ruby 2.2 and higher in it's stable repositories in 1.5 years.

@luke-gru

This comment has been minimized.

Copy link
Contributor

commented Dec 24, 2015

Maybe I'm not understanding, but wouldn't this only be an issue in development environments, or if you're doing something weird in production, such as uncaching the templates. Say you have 100 template files, and 2 unicorn workers, you have a maximum of 200 of these methods, so 200 symbols created.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.