search

newrelic / newrelic-ruby-agent

New Relic RPM Ruby Agent
https://docs.newrelic.com/docs/apm/agents/ruby-agent/getting-started/introduction-new-relic-ruby/
Apache License 2.0
1.19k stars 597 forks source link

MLT: Conduct performance A/B tests with and without MLT enabled #1075

Closed fallwith closed 2 years ago

fallwith commented 2 years ago

Performance tests should be conducted against the method_level_telemetry branch with MLT enabled and disabled via the new configuration setting and optionally against the dev branch as well if the configuration setting is not thought to be sufficient.

We are seeking to determine:

angelatan2 commented 2 years ago

The scope of this ticket is limited to stackprof and exclude OATs.

kaylareopelle commented 2 years ago 
MethodTracerTest#test_tracer_code_level_metrics_enabled: 3403.199 ips (293.84 µs / iteration)
    cpu_time_user:    4.90353 (0.00 / iter)
  cpu_time_system:   0.122259 (0.00 / iter)
          gc_runs:          0 (0.00 / iter)
     live_objects: 7.6139e+06 (442.00 / iter)
      allocations: 7.6139e+06 (442.00 / iter)
         retained:          0 (0.00 / iter)
       iterations:      17226

MethodTracerTest#test_tracer_code_level_metrics_disabled: 3314.989 ips (301.66 µs / iteration)
    cpu_time_user:     4.87302 (0.00 / iter)
  cpu_time_system:    0.140496 (0.00 / iter)
          gc_runs:           0 (0.00 / iter)
     live_objects: 7.37919e+06 (442.00 / iter)
      allocations: 7.37919e+06 (442.00 / iter)
         retained:           0 (0.00 / iter)
       iterations:       16695

MethodTracerTest#test_with_metric_code_level_metrics_enabled: 3525.946 ips (283.61 µs / iteration)
    cpu_time_user:     4.86533 (0.00 / iter)
  cpu_time_system:    0.131526 (0.00 / iter)
          gc_runs:           0 (0.00 / iter)
     live_objects: 7.79688e+06 (442.00 / iter)
      allocations: 7.79688e+06 (442.00 / iter)
         retained:           0 (0.00 / iter)
       iterations:       17640

MethodTracerTest#test_with_metric_code_level_metrics_disabled: 3493.836 ips (286.22 µs / iteration)
    cpu_time_user:     4.91536 (0.00 / iter)
  cpu_time_system:     0.13141 (0.00 / iter)
          gc_runs:           0 (0.00 / iter)
     live_objects: 7.81898e+06 (442.00 / iter)
      allocations: 7.81898e+06 (442.00 / iter)
         retained:           0 (0.00 / iter)
       iterations:       17690

MethodTracerTest#test_with_proc_code_level_metrics_enabled: 3455.788 ips (289.37 µs / iteration)
    cpu_time_user:     4.90477 (0.00 / iter)
  cpu_time_system:    0.135506 (0.00 / iter)
          gc_runs:           0 (0.00 / iter)
     live_objects: 7.70937e+06 (442.00 / iter)
      allocations: 7.70937e+06 (442.00 / iter)
         retained:           0 (0.00 / iter)
       iterations:       17442

MethodTracerTest#test_with_proc_code_level_metrics_disabled: 3479.971 ips (287.36 µs / iteration)
    cpu_time_user:     4.88746 (0.00 / iter)
  cpu_time_system:    0.126163 (0.00 / iter)
          gc_runs:           0 (0.00 / iter)
     live_objects: 7.73058e+06 (442.00 / iter)
      allocations: 7.73058e+06 (442.00 / iter)
         retained:           0 (0.00 / iter)
       iterations:       17490

MethodTracerTest#test_push_scope_false_code_level_metrics_enabled: 3418.730 ips (292.51 µs / iteration)
    cpu_time_user:    4.89297 (0.00 / iter)
  cpu_time_system:    0.12719 (0.00 / iter)
          gc_runs:          0 (0.00 / iter)
     live_objects: 7.5887e+06 (442.00 / iter)
      allocations: 7.5887e+06 (442.00 / iter)
         retained:          0 (0.00 / iter)
       iterations:      17169

MethodTracerTest#test_push_scope_false_code_level_metrics_disabled: 3493.620 ips (286.24 µs / iteration)
    cpu_time_user:    4.88480 (0.00 / iter)
  cpu_time_system:    0.13201 (0.00 / iter)
          gc_runs:          0 (0.00 / iter)
     live_objects: 7.7571e+06 (442.00 / iter)
      allocations: 7.7571e+06 (442.00 / iter)
         retained:          0 (0.00 / iter)
       iterations:      17550

MethodTracerTest#test_metric_false_code_level_metrics_enabled: 3417.194 ips (292.64 µs / iteration)
    cpu_time_user:      4.9681 (0.00 / iter)
  cpu_time_system:    0.111937 (0.00 / iter)
          gc_runs:           0 (0.00 / iter)
     live_objects: 7.68196e+06 (442.00 / iter)
      allocations: 7.68196e+06 (442.00 / iter)
         retained:           0 (0.00 / iter)
       iterations:       17380

MethodTracerTest#test_metric_false_code_level_metrics_disabled: 3462.276 ips (288.83 µs / iteration)
    cpu_time_user:      4.8861 (0.00 / iter)
  cpu_time_system:    0.136632 (0.00 / iter)
          gc_runs:           0 (0.00 / iter)
     live_objects: 7.70937e+06 (442.00 / iter)
      allocations: 7.70937e+06 (442.00 / iter)
         retained:           0 (0.00 / iter)
       iterations:       17442
kaylareopelle commented 2 years ago
One more version of the output. Here "before" is with code-level metrics turned off. "after" is with them turned on. This test was run on the method_level_telemetry branch. name before after delta allocs_before allocs_after allocs_delta retained retained_delta
MethodTracerTest#test_tracer_code_level_metrics 305.16 µs 271.85 µs -10.9% 442 442 0.0% 0 0.0%
MethodTracerTest#test_with_metric_code_level_metrics 312.52 µs 295.89 µs -5.3% 442 442 0.0% 0 0.0%
MethodTracerTest#test_with_proc_code_level_metrics 324.55 µs 276.11 µs -14.9% 442 442 0.0% 0 0.0%
MethodTracerTest#test_push_scope_false_code_level_metrics 334.80 µs 281.63 µs -15.9% 442 442 0.0% 0 0.0%
MethodTracerTest#test_metric_false_code_level_metrics 278.35 µs 270.68 µs -2.8% 442 442 0.0% 0 0.0%
kaylareopelle commented 2 years ago

Results dev (before) compared with method_level_telemetry (after)

The following tests were not found in the baseline results: MethodTracerTest#test_tracer_code_level_metrics_enabled MethodTracerTest#test_tracer_code_level_metrics_disabled MethodTracerTest#test_with_metric_code_level_metrics_enabled MethodTracerTest#test_with_metric_code_level_metrics_disabled MethodTracerTest#test_with_proc_code_level_metrics_enabled MethodTracerTest#test_with_proc_code_level_metrics_disabled MethodTracerTest#test_push_scope_false_code_level_metrics_enabled MethodTracerTest#test_push_scope_false_code_level_metrics_disabled MethodTracerTest#test_metric_false_code_level_metrics_enabled MethodTracerTest#test_metric_false_code_level_metrics_disabled

The following tests were not found in the new results: ExternalSegment#test_external_request_in_thread ExternalSegment#test_external_trace_context_request_within_thread TransactionTracingPerfTests#test_short_transactions_in_thread TransactionTracingPerfTests#test_long_transactions_in_thread TransactionTracingPerfTests#test_short_transaction_with_datastore_segment_in_thread TransactionTracingPerfTests#test_short_transaction_with_external_request_segment_in_thread

name before after delta allocs_before allocs_after allocs_delta retained retained_delta
ActiveRecordTest#test_helper_by_name 2.07 µs 1.76 µs -14.7% 4 4 0.0% 0 0.0%
ActiveRecordTest#test_helper_by_sql 3.68 µs 3.49 µs -5.2% 9 9 0.0% 0 0.0%
ActiveRecordSubscriberTest#test_subscriber_in_txn 10.57 ms 9.94 ms -6.0% 1368 1350 -1.3% 0 0.0%
AgentAttributesTests#test_empty_agent_attributes 1.64 µs 1.82 µs +10.6% 0 0 NaN% 0 0.0%
AgentAttributesTests#test_with_wildcards 2.58 µs 2.85 µs +10.7% 0 0 NaN% 0 0.0%
AgentAttributesTests#test_with_tons_o_rules 59.00 µs 91.71 µs +55.4% 0 0 NaN% 0 0.0%
AgentAttributesTests#test_with_attribute_rules 2.39 µs 2.50 µs +4.7% 0 0 NaN% 0 0.0%
AgentModuleTest#test_increment_metric_by_1 5.27 µs 4.83 µs -8.2% 8 8 0.0% 0 0.0%
AgentModuleTest#test_increment_metric_by_more_than_1 7.52 µs 7.45 µs -0.9% 11 11 0.0% 0 0.0%
ConfigPerfTests#test_raw_access 0.25 µs 0.22 µs -8.9% 0 0 NaN% 0 0.0%
ConfigPerfTests#test_defaulting_access 0.24 µs 0.25 µs +3.0% 0 0 NaN% 0 0.0%
ConfigPerfTests#test_missing_key 0.32 µs 0.32 µs -1.9% 0 0 NaN% 0 0.0%
ConfigPerfTests#test_blowing_cache 2.94 µs 2.67 µs -9.0% 5 5 0.0% 0 0.0%
DatastoresPerfTest#test_segment_notice_sql 2.06 µs 2.20 µs +6.8% 2 2 0.0% 0 0.0%
DatastoresPerfTest#test_instrumentation_via_trace 316.66 µs 294.28 µs -7.1% 109 95 -12.8% 0 0.0%
DatastoresPerfTest#test_wrap 384.05 µs 289.33 µs -24.7% 112 96 -14.3% 0 0.0%
DatastoresPerfTest#test_notice_sql 4.60 µs 4.09 µs -11.3% 4 4 0.0% 0 0.0%
ErrorCollectorTests#test_notice_error 1.75 ms 1.26 ms -28.0% 142 127 -10.6% 0 0.0%
ErrorCollectorTests#test_notice_error_with_custom_attributes 1.15 ms 1.19 ms +2.9% 140 125 -10.7% 0 0.0%
ExternalSegment#test_external_request 3.57 ms 2.50 ms -29.9% 480 464 -3.3% 0 0.0%
ExternalSegment#test_external_cat_request 3.30 ms 3.05 ms -7.6% 495 481 -2.8% 0 0.0%
ExternalSegment#test_external_trace_context_request 3.19 ms 2.27 ms -28.8% 478 464 -2.9% 0 0.0%
LoggingTest#test_logger_instrumentation 39.17 µs 27.80 µs -29.0% 8 7 -12.5% 0 0.0%
LoggingTest#test_local_log_decoration 432.12 µs 376.93 µs -12.8% 495 487 -1.6% 0 0.0%
LoggingTest#test_local_log_decoration_in_transaction 741.97 µs 753.75 µs +1.6% 626 614 -1.9% 0 0.0%
LoggingTest#test_logger_instrumentation_in_transaction 320.91 µs 281.91 µs -12.2% 94 82 -12.8% 0 0.0%
LoggingTest#test_decorating_logger 45.16 µs 32.67 µs -27.6% 9 7 -22.2% 0 0.0%
Marshalling#test_basic_marshalling_json 48.73 ms 50.85 ms +4.4% 17072 17072 0.0% 0 0.0%
Marshalling#test_json_marshalling_binary_strings 92.40 ms 87.52 ms -5.3% 40852 40852 0.0% 0 0.0%
Marshalling#test_json_marshalling_utf16_strings 98.09 ms 107.83 ms +9.9% 40852 40852 0.0% 0 0.0%
Marshalling#test_json_marshalling_latin1_strings 70.05 ms 79.09 ms +12.9% 30940 30940 0.0% 0 0.0%
QueueTimePerfTests#test_queue_time_parsing 51.20 µs 46.57 µs -9.0% 15 15 0.0% 0 0.0%
RackMiddleware#test_basic_middleware_stack 983.81 µs 938.30 µs -4.6% 261 234 -10.3% 0 0.0%
RackMiddleware#test_request_with_params_capture_params_off 1.05 ms 1.12 ms +7.0% 296 267 -9.8% 0 0.0%
RackMiddleware#test_request_with_params_capture_params_on 1.17 ms 1.16 ms -0.6% 361 332 -8.0% 0 0.0%
RedisTest#test_no_args 0.86 µs 0.86 µs -0.3% 1 1 0.0% 0 0.0%
RedisTest#test_args 4.84 µs 4.72 µs -2.6% 2 2 0.0% 0 0.0%
RedisTest#test_long_args 5.08 µs 6.11 µs +20.3% 8 8 0.0% 0 0.0%
RedisTest#test_pipelined 10.22 µs 10.60 µs +3.7% 15 15 0.0% 0 0.0%
RulesEngineTests#test_rules_engine_init_transaction_rules 1.15 µs 1.28 µs +11.8% 6 6 0.0% 0 0.0%
RulesEngineTests#test_rules_engine_rename_transaction_rules 1.98 µs 2.13 µs +7.2% 9 9 0.0% 0 0.0%
RumAutoInsertion#test_rum_autoinsertion_with_x_ua_compatible_after 1.31 ms 1.33 ms +1.4% 76 76 0.0% 0 0.0%
RumAutoInsertion#test_rum_autoinsertion 1.25 ms 1.45 ms +15.8% 75 75 0.0% 0 0.0%
RumAutoInsertion#test_rum_autoinsertion_with_x_ua_compatible 1.18 ms 1.13 ms -4.1% 76 77 +1.3% 0 0.0%
SegmentTermsRuleTests#test_segment_terms_rule_apply 5.89 µs 6.15 µs +4.4% 20 20 0.0% 0 0.0%
SegmentTermsRuleTests#test_segment_terms_rule_matches? 1.57 µs 1.33 µs -15.3% 6 6 0.0% 0 0.0%
SqlObfuscationTests#test_obfuscate_sql 212.26 µs 211.79 µs -0.2% 10 10 0.0% 0 0.0%
SqlObfuscationTests#test_obfuscate_sql_postgres 192.54 µs 174.57 µs -9.3% 10 10 0.0% 0 0.0%
SqlObfuscationTests#test_obfuscate_cross_agent_tests 3.55 ms 3.14 ms -11.4% 917 917 0.0% 0 0.0%
StartupShutdown#test_startup_shutdown 11.86 ms 11.88 ms +0.2% 434 434 0.0% 0 0.0%
StatsHashPerfTest#test_record 337.94 µs 265.81 µs -21.3% 306 206 -32.7% 0 0.0%
StatsHashPerfTest#test_merge 552.66 µs 524.99 µs -5.0% 712 612 -14.0% 0 0.0%
ThreadProfiling#test_gather_backtraces 1.84 ms 2.11 ms +14.7% 4813 4813 0.0% 0 0.0%
ThreadProfiling#test_gather_backtraces_subscribed 77.34 µs 89.22 µs +15.4% 21 21 0.0% 0 0.0%
ThreadProfiling#test_generating_traces 284.76 ms 263.52 ms -7.5% 585472 585472 0.0% 0 0.0%
TraceContext#test_parse 20.37 µs 18.15 µs -10.9% 47 47 0.0% 0 0.0%
TraceContext#test_insert 1.79 µs 1.66 µs -7.0% 3 3 0.0% 0 0.0%
TraceContext#test_insert_trace_context 46.08 µs 35.43 µs -23.1% 20 20 0.0% 0 0.0%
TraceContextRequestMonitor#test_on_before_call 311.69 µs 305.94 µs -1.8% 147 134 -8.8% 0 0.0%
TraceExecutionScopedTests#test_trace_execution_scoped 37.28 µs 35.61 µs -4.5% 13 13 0.0% 0 0.0%
TraceExecutionScopedTests#test_trace_execution_scoped_in_a_transaction 327.56 µs 338.97 µs +3.5% 101 89 -11.9% 0 0.0%
TransactionTracingPerfTests#test_with_custom_attributes 561.25 µs 340.08 µs -39.4% 135 123 -8.9% 0 0.0%
TransactionTracingPerfTests#test_spans_with_custom_attributes 48.21 µs 46.42 µs -3.7% 19 19 0.0% 0 0.0%
TransactionTracingPerfTests#test_failure 1.38 ms 1.37 ms -0.6% 186 170 -8.6% 0 0.0%
TransactionTracingPerfTests#test_start_with_tracer_start 265.16 µs 220.49 µs -16.8% 91 78 -14.3% 0 0.0%
TransactionTracingPerfTests#test_short_transaction_with_datastore_segment 314.53 µs 336.71 µs +7.1% 120 105 -12.5% 0 0.0%
TransactionTracingPerfTests#test_short_transaction_with_external_request_segment 384.53 µs 356.33 µs -7.3% 130 116 -10.8% 0 0.0%
TransactionTracingPerfTests#test_short_transactions 324.87 µs 403.23 µs +24.1% 121 110 -9.1% 0 0.0%
TransactionTracingPerfTests#test_long_transactions 1.70 s 1.69 s -0.6% 699650 688363 -1.6% 0 0.0%
kaylareopelle commented 2 years ago

before is dev, with the new method_tracer.rb file added to the branch, after is method_level_telemetry:

name before after delta allocs_before allocs_after allocs_delta retained retained_delta
MethodTracerTest#test_tracer_code_level_metrics_enabled 278.68 µs 287.61 µs +3.2% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_tracer_code_level_metrics_disabled 279.61 µs 332.79 µs +19.0% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_with_metric_code_level_metrics_enabled 279.30 µs 331.62 µs +18.7% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_with_metric_code_level_metrics_disabled 283.52 µs 324.40 µs +14.4% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_with_proc_code_level_metrics_enabled 300.09 µs 330.58 µs +10.2% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_with_proc_code_level_metrics_disabled 278.04 µs 316.80 µs +13.9% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_push_scope_false_code_level_metrics_enabled 300.52 µs 305.03 µs +1.5% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_push_scope_false_code_level_metrics_disabled 307.69 µs 312.87 µs +1.7% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_metric_false_code_level_metrics_enabled 299.61 µs 333.10 µs +11.2% 440 442 +0.5% 0 0.0%
MethodTracerTest#test_metric_false_code_level_metrics_disabled 335.59 µs 297.79 µs -11.3% 440 442 +0.5% 0 0.0%
kaylareopelle commented 2 years ago

One more version of the output. Here "before" is with code-level metrics turned off. "after" is with them turned on. This test was run on the method_level_telemetry branch.

...

Here is this test re-run. Strangely, we see the same output -- faster with code_level_metrics on.

name before after delta allocs_before allocs_after allocs_delta retained retained_delta
MethodTracerTest#test_tracer_code_level_metrics 312.82 µs 274.27 µs -12.3% 442 442 0.0% 0 0.0%
MethodTracerTest#test_with_metric_code_level_metrics 349.37 µs 278.41 µs -20.3% 442 442 0.0% 0 0.0%
MethodTracerTest#test_with_proc_code_level_metrics 299.06 µs 279.88 µs -6.4% 442 442 0.0% 0 0.0%
MethodTracerTest#test_push_scope_false_code_level_metrics 291.61 µs 271.34 µs -6.9% 442 442 0.0% 0 0.0%
MethodTracerTest#test_metric_false_code_level_metrics 289.82 µs 277.43 µs -4.3% 442 442 0.0% 0 0.0%
kaylareopelle commented 2 years ago

Stackprof results

code_level_metrics.enabled: false

Mode: wall(500) Samples: 1762 (10.92% miss rate) GC: 64 (3.63%)

 TOTAL    (pct)     SAMPLES    (pct)     FRAME
   191  (10.8%)         191  (10.8%)     Puma::Single#run
   201  (11.4%)         178  (10.1%)     Rack::MiniProfiler::TimerStruct::Sql#initialize
   155   (8.8%)         155   (8.8%)     Bootsnap::CompileCache::ISeq.input_to_storage
    82   (4.7%)          82   (4.7%)     Bootsnap::CompileCache::ISeq.storage_to_output
    54   (3.1%)          54   (3.1%)     (sweeping)
    55   (3.1%)          50   (2.8%)     Logger::LogDevice#write
    48   (2.7%)          48   (2.7%)     SQLite3::ResultSet#next_hash
   141   (8.0%)          48   (2.7%)     ActiveRecord::LogSubscriber#log_query_source
    46   (2.6%)          46   (2.6%)     Digest::Instance#file
    45   (2.6%)          45   (2.6%)     ActiveSupport::BacktraceCleaner#add_gem_filter
    34   (1.9%)          34   (1.9%)     SQLite3::Statement#each
    50   (2.8%)          27   (1.5%)     Addrinfo#connect_internal
    22   (1.2%)          22   (1.2%)     Socket#connect_nonblock
    21   (1.2%)          21   (1.2%)     Rack::MiniProfiler.config
    75   (4.3%)          21   (1.2%)     Webpacker::Compiler#watched_files_digest
    19   (1.1%)          19   (1.1%)     Sprockets::PathUtils#entries
    15   (0.9%)          15   (0.9%)     Pathname#chop_basename
    14   (0.8%)          14   (0.8%)     ActiveRecord::Base.logger
   131   (7.4%)          12   (0.7%)     ActiveSupport::LoggerThreadSafeLevel#add
    12   (0.7%)          12   (0.7%)     ActiveSupport::PerThreadRegistry#instance
    12   (0.7%)          12   (0.7%)     Concurrent::Collection::NonConcurrentMapBackend#[]
   250  (14.2%)          12   (0.7%)     Bootsnap::CompileCache::ISeq::InstructionSequenceMixin#load_iseq
    10   (0.6%)          10   (0.6%)     TracePoint#self
    10   (0.6%)          10   (0.6%)     (marking)
    10   (0.6%)           9   (0.5%)     Rails::BacktraceCleaner#initialize
     8   (0.5%)           8   (0.5%)     NewRelic::LanguageSupport#constantize
     8   (0.5%)           8   (0.5%)     ActiveSupport::Logger::SimpleFormatter#call
     8   (0.5%)           8   (0.5%)     ActiveSupport::NumericWithFormat#to_s
     7   (0.4%)           7   (0.4%)     ActiveSupport::TaggedLogging::Formatter#current_tags
     7   (0.4%)           7   (0.4%)     NewRelic::Agent#config
kaylareopelle commented 2 years ago

Stackprof results

code_level_metrics.enabled: true

Mode: wall(500) Samples: 2632 (10.23% miss rate) GC: 116 (4.41%)

 TOTAL    (pct)     SAMPLES    (pct)     FRAME
   354  (13.4%)         308  (11.7%)     Rack::MiniProfiler::TimerStruct::Sql#initialize
   304  (11.6%)         304  (11.6%)     Puma::Single#run
    96   (3.6%)          93   (3.5%)     Logger::LogDevice#write
    91   (3.5%)          91   (3.5%)     SQLite3::ResultSet#next_hash
   264  (10.0%)          84   (3.2%)     ActiveRecord::LogSubscriber#log_query_source
    79   (3.0%)          79   (3.0%)     ActiveSupport::BacktraceCleaner#add_gem_filter
    77   (2.9%)          77   (2.9%)     (sweeping)
    77   (2.9%)          77   (2.9%)     Digest::Instance#file
    65   (2.5%)          65   (2.5%)     SQLite3::Statement#each
   129   (4.9%)          44   (1.7%)     Webpacker::Compiler#watched_files_digest
    85   (3.2%)          43   (1.6%)     Addrinfo#connect_internal
    42   (1.6%)          42   (1.6%)     Socket#connect_nonblock
    41   (1.6%)          41   (1.6%)     Rack::MiniProfiler.config
    38   (1.4%)          38   (1.4%)     (marking)
    29   (1.1%)          29   (1.1%)     Pathname#chop_basename
    25   (0.9%)          25   (0.9%)     Sprockets::PathUtils#entries
   250   (9.5%)          25   (0.9%)     ActiveSupport::LoggerThreadSafeLevel#add
    21   (0.8%)          21   (0.8%)     Concurrent::Collection::NonConcurrentMapBackend#[]
    20   (0.8%)          20   (0.8%)     Sprockets::PathUtils#stat
    19   (0.7%)          19   (0.7%)     Rails::BacktraceCleaner#initialize
    17   (0.6%)          17   (0.6%)     NewRelic::LanguageSupport#constantize
    18   (0.7%)          16   (0.6%)     NewRelic::Agent::Tracer.state
    16   (0.6%)          16   (0.6%)     Rack::Request::Env#get_header
    15   (0.6%)          15   (0.6%)     ActiveSupport::NumericWithFormat#to_s
    99   (3.8%)          14   (0.5%)     Addrinfo.foreach
    14   (0.5%)          14   (0.5%)     ActiveSupport::BacktraceCleaner#add_gem_silencer
    13   (0.5%)          13   (0.5%)     ActiveRecord::Base.logger
    11   (0.4%)          11   (0.4%)     ActiveRecord::Base.legacy_connection_handling
    11   (0.4%)          11   (0.4%)     ActiveSupport::PerThreadRegistry#instance
    10   (0.4%)          10   (0.4%)     ActiveSupport::Logger::SimpleFormatter#call