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

[WIP] Save allocations (?) by using symbols for JSON keys #252

Closed
wants to merge 1 commit into from

Conversation

cben
Copy link
Collaborator

@cben cben commented Jun 7, 2017

The JSONs we parse have the same keys repeating in many places.
Currently JSON parsing returns string keys, which allocates a new string every time:

[18] pry(main)> a1, a2 = JSON.parse('[{"a": 1}, {"a": 2}]'); a1.keys.first.equal? a2.keys.first
=> false

This returns symbols instead, so each key is allocated at most once.


Nice theory, but needs evidence of win
I see total allocations slightly actually go up :-( Fluctuates randomly from run to run.
Measuring on kubeclient test suite by appending this to test/test_helper.rb:

at_exit do
  # happens shortly before Minitest.run
  GC.start
  $gc_stat_before_tests = GC.stat
end
Minitest.after_run do
  puts '>'*80
  printf "%40s\t%9s\t%9s\t%9s\t%s\n", 'GC.stat key', 'before', 'after', 'diff', 'ratio'
  GC.stat.each do |k, after_v|
    GC.start
    before_v = $gc_stat_before_tests[k]
    printf "%40s\t%9d\t%9d\t%9d\t%.3f\n", "#{k}:", before_v, after_v, after_v - before_v, after_v / before_v.to_f
  end
  puts '<'*80
end

I see on master 738077 total_allocated_objects:

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
                             GC.stat key	   before	    after	     diff	ratio
                                  count:	       43	       61	       18	1.419
                   heap_allocated_pages:	      413	      413	        0	1.000
                     heap_sorted_length:	      413	      413	        0	1.000
                 heap_allocatable_pages:	        0	        0	        0	NaN
                   heap_available_slots:	   168348	   168348	        0	1.000
                        heap_live_slots:	   122390	   168306	    45916	1.375
                        heap_free_slots:	    45958	       42	   -45916	0.001
                       heap_final_slots:	        0	        0	        0	NaN
                      heap_marked_slots:	   122307	   131317	     9010	1.074
                        heap_eden_pages:	      413	      413	        0	1.000
                        heap_tomb_pages:	        0	        0	        0	NaN
                  total_allocated_pages:	      413	      413	        0	1.000
                      total_freed_pages:	        0	        0	        0	NaN
                total_allocated_objects:	   817165	  1555242	   738077	1.903
                    total_freed_objects:	   694775	  1386936	   692161	1.996
                  malloc_increase_bytes:	     1176	    41976	    40800	35.694
            malloc_increase_bytes_limit:	 16777216	 16777216	        0	1.000
                         minor_gc_count:	       36	       53	       17	1.472
                         major_gc_count:	        7	        8	        1	1.143
      remembered_wb_unprotected_objects:	      505	      580	       75	1.149
remembered_wb_unprotected_objects_limit:	     1010	     1150	      140	1.139
                            old_objects:	   120807	   130029	     9222	1.076
                      old_objects_limit:	   241614	   258582	    16968	1.070
               oldmalloc_increase_bytes:	  4124968	    64056	 -4060912	0.016
         oldmalloc_increase_bytes_limit:	 16777216	 16777216	        0	1.000
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

and with this change 775103 total_allocated_objects:

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
                             GC.stat key	   before	    after	     diff	ratio
                                  count:	       43	       62	       19	1.442
                   heap_allocated_pages:	      413	      413	        0	1.000
                     heap_sorted_length:	      413	      413	        0	1.000
                 heap_allocatable_pages:	        0	        0	        0	NaN
                   heap_available_slots:	   168333	   168333	        0	1.000
                        heap_live_slots:	   122389	   168201	    45812	1.374
                        heap_free_slots:	    45944	      132	   -45812	0.003
                       heap_final_slots:	        0	        0	        0	NaN
                      heap_marked_slots:	   122306	   128777	     6471	1.053
                        heap_eden_pages:	      413	      413	        0	1.000
                        heap_tomb_pages:	        0	        0	        0	NaN
                  total_allocated_pages:	      413	      413	        0	1.000
                      total_freed_pages:	        0	        0	        0	NaN
                total_allocated_objects:	   817162	  1592265	   775103	1.949
                    total_freed_objects:	   694773	  1424064	   729291	2.050
                  malloc_increase_bytes:	     1176	    24840	    23664	21.122
            malloc_increase_bytes_limit:	 16777216	 16777216	        0	1.000
                         minor_gc_count:	       36	       54	       18	1.500
                         major_gc_count:	        7	        8	        1	1.143
      remembered_wb_unprotected_objects:	      505	      562	       57	1.113
remembered_wb_unprotected_objects_limit:	     1010	     1100	       90	1.089
                            old_objects:	   120807	   127895	     7088	1.059
                      old_objects_limit:	   241614	   252694	    11080	1.046
               oldmalloc_increase_bytes:	  4125736	   158312	 -3967424	0.038
         oldmalloc_increase_bytes_limit:	 16777216	 16777216	        0	1.000
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

I suspect RecursiveOpenStruct's _get_key_from_table_ trying name.to_s before name.to_sym (see link above) means we still get a string allocated for each symbol. (:a.to_s returns new string every time. Darn you Ruby and your mutable strings!) I'll try swapping these 2 ROS lines.

I think this PR is orthogonal to other ROS problems listed in #251.

OTOH malloc_increase_bytes is down from 40800 to 23664 :-) Fluctuates randomly from run to run.
I'm not sure what I should look at. I actually want peak memory usage on big JSON, don't think test suite does that.
@ilackarms can you help measuring this? (low priority, probably low payoff compared to #250.)

With your #250 involving a ruby JSON parser, I suppose we'll get lots of unavoidable string allocations during parsing, That's fine, but if you can make it free the strings and use symbols in the final data structure, could help with total RAM.

@ilackarms
Copy link

@cben the payoff may in fact be better from this change because the memory allocation for parsing gets garbage collected once it's finished. the ROS objects remain in memory; if we can reduce their footprint that might produce a better memory reduction

@cben
Copy link
Collaborator Author

cben commented Sep 24, 2017

Closing for now until I revisit it and get more data (if anybody else wants, I'm glad to help).
I still believe this could be a win, but there is a larger space to explore.

  • Is this backward-compatible? Seems it is currently, even after ros.to_h, thanks to RecursiveOpenStruct converting to symbols anyway during deep-copy.
  • Ensure this produces "mortal" symbols to prevent memory leak DOS — MRI version dependent.
  • There are a few RecursiveOpenStruct options I wanted to tweak to avoid deep-copying the hashes JSON.parse just created, need to check how this interacts with symbols / would it be backward compatible for kubeclient...
  • JSON.parse can be told which array/hash classes to use. Direct parsing to say OpenStruct may be more efficient than to hashes and then deep-copying, and then wrapping on demand...
  • Disabling/bypassing RecursiveOpenStruct is most promising. (At which point symbol/string should be decided.)
  • This would need to be implemented separately with streaming parsing.

Hopefully we'll measure various directions in ManageIQ and come back with data...

EDIT: ROS implements indifferent ros["string"] / ros[:symbol] access but not after .to_h — that always deep-copies again, and returns simple hash with symbols. What I see in practice doesn't fully match code though.

@cben cben closed this Jan 15, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants