$30 off During Our Annual Pro Sale. View Details »

The Future of Ruby Performance Tooling

The Future of Ruby Performance Tooling

A presentation I gave at Gotham Ruby Conf 2014 (http://goruco.com) about Ruby Performance Tooling and what we've been doing at Paperless Post. There were a couple videos in the slides so unfortunately those are not included here. Video should be up soon though.

Aaron Quint

June 21, 2014
Tweet

More Decks by Aaron Quint

Other Decks in Programming

Transcript

  1. THE future of
    ruby performance
    tooling
    @aq / GoRuCo 2014

    View Slide

  2. Thanks for coming.
    Good Morning!

    View Slide

  3. View Slide

  4. Well, lets start with the philosophy at least.
    today’s agenda:
    More Practical,
    Less Philosophical

    View Slide

  5. User Experience, but also $$$
    Performance
    matters.

    View Slide

  6. + PERFORMANCE

    View Slide

  7. Connecting
    Ruby Server
    HTML DL
    CSS DL
    JS DL
    Images
    JS onLoad() Done
    0-10ms
    10-30,000ms
    30ms
    150ms
    100-50,000ms

    View Slide

  8. Connecting
    Ruby Server
    HTML DL
    CSS DL
    JS DL
    Images
    Sorted by how much
    control we have
    to improve

    View Slide

  9. Ruby Server
    Ruby/Stdlib
    Rails
    DB/Cache
    YOUR APPLICATION

    View Slide

  10. So where do we start?

    View Slide

  11. The Past of RUBY-CORE:
    Developers > Operators

    View Slide

  12. View Slide

  13. THE FUTURE OF RUBY-CORE:
    INTROSPECTABILITY

    View Slide

  14. Heres to the future cuz we got through the past

    View Slide

  15. Multitudinous
    The future of ruby
    performance tooling

    View Slide

  16. There is no BEST tool, either.
    Reminder:
    THERE IS NO ONE TOOL

    View Slide

  17. Ruby
    PerformancE
    Character
    Profiles

    View Slide

  18. • Specificity (Sp)
    • Impact (Im)
    • Difficulty of Operator Use (Op)
    • Readability (Rd)
    • Realtimedness (Rl)
    • Special Abilities (SA)

    View Slide

  19. The Elves
    AS::Notifications + Friends

    View Slide

  20. ActiveSupport::Notifications.publish("log_action.request_subscriber", data)

    View Slide

  21. class StatsdSubscriber < ActiveSupport::LogSubscriber
    attr_reader :event
    !
    def log_action(event)
    payload = event.payload[:controller_data]
    prefix = “controller.#{payload[:method]}.#{payload[:controller].to_s.gsub(‘::’,'_')}."
    %w{view db total}.each do |metric|
    value = payload["#{metric}_runtime".to_sym]
    Paperless::Statsd.timing("#{prefix}.#{metric}", value) if value
    Paperless::Statsd.timing("controller.#{metric}", value) if value
    end
    end
    !
    end

    View Slide

  22. View Slide

  23. AS:Notify
    Sp: 5-10
    Im: 5-10
    Op: 7
    Rd: 2-10
    Rl: 9
    • Special Abilities:
    Graphs!
    • Good for: p90s, what
    _layers_ are slow?
    Trending data.
    • Not Good for: Giving
    you details about
    anything. Easy to
    misinterpret data.

    View Slide

  24. The Warrior
    RblineproF

    View Slide

  25. require 'rblineprof'
    def lineprof_block(options = {}, &block)
    profile = lineprof(/app/) do
    ret = yield
    end
    profile_text(profile, options)
    end

    View Slide

  26. View Slide

  27. RblineproF
    Sp: 9
    Im: 9
    Op: 8
    Rd: 7
    Rl: 3
    • Special Abilities:
    Amazing visibility
    into dev hotspots
    • Good for: Diving deep
    into slow actions.
    • Not Good for:
    Discovery or fixing of
    systematic issues.
    Real world numbers.

    View Slide

  28. You have obtained a
    special weapon

    View Slide

  29. Sword of Repeatability
    PPprofiler

    View Slide

  30. $ ./script/ppprofiler ‘Event.last.as_json(:expand => true)’

    View Slide

  31. View Slide

  32. PPprofiler
    +2 Op
    +2 Rd
    • Special Abilities:
    Tracks local
    improvements.
    • Good for: Golf.
    Sharing
    improvements with
    team.
    • Not Good for:
    Production. This is
    about local.

    View Slide

  33. The Mage
    StackProF

    View Slide

  34. Ruby Process (Unicorn)
    AC::Dispatch
    MyController::Create
    Template::Render
    Ar::Find

    View Slide

  35. Ruby Process (Unicorn)
    StackProf.start rb_profile_frames() rb_profile_frames() rb_profile_frames() rb_profile_frames()
    StackProf.stop
    StackProf.dump

    View Slide

  36. $ stackprof ~/Downloads/stackprof-cpu-1402024056.dump
    ==================================
    Mode: cpu(1000)
    Samples: 562 (0.35% miss rate)
    GC: 71 (12.63%)
    ==================================
    TOTAL (pct) SAMPLES (pct) FRAME
    33 (5.9%) 33 (5.9%) ActiveRecord::Base.scoped_methods
    30 (5.3%) 30 (5.3%) ActiveRecord::ConnectionAdapters::PostgreSQLAdapter#…
    26 (4.6%) 26 (4.6%) ActiveSupport::CoreExtensions::Hash::Keys#assert_valid_keys
    24 (4.3%) 24 (4.3%) block in ActiveRecord::ConnectionAdapters::..#execute
    14 (2.5%) 14 (2.5%) block in ActiveSupport::Inflector#singularize
    13 (2.3%) 12 (2.1%) block in ActiveSupport::Notifications::Fanout#listeners_for
    12 (2.1%) 12 (2.1%) ActiveRecord::Reflection::AssociationReflection#klass
    19 (3.4%) 12 (2.1%) ActiveRecord::ConnectionAdapters::ConnectionHandler#…
    11 (2.0%) 11 (2.0%) block in ActiveRecord::Base.with_scope
    797 (141.8%) 11 (2.0%) ActiveRecord::Base.with_scope
    18 (3.2%) 8 (1.4%) ActiveRecord::Base.quote_bound_value
    7 (1.2%) 7 (1.2%) Haml::Helpers#preserve
    79 (14.1%) 7 (1.2%) block in ActiveRecord::Base.with_scope
    6 (1.1%) 6 (1.1%) block (2 levels) in ActiveRecord::Base.connection_handler=
    72 (12.8%) 6 (1.1%) block (2 levels) in ActiveRecord::Base.with_scope

    View Slide

  37. View Slide

  38. StackProF
    Sp: 4
    Im: 2
    Op: 3
    Rd: 4-6
    Rl: 9
    • Special Abilities:
    FLAMEGRAPHS
    • Good for: Finding
    systemic issues in
    production.
    • Not Good for: Detailed
    info about whats slow
    in YOUR code.

    View Slide

  39. You have obtained a
    special weapon

    View Slide

  40. Axe of Usability
    StackProF-RemotE

    View Slide

  41. require 'stackprof/remote/middleware'
    !
    enabled = proc do |env|
    magic_method || Rails.env.development?
    end
    ActionController::Dispatcher.middleware.use StackProf::Remote::Middleware,
    enabled: enabled, logger: Rails.logger

    View Slide

  42. View Slide

  43. SP::Remote
    +4 Op
    +2 Rd
    +1 Rl
    • Special Abilities:
    Interactive StackProf
    • Good for: Easily
    introspecting a
    production server.
    • Not Good for:
    Development.

    View Slide

  44. The Giant
    ObjecTSpacE

    View Slide

  45. $ ./bin/rbtrace -p 8963 -e 'GC.start(full_mark: true); require “objspace”;\
    ObjectSpace.dump_all(output: File.open(“heap.json","w"))'
    !
    $ ls -lh heap.json
    -rw-r--r-- 1 aaronquint staff 87M Jun 16 21:52 heap.json

    View Slide

  46. {"address":"0xf583b8", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "bytesize":13,
    "value":"output_format", "encoding":"UTF-8", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf583e0", "type":"OBJECT", "class":"0x2471268", "frozen":true, "ivars":3, "references":["0xf58480"],
    "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58458", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "bytesize":10,
    "value":"transforms", "encoding":"UTF-8", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58480", "type":"STRING", "class":"0xf11620", "embedded":true, "bytesize":1, "value":"/",
    "encoding":"UTF-8", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf584d0", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "bytesize":6,
    "value":"output", "encoding":"UTF-8", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58570", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "bytesize":11,
    "value":"progressive", "encoding":"UTF-8", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58598", "type":"OBJECT", "class":"0x2470b10", "frozen":true, "ivars":3, "flags":{"wb_protected":true,
    "old":true, "marked":true}}
    {"address":"0xf58610", "type":"OBJECT", "class":"0x24714e8", "frozen":true, "ivars":3, "references":["0xf58638"],
    "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58638", "type":"STRING", "class":"0xf11620", "embedded":true, "bytesize":3, "value":"api",
    "encoding":"UTF-8", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58700", "type":"OBJECT", "class":"0x24714e8", "frozen":true, "ivars":3, "references":["0xf58750"],
    "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58728", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "fstring":true, "bytesize"
    8, "value":"ASTERISK", "encoding":"US-ASCII", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58750", "type":"STRING", "class":"0xf11620", "shared":true, "encoding":"UTF-8", "references":
    ["0xf5f1b8"], "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf587a0", "type":"STRING", "class":"0xf11620", "frozen":true, "bytesize":24, "capacity":48,
    "value":"ActionController::CgiExt", "encoding":"US-ASCII", "memsize":49, "flags":{"wb_protected":true, "old":true,
    "marked":true}}
    {"address":"0xf587c8", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "bytesize":5,
    "value":"strip", "encoding":"UTF-8", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf587f0", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "fstring":true, "bytesize"
    9, "value":"SEV_LABEL", "encoding":"US-ASCII", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58840", "type":"OBJECT", "class":"0x2471268", "frozen":true, "ivars":3, "references":["0xf588e0"],
    "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf588b8", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "fstring":true, "bytesize"
    6, "value":"DOLLAR", "encoding":"US-ASCII", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf588e0", "type":"STRING", "class":"0xf11620", "embedded":true, "bytesize":1, "value":"/",
    "encoding":"UTF-8", "flags":{"wb_protected":true, "old":true, "marked":true}}
    {"address":"0xf58930", "type":"STRING", "class":"0xf11620", "frozen":true, "embedded":true, "bytesize":12,
    "value":"version_name", "encoding":"UTF-8", "flags"

    View Slide

  47. ObjecTSpacE
    Sp: 10
    Im: 10
    Op: 3
    Rd:3
    Rl: 2
    • Special Abilities:
    Every. Object.
    • Good for: Potential for
    diagnosing memory
    issues.
    • Not Good for: Hard to
    fetch from running
    systems.

    View Slide

  48. A WIP Palantir
    ObjspacEViewer

    View Slide

  49. $ ./scripts/import heap.json
    Time: 00:12:22 |==============================================>> | 93% Progress

    View Slide

  50. View Slide

  51. ObSViewer
    +2 Rd
    • Total WIP
    • The data is there, we
    just need better tools
    to gain analysis

    View Slide

  52. View Slide

  53. — The Strategy
    Use low impact tools to collect data
    from production
    and high impact tools to measure the
    relative improvements of iterative
    changes in development and staging.

    View Slide

  54. THANKS!
    !
    twitter: @aq
    code: github.com/quirkey
    !
    rblineprof: github.com/tmm1/rblineprof
    stackprof: github.com/tmm1/stackprof
    ppprofiler: dev.paperlesspost.com
    stackprof-remote: github.com/quirkey/stackprof-remote
    objspace_viewer: github.com/quirkey/objspace_viewer

    View Slide