Reduce object allocation during logging
What does this MR do?
Noticed that we're creating unnecessary objects while generating logs. The impact is really small.
I also moved the custom_format
lambda to it's own module and added a test case for it.
Performance comparison
Ran benchmark/ips
, however there is no significant performance difference.
Before
normal_api_log_entry 17.669k i/s
large_api_log_entry 417.889 i/s
normal_log_entry 17.736k i/s
large_log_entry 494.634 i/s
After
normal_api_log_entry 17.546k i/s
large_api_log_entry 435.117 i/s
normal_log_entry 19.355k i/s
large_log_entry 538.868 i/s
Allocations
Before
Generating API log entry, 237 allocations
log_perf.rb:85 T_OBJECT 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:30 T_DATA 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:31 T_ARRAY 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:31 T_IMEMO 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:46 T_IMEMO 1 0 0 0 0 0
gitlab/encoding_helper.rb:54 T_IMEMO 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:34 T_HASH 1 0 0 0 0 0
gitlab/utils/log_limited_array.rb:16 T_IMEMO 1 0 0 0 0 0
active_support/core_ext/object/json.rb:158 T_IMEMO 1 0 0 0 0 0
active_support/json/encoding.rb:57 T_IMEMO 1 0 0 0 0 0
gitlab/utils/log_limited_array.rb:15 T_ARRAY 1 0 0 0 0 0
time.rb:722 T_STRING 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:21 T_STRING 1 0 0 0 0 0
active_support/core_ext/object/json.rb:44 T_IMEMO 2 0 0 0 0 0
time.rb:724 T_STRING 2 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:19 T_HASH 2 0 0 0 0 0
json/common.rb:223 T_IMEMO 2 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:31 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:22 T_OBJECT 3 0 0 0 0 0
active_support/json/encoding.rb:30 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:35 T_HASH 3 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_IMEMO 3 0 0 0 0 0
active_support/core_ext/object/json.rb:94 T_STRING 3 0 0 0 0 0
active_support/json/encoding.rb:96 T_IMEMO 3 0 0 0 0 0
active_support/json/encoding.rb:96 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:107 T_HASH 3 0 0 0 0 0
json/common.rb:211 T_DATA 4 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_STRING 6 0 0 0 0 0
active_support/core_ext/numeric/conversions.rb:108 T_STRING 6 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_ARRAY 9 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_HASH 9 0 0 0 0 0
active_support/json/encoding.rb:96 T_ARRAY 9 0 0 0 0 0
active_support/json/encoding.rb:92 T_STRING 12 0 0 0 0 0
active_support/json/encoding.rb:58 T_IMEMO 12 0 0 0 0 0
json/common.rb:223 T_ARRAY 19 0 0 0 0 0
active_support/core_ext/object/json.rb:39 T_STRING 36 0 0 0 0 0
json/common.rb:223 T_STRING 67 0 0 0 0 0
TOTAL 237 0 0 0 0 0
Generating API log entry, 876 allocations
rails/railtie/configuration.rb:92 T_STRING 1 0 0 0 0 0
rails/railtie/configuration.rb:92 T_IMEMO 1 0 0 0 0 0
active_support/ordered_options.rb:42 T_STRING 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:25 T_ARRAY 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:26 T_ARRAY 1 0 0 0 0 0
active_support/core_ext/hash/except.rb:13 T_HASH 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:26 T_DATA 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:27 T_ARRAY 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:27 T_IMEMO 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:30 T_DATA 1 0 0 0 0 0
time.rb:722 T_STRING 1 0 0 0 0 0
active_support/core_ext/numeric/conversions.rb:108 T_STRING 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:31 T_HASH 1 0 0 0 0 0
gitlab/utils/log_limited_array.rb:16 T_IMEMO 1 0 0 0 0 0
active_support/core_ext/object/json.rb:158 T_IMEMO 1 0 0 0 0 0
active_support/json/encoding.rb:57 T_IMEMO 1 0 0 0 0 0
active_support/core_ext/object/json.rb:44 T_IMEMO 1 0 0 0 0 0
gitlab/utils/log_limited_array.rb:15 T_ARRAY 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:29 T_HASH 1 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:39 T_IMEMO 1 0 0 0 0 0
gitlab/gitaly_client.rb:341 T_ARRAY 1 0 0 0 0 0
labkit/correlation.rb:3 T_IMEMO 1 0 0 0 0 0
labkit/correlation.rb:10 T_MODULE 1 0 0 0 0 0
labkit/correlation.rb:10 T_STRING 1 0 0 0 0 0
labkit/correlation.rb:10 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:3 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:27 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:26 T_MODULE 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:26 T_STRING 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:26 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_FILE 1 0 0 0 0 0
labkit/context.rb:3 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:133 T_STRING 1 0 0 0 0 0
labkit/context.rb:133 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:23 T_ARRAY 1 0 0 0 0 0
labkit/context.rb:24 T_ARRAY 1 0 0 0 0 0
labkit/context.rb:26 T_CLASS 1 0 0 0 0 0
labkit/context.rb:26 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:27 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:37 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:45 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:49 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:53 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:57 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:65 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:74 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:76 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:82 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:89 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:93 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:99 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:117 T_ARRAY 1 0 0 0 0 0
active_support/core_ext/module/delegation.rb:187 T_ARRAY 1 0 0 0 0 0
active_support/core_ext/module/delegation.rb:190 T_STRING 1 0 0 0 0 0
active_support/core_ext/module/delegation.rb:191 T_STRING 1 0 0 0 0 0
active_support/core_ext/module/delegation.rb:193 T_ARRAY 1 0 0 0 0 0
labkit/context.rb:119 T_STRING 1 0 0 0 0 0
labkit/context.rb:119 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:119 T_ARRAY 1 0 0 0 0 0
labkit/context.rb:121 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:132 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:25 T_CLASS 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:25 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:11 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:17 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:24 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:72 T_ARRAY 1 0 0 0 0 0
gitlab/request_context.rb:14 T_OBJECT 1 0 0 0 0 0
log_perf.rb:95 T_ARRAY 2 0 0 0 0 0
active_support/core_ext/hash/except.rb:13 T_ARRAY 2 0 0 0 0 0
time.rb:724 T_STRING 2 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:31 T_STRING 2 0 0 0 0 0
gitlab/rugged_instrumentation.rb:18 T_ARRAY 2 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:43 T_FILE 2 0 0 0 0 0
labkit/correlation.rb:8 T_DATA 2 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_HASH 2 0 0 0 0 0
labkit/context.rb:133 T_CLASS 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:187 T_DATA 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:219 T_STRING 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:223 T_STRING 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:217 T_ARRAY 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:217 T_STRING 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_DATA 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_HASH 2 0 0 0 0 0
labkit/context.rb:117 T_IMEMO 2 0 0 0 0 0
gitlab/request_context.rb:14 T_ARRAY 2 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:25 T_STRING 3 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:27 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:22 T_OBJECT 3 0 0 0 0 0
active_support/json/encoding.rb:30 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:35 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:107 T_HASH 3 0 0 0 0 0
json/common.rb:211 T_DATA 3 0 0 0 0 0
json/common.rb:223 T_STRING 3 0 0 0 0 0
labkit/correlation.rb:6 T_DATA 3 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_DATA 3 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_IMEMO 4 0 0 0 0 0
active_support/json/encoding.rb:96 T_IMEMO 4 0 0 0 0 0
active_support/json/encoding.rb:96 T_HASH 4 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:43 T_HASH 4 0 0 0 0 0
active_support/core_ext/module/delegation.rb:218 T_STRING 4 0 0 0 0 0
active_support/core_ext/module/delegation.rb:220 T_STRING 4 0 0 0 0 0
active_support/core_ext/module/delegation.rb:222 T_STRING 4 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_STRING 6 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:43 T_DATA 6 0 0 0 0 0
active_support/core_ext/module/delegation.rb:215 T_STRING 10 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_STRING 12 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_ARRAY 13 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_HASH 13 0 0 0 0 0
active_support/json/encoding.rb:96 T_ARRAY 13 0 0 0 0 0
active_support/json/encoding.rb:92 T_STRING 17 0 0 0 0 0
active_support/json/encoding.rb:58 T_IMEMO 17 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_IMEMO 18 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_ARRAY 18 0 0 0 0 0
json/common.rb:223 T_ARRAY 21 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:43 T_ARRAY 31 0 0 0 0 0
active_support/core_ext/object/json.rb:39 T_STRING 34 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:43 T_IMEMO 34 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_ARRAY 60 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_IMEMO 67 0 0 0 0 0
...itlab/gdk-ee/gitlab/config/initializers/lograge.rb:43 T_STRING 123 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_STRING 201 0 0 0 0 0
TOTAL 876 0 0 0 0 0
After
Generating log entry, 233 allocations
log_perf.rb:85 T_OBJECT 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:28 T_IMEMO 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:31 T_ARRAY 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:31 T_IMEMO 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:45 T_IMEMO 1 0 0 0 0 0
gitlab/encoding_helper.rb:54 T_IMEMO 1 0 0 0 0 0
gitlab/utils/log_limited_array.rb:16 T_IMEMO 1 0 0 0 0 0
active_support/json/encoding.rb:57 T_IMEMO 1 0 0 0 0 0
gitlab/utils/log_limited_array.rb:15 T_ARRAY 1 0 0 0 0 0
time.rb:722 T_STRING 1 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:21 T_HASH 1 0 0 0 0 0
active_support/core_ext/object/json.rb:44 T_IMEMO 2 0 0 0 0 0
time.rb:724 T_STRING 2 0 0 0 0 0
json/common.rb:223 T_IMEMO 2 0 0 0 0 0
...grape_logging/formatters/lograge_with_timestamp.rb:31 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:22 T_OBJECT 3 0 0 0 0 0
active_support/json/encoding.rb:30 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:35 T_HASH 3 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_IMEMO 3 0 0 0 0 0
active_support/core_ext/object/json.rb:94 T_STRING 3 0 0 0 0 0
active_support/json/encoding.rb:96 T_IMEMO 3 0 0 0 0 0
active_support/json/encoding.rb:96 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:107 T_HASH 3 0 0 0 0 0
json/common.rb:211 T_DATA 4 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_STRING 6 0 0 0 0 0
active_support/core_ext/numeric/conversions.rb:108 T_STRING 6 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_ARRAY 9 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_HASH 9 0 0 0 0 0
active_support/json/encoding.rb:96 T_ARRAY 9 0 0 0 0 0
active_support/json/encoding.rb:92 T_STRING 12 0 0 0 0 0
active_support/json/encoding.rb:58 T_IMEMO 12 0 0 0 0 0
json/common.rb:223 T_ARRAY 19 0 0 0 0 0
active_support/core_ext/object/json.rb:39 T_STRING 36 0 0 0 0 0
json/common.rb:223 T_STRING 67 0 0 0 0 0
TOTAL 233 0 0 0 0 0
Generating log entry, 870 allocations
rails/railtie/configuration.rb:92 T_STRING 1 0 0 0 0 0
rails/railtie/configuration.rb:92 T_IMEMO 1 0 0 0 0 0
active_support/ordered_options.rb:42 T_STRING 1 0 0 0 0 0
gitlab/lograge/custom_options.rb:9 T_IMEMO 1 0 0 0 0 0
gitlab/lograge/custom_options.rb:12 T_IMEMO 1 0 0 0 0 0
gitlab/lograge/custom_options.rb:15 T_DATA 1 0 0 0 0 0
time.rb:722 T_STRING 1 0 0 0 0 0
active_support/core_ext/numeric/conversions.rb:108 T_STRING 1 0 0 0 0 0
gitlab/utils/log_limited_array.rb:16 T_IMEMO 1 0 0 0 0 0
active_support/core_ext/object/json.rb:158 T_IMEMO 1 0 0 0 0 0
active_support/json/encoding.rb:57 T_IMEMO 1 0 0 0 0 0
active_support/core_ext/object/json.rb:44 T_IMEMO 1 0 0 0 0 0
gitlab/utils/log_limited_array.rb:15 T_ARRAY 1 0 0 0 0 0
gitlab/lograge/custom_options.rb:14 T_HASH 1 0 0 0 0 0
gitlab/lograge/custom_options.rb:24 T_IMEMO 1 0 0 0 0 0
gitlab/gitaly_client.rb:341 T_ARRAY 1 0 0 0 0 0
labkit/correlation.rb:3 T_IMEMO 1 0 0 0 0 0
labkit/correlation.rb:10 T_MODULE 1 0 0 0 0 0
labkit/correlation.rb:10 T_STRING 1 0 0 0 0 0
labkit/correlation.rb:10 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:3 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:27 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:26 T_MODULE 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:26 T_STRING 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:26 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_FILE 1 0 0 0 0 0
labkit/context.rb:3 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:133 T_STRING 1 0 0 0 0 0
labkit/context.rb:133 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:23 T_ARRAY 1 0 0 0 0 0
labkit/context.rb:24 T_ARRAY 1 0 0 0 0 0
labkit/context.rb:26 T_CLASS 1 0 0 0 0 0
labkit/context.rb:26 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:27 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:37 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:45 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:49 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:53 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:57 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:65 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:74 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:76 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:82 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:89 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:93 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:99 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:117 T_ARRAY 1 0 0 0 0 0
active_support/core_ext/module/delegation.rb:187 T_ARRAY 1 0 0 0 0 0
active_support/core_ext/module/delegation.rb:190 T_STRING 1 0 0 0 0 0
active_support/core_ext/module/delegation.rb:191 T_STRING 1 0 0 0 0 0
active_support/core_ext/module/delegation.rb:193 T_ARRAY 1 0 0 0 0 0
labkit/context.rb:119 T_STRING 1 0 0 0 0 0
labkit/context.rb:119 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:119 T_ARRAY 1 0 0 0 0 0
labkit/context.rb:121 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:132 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:25 T_CLASS 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:25 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:11 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:17 T_IMEMO 1 0 0 0 0 0
labkit/correlation/correlation_id.rb:24 T_IMEMO 1 0 0 0 0 0
labkit/context.rb:72 T_ARRAY 1 0 0 0 0 0
gitlab/request_context.rb:14 T_OBJECT 1 0 0 0 0 0
log_perf.rb:95 T_ARRAY 2 0 0 0 0 0
time.rb:724 T_STRING 2 0 0 0 0 0
gitlab/rugged_instrumentation.rb:18 T_ARRAY 2 0 0 0 0 0
gitlab/lograge/custom_options.rb:28 T_FILE 2 0 0 0 0 0
labkit/correlation.rb:8 T_DATA 2 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_HASH 2 0 0 0 0 0
labkit/context.rb:133 T_CLASS 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:187 T_DATA 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:219 T_STRING 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:223 T_STRING 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:217 T_ARRAY 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:217 T_STRING 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_DATA 2 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_HASH 2 0 0 0 0 0
labkit/context.rb:117 T_IMEMO 2 0 0 0 0 0
gitlab/request_context.rb:14 T_ARRAY 2 0 0 0 0 0
gitlab/lograge/custom_options.rb:12 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:22 T_OBJECT 3 0 0 0 0 0
active_support/json/encoding.rb:30 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:35 T_HASH 3 0 0 0 0 0
active_support/json/encoding.rb:107 T_HASH 3 0 0 0 0 0
json/common.rb:211 T_DATA 3 0 0 0 0 0
json/common.rb:223 T_STRING 3 0 0 0 0 0
labkit/correlation.rb:6 T_DATA 3 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_DATA 3 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_IMEMO 4 0 0 0 0 0
active_support/json/encoding.rb:96 T_IMEMO 4 0 0 0 0 0
active_support/json/encoding.rb:96 T_HASH 4 0 0 0 0 0
gitlab/lograge/custom_options.rb:28 T_HASH 4 0 0 0 0 0
active_support/core_ext/module/delegation.rb:218 T_STRING 4 0 0 0 0 0
active_support/core_ext/module/delegation.rb:220 T_STRING 4 0 0 0 0 0
active_support/core_ext/module/delegation.rb:222 T_STRING 4 0 0 0 0 0
gitlab/lograge/custom_options.rb:12 T_ARRAY 6 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_STRING 6 0 0 0 0 0
gitlab/lograge/custom_options.rb:28 T_DATA 6 0 0 0 0 0
active_support/core_ext/module/delegation.rb:215 T_STRING 10 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_STRING 12 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_ARRAY 13 0 0 0 0 0
active_support/core_ext/object/json.rb:172 T_HASH 13 0 0 0 0 0
active_support/json/encoding.rb:96 T_ARRAY 13 0 0 0 0 0
active_support/json/encoding.rb:92 T_STRING 17 0 0 0 0 0
active_support/json/encoding.rb:58 T_IMEMO 17 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_IMEMO 18 0 0 0 0 0
active_support/core_ext/module/delegation.rb:231 T_ARRAY 18 0 0 0 0 0
json/common.rb:223 T_ARRAY 21 0 0 0 0 0
gitlab/lograge/custom_options.rb:28 T_ARRAY 31 0 0 0 0 0
active_support/core_ext/object/json.rb:39 T_STRING 34 0 0 0 0 0
gitlab/lograge/custom_options.rb:28 T_IMEMO 34 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_ARRAY 60 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_IMEMO 67 0 0 0 0 0
gitlab/lograge/custom_options.rb:28 T_STRING 123 0 0 0 0 0
labkit/correlation/correlation_id.rb:8 T_STRING 201 0 0 0 0 0
TOTAL 870 0 0 0 0 0
Script
Place it to Rails.root
and run RAILS_ENV=production rails runner log_perf.rb
Does this MR meet the acceptance criteria?
Conformity
- [-] Changelog entry
- [-] Documentation (if required)
-
Code review guidelines -
Merge request performance guidelines -
Style guides - [-] Database guides
- [-] Separation of EE specific content
Availability and Testing
- [-] Review and add/update tests for this feature/bug. Consider all test levels. See the Test Planning Process.
- [-] Tested in all supported browsers
- [-] Informed Infrastructure department of a default or new setting change, if applicable per definition of done
Security
If this MR contains changes to processing or storing of credentials or tokens, authorization and authentication methods and other items described in the security review guidelines:
- [-] Label as security and @ mention
@gitlab-com/gl-security/appsec
- [-] The MR includes necessary changes to maintain consistency between UI, API, email, or other methods
- [-] Security reports checked/validated by a reviewer from the AppSec team
Merge request reports
Activity
changed milestone to %12.9
added Stuff that should Just Work bugperformance labels
1 Warning 503e3859: Commits that change 30 or more lines across at least 3 files must describe these changes in the commit body Reviewer roulette
Changes that require review have been detected! A merge request is normally reviewed by both a reviewer and a maintainer in its primary category (e.g. frontend or backend), and by a maintainer in all other categories.
To spread load more evenly across eligible reviewers, Danger has randomly picked a candidate for each review slot. Feel free to override this selection if you think someone else would be better-suited, or the chosen person is unavailable.
To read more on how to use the reviewer roulette, please take a look at the Engineering workflow and code review guidelines.
Once you've decided who will review this merge request, mention them as you normally would! Danger does not (yet?) automatically notify them for you.
Category Reviewer Maintainer backend Aakriti Gupta ( @aakriti.gupta
)Ash McKenzie ( @ashmckenzie
)Generated by
DangerEdited by 🤖 GitLab Bot 🤖added backstage [DEPRECATED] label
- Resolved by Peter Leitzen
Hi @splattael,
We've discussed this during coworking day
Can you do the backend review, maybe you spot other places where we can save some cycles?
I was thinking about doing
lazy
whenmap
-ing theparams
, it helps a bit for large collections but has a bit of overhead.
assigned to @splattael
- Resolved by Adam Hegyi
- Resolved by Adam Hegyi
- Resolved by Adam Hegyi
- Resolved by Adam Hegyi
- Resolved by Peter Leitzen
- Resolved by Adam Hegyi
- Resolved by Peter Leitzen
unassigned @splattael
added groupoptimize label
- Resolved by Adam Hegyi
- Resolved by Adam Hegyi
- Resolved by Adam Hegyi
@ahegyi thanks so much, this is great! As the counting is already inaccurate in one sense (i.e. we might log slightly more than 10 KiB due to the size of the sentinel value), I'd be in favour of cases where we can simplify the code at a small cost to accuracy - especially if we over-count rather than under-count.
- Resolved by Adam Hegyi
added 676 commits
-
f32feeb6...22d85fbc - 675 commits from branch
master
- 44bdf1eb - Reduce object allocation during logging
-
f32feeb6...22d85fbc - 675 commits from branch
- Resolved by Peter Leitzen
hey @splattael,
Could you take another look?
assigned to @splattael
unassigned @splattael
added 34 commits
-
44bdf1eb...d8e1cfcf - 33 commits from branch
master
- bff8a38e - Reduce object allocation during logging
-
44bdf1eb...d8e1cfcf - 33 commits from branch
added 12 commits
-
408ab23f...89e14fb6 - 11 commits from branch
master
- 0b12508a - Reduce object allocation during logging
-
408ab23f...89e14fb6 - 11 commits from branch
added 100 commits
-
0b12508a...eb36e9e1 - 99 commits from branch
master
- d809af29 - Reduce object allocation during logging
-
0b12508a...eb36e9e1 - 99 commits from branch
Thanks for the updates @ahegyi
LGTM
assigned to @splattael
Hi @smcgivern,
Could you do the BE maintainer review? (I've just rebased it.)
assigned to @smcgivern and unassigned @splattael
added 43 commits
-
d809af29...4007dea8 - 42 commits from branch
master
- 159d62b9 - Reduce object allocation during logging
-
d809af29...4007dea8 - 42 commits from branch
- Resolved by Adam Hegyi
- Resolved by Adam Hegyi
Thanks @ahegyi, nice work! One question about a spec we may not need, or we may decide to keep it.
The failures are waiting on !26080 (merged).
unassigned @smcgivern
added 26 commits
-
159d62b9...46eb6ce2 - 25 commits from branch
master
- 503e3859 - Reduce object allocation during logging
-
159d62b9...46eb6ce2 - 25 commits from branch
assigned to @smcgivern
Thanks @ahegyi!
mentioned in commit c118dd50
mentioned in issue gitlab-com/gl-infra/scalability#190
mentioned in issue #208501 (closed)
mentioned in merge request !26257 (merged)
added workflowstaging label
added workflowcanary label and removed workflowstaging label
added workflowproduction label and removed workflowcanary label