Spec failures in Ruby 2.7.7: expected `Gitlab::Memory::Instrumentation.available?` to be truthy, got false
Summary
This failure is impacting the following tests:
- rspec ./spec/lib/gitlab/memory/instrumentation_spec.rb:13 # Gitlab::Memory::Instrumentation.available? returns true
- rspec ./spec/lib/gitlab/memory/instrumentation_spec.rb:21 # Gitlab::Memory::Instrumentation.start_thread_memory_allocations a hash is returned
- rspec ./spec/lib/gitlab/memory/instrumentation_spec.rb:50 # Gitlab::Memory::Instrumentation.with_memory_allocations a hash is returned
Failures:
1) Gitlab::Memory::Instrumentation.available? returns true
Failure/Error: expect(described_class).to be_available
expected `Gitlab::Memory::Instrumentation.available?` to be truthy, got false
# ./spec/lib/gitlab/memory/instrumentation_spec.rb:14:in `block (3 levels) in <main>'
# ./spec/spec_helper.rb:413:in `block (3 levels) in <top (required)>'
# ./spec/support/sidekiq_middleware.rb:18:in `with_sidekiq_server_middleware'
# ./spec/spec_helper.rb:405:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:401:in `block (3 levels) in <top (required)>'
# ./lib/gitlab/application_context.rb:59:in `with_raw_context'
# ./spec/spec_helper.rb:401:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:241:in `block (2 levels) in <top (required)>'
# ./spec/support/system_exit_detected.rb:7:in `block (2 levels) in <main>'
# ./spec/support/flaky_tests.rb:27:in `block (2 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (3 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:60:in `with_cross_joins_prevented'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (2 levels) in <main>'
2) Gitlab::Memory::Instrumentation.start_thread_memory_allocations a hash is returned
Failure/Error: is_expected.to be_a(Hash)
expected nil to be a kind of Hash
# ./spec/lib/gitlab/memory/instrumentation_spec.rb:22:in `block (3 levels) in <main>'
# ./spec/spec_helper.rb:413:in `block (3 levels) in <top (required)>'
# ./spec/support/sidekiq_middleware.rb:18:in `with_sidekiq_server_middleware'
# ./spec/spec_helper.rb:405:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:401:in `block (3 levels) in <top (required)>'
# ./lib/gitlab/application_context.rb:59:in `with_raw_context'
# ./spec/spec_helper.rb:401:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:241:in `block (2 levels) in <top (required)>'
# ./spec/support/system_exit_detected.rb:7:in `block (2 levels) in <main>'
# ./spec/support/flaky_tests.rb:27:in `block (2 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (3 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:60:in `with_cross_joins_prevented'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (2 levels) in <main>'
3) Gitlab::Memory::Instrumentation.with_memory_allocations a hash is returned
Failure/Error: mem_total_bytes: eq(result[:mem_bytes] + 40 * result[:mem_objects])
NoMethodError:
undefined method `[]' for nil:NilClass
# ./spec/lib/gitlab/memory/instrumentation_spec.rb:56:in `block (3 levels) in <main>'
# ./spec/spec_helper.rb:413:in `block (3 levels) in <top (required)>'
# ./spec/support/sidekiq_middleware.rb:18:in `with_sidekiq_server_middleware'
# ./spec/spec_helper.rb:405:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:401:in `block (3 levels) in <top (required)>'
# ./lib/gitlab/application_context.rb:59:in `with_raw_context'
# ./spec/spec_helper.rb:401:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:241:in `block (2 levels) in <top (required)>'
# ./spec/support/system_exit_detected.rb:7:in `block (2 levels) in <main>'
# ./spec/support/flaky_tests.rb:27:in `block (2 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (3 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:60:in `with_cross_joins_prevented'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (2 levels) in <main>'
Finished in 3.18 seconds (files took 48.43 seconds to load)
3 examples, 3 failures
Failed examples:
rspec ./spec/lib/gitlab/memory/instrumentation_spec.rb:13 # Gitlab::Memory::Instrumentation.available? returns true
rspec ./spec/lib/gitlab/memory/instrumentation_spec.rb:21 # Gitlab::Memory::Instrumentation.start_thread_memory_allocations a hash is returned
rspec ./spec/lib/gitlab/memory/instrumentation_spec.rb:50 # Gitlab::Memory::Instrumentation.with_memory_allocations a hash is returned
- rspec ./spec/initializers/lograge_spec.rb:99
Failures:
1) lograge for Controller requests when logging memory allocations logs memory usage metrics
Failure/Error: return @app.call(env) unless rendering_memory_profiler?(request)
#<Lograge::Formatters::Json:0x00007fadc4872520> received :call with unexpected arguments
expected: (a hash including :mem_objects)
got: ({:action=>"index", :controller=>"RootController", "correlation_id"=>"new-correlation-id", :cpu_s=>0.0...uration_s=>5, :time=>"2022-11-29T18:39:19.737Z", :view_duration_s=>0.0, :worker_id=>"process_16418"})
Diff:
@@ -1,64 +1,127 @@
-["a hash including :mem_objects"]
+[{:action=>"index",
+ :controller=>"RootController",
+ "correlation_id"=>"new-correlation-id",
+ :cpu_s=>0.019701,
+ :db_cached_count=>0,
+ :db_ci_cached_count=>0,
+ :db_ci_count=>0,
+ :db_ci_duration_s=>0.0,
+ :db_ci_replica_cached_count=>0,
+ :db_ci_replica_count=>0,
+ :db_ci_replica_duration_s=>0.0,
+ :db_ci_replica_wal_cached_count=>0,
+ :db_ci_replica_wal_count=>0,
+ :db_ci_wal_cached_count=>0,
+ :db_ci_wal_count=>0,
+ :db_count=>1,
+ :db_duration_s=>0.0005,
+ :db_geo_cached_count=>0,
+ :db_geo_count=>0,
+ :db_geo_duration_s=>0.0,
+ :db_geo_wal_cached_count=>0,
+ :db_geo_wal_count=>0,
+ :db_main_cached_count=>0,
+ :db_main_count=>1,
+ :db_main_duration_s=>0.001,
+ :db_main_replica_cached_count=>0,
+ :db_main_replica_count=>0,
+ :db_main_replica_duration_s=>0.0,
+ :db_main_replica_wal_cached_count=>0,
+ :db_main_replica_wal_count=>0,
+ :db_main_wal_cached_count=>0,
+ :db_main_wal_count=>0,
+ :db_primary_cached_count=>0,
+ :db_primary_count=>1,
+ :db_primary_duration_s=>0.001,
+ :db_primary_wal_cached_count=>0,
+ :db_primary_wal_count=>0,
+ :db_replica_cached_count=>0,
+ :db_replica_count=>0,
+ :db_replica_duration_s=>0.0,
+ :db_replica_wal_cached_count=>0,
+ :db_replica_wal_count=>0,
+ :db_write_count=>0,
+ :duration_s=>0.0117,
+ :feature_flag_states=>[],
+ :format=>:html,
+ :location=>"http://www.example.com/users/sign_in",
+ "meta.caller_id"=>"RootController#index",
+ "meta.client_id"=>"ip/127.0.0.1",
+ "meta.feature_category"=>"projects",
+ "meta.remote_ip"=>"127.0.0.1",
+ :method=>"GET",
+ :params=>[],
+ :path=>"/",
+ :pid=>16418,
+ :rate_limiting_gates=>[],
+ :remote_ip=>"127.0.0.1",
+ :request_urgency=>:low,
+ :response_bytes=>102,
+ :status=>302,
+ :target_duration_s=>5,
+ :time=>"2022-11-29T18:39:19.737Z",
+ :view_duration_s=>0.0,
+ :worker_id=>"process_16418"}]
# ./lib/gitlab/middleware/memory_report.rb:13:in `call'
# ./lib/gitlab/middleware/speedscope.rb:13:in `call'
# ./lib/gitlab/query_limiting/middleware.rb:17:in `block in call'
# ./lib/gitlab/query_limiting/transaction.rb:45:in `run'
# ./lib/gitlab/query_limiting/middleware.rb:16:in `call'
# ./lib/gitlab/database/load_balancing/rack_middleware.rb:23:in `call'
# ./lib/gitlab/jira/middleware.rb:19:in `call'
# ./lib/gitlab/middleware/go.rb:20:in `call'
# ./lib/gitlab/etag_caching/middleware.rb:21:in `call'
# ./lib/gitlab/middleware/query_analyzer.rb:11:in `block in call'
# ./lib/gitlab/database/query_analyzer.rb:37:in `within'
# ./lib/gitlab/middleware/query_analyzer.rb:11:in `call'
# ./lib/gitlab/middleware/multipart.rb:173:in `call'
# ./lib/gitlab/middleware/read_only/controller.rb:50:in `call'
# ./lib/gitlab/middleware/read_only.rb:18:in `call'
# ./lib/gitlab/middleware/same_site_cookies.rb:27:in `call'
# ./lib/gitlab/middleware/handle_malformed_strings.rb:21:in `call'
# ./lib/gitlab/middleware/basic_health_check.rb:25:in `call'
# ./lib/gitlab/middleware/handle_ip_spoof_attack_error.rb:25:in `call'
# ./lib/gitlab/middleware/request_context.rb:21:in `call'
# ./lib/gitlab/middleware/webhook_recursion_detection.rb:15:in `call'
# ./config/initializers/fix_local_cache_middleware.rb:11:in `call'
# ./lib/gitlab/middleware/compressed_json.rb:37:in `call'
# ./lib/gitlab/middleware/static.rb:11:in `call'
# ./lib/gitlab/testing/clear_process_memory_cache_middleware.rb:13:in `call'
# ./lib/gitlab/testing/request_inspector_middleware.rb:35:in `call'
# ./lib/gitlab/testing/robots_blocker_middleware.rb:30:in `call'
# ./lib/gitlab/testing/request_blocker_middleware.rb:47:in `call'
# ./lib/gitlab/middleware/rack_multipart_tempfile_factory.rb:19:in `call'
# ./lib/gitlab/middleware/sidekiq_web_static.rb:20:in `call'
# ./lib/gitlab/metrics/requests_rack_middleware.rb:77:in `call'
# ./spec/initializers/lograge_spec.rb:43:in `block (3 levels) in <main>'
# ./spec/initializers/lograge_spec.rb:108:in `block (4 levels) in <main>'
# ./spec/spec_helper.rb:413:in `block (3 levels) in <top (required)>'
# ./spec/support/sidekiq_middleware.rb:18:in `with_sidekiq_server_middleware'
# ./spec/spec_helper.rb:405:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:401:in `block (3 levels) in <top (required)>'
# ./lib/gitlab/application_context.rb:59:in `with_raw_context'
# ./spec/spec_helper.rb:401:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:241:in `block (2 levels) in <top (required)>'
# ./spec/support/system_exit_detected.rb:7:in `block (2 levels) in <main>'
# ./spec/support/flaky_tests.rb:27:in `block (2 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (3 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:60:in `with_cross_joins_prevented'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (2 levels) in <main>'
Finished in 6.62 seconds (files took 47.62 seconds to load)
1 example, 1 failure
- rspec ./spec/lib/gitlab/instrumentation_helper_spec.rb:132
Failures:
1) Gitlab::InstrumentationHelper.add_instrumentation_data when logging memory allocations logs memory usage metrics
Failure/Error:
expect(payload).to include(
:mem_objects,
:mem_bytes,
:mem_mallocs
)
expected {:cpu_s => 0.000285, :db_cached_count => 0, :db_ci_cached_count => 0, :db_ci_count => 0, :db_ci_duration_s => 0...al_count => 0, :db_write_count => 0, :pid => 14529, :rate_limiting_gates => [], :worker_id => "process_14529"} to include :mem_objects, :mem_bytes, and :mem_mallocs
Diff:
@@ -1,42 +1,83 @@
-[:mem_objects, :mem_bytes, :mem_mallocs]
+:cpu_s => 0.000285,
+:db_cached_count => 0,
+:db_ci_cached_count => 0,
+:db_ci_count => 0,
+:db_ci_duration_s => 0.0,
+:db_ci_replica_cached_count => 0,
+:db_ci_replica_count => 0,
+:db_ci_replica_duration_s => 0.0,
+:db_ci_replica_wal_cached_count => 0,
+:db_ci_replica_wal_count => 0,
+:db_ci_wal_cached_count => 0,
+:db_ci_wal_count => 0,
+:db_count => 0,
+:db_geo_cached_count => 0,
+:db_geo_count => 0,
+:db_geo_duration_s => 0.0,
+:db_geo_wal_cached_count => 0,
+:db_geo_wal_count => 0,
+:db_main_cached_count => 0,
+:db_main_count => 0,
+:db_main_duration_s => 0.0,
+:db_main_replica_cached_count => 0,
+:db_main_replica_count => 0,
+:db_main_replica_duration_s => 0.0,
+:db_main_replica_wal_cached_count => 0,
+:db_main_replica_wal_count => 0,
+:db_main_wal_cached_count => 0,
+:db_main_wal_count => 0,
+:db_primary_cached_count => 0,
+:db_primary_count => 0,
+:db_primary_duration_s => 0.0,
+:db_primary_wal_cached_count => 0,
+:db_primary_wal_count => 0,
+:db_replica_cached_count => 0,
+:db_replica_count => 0,
+:db_replica_duration_s => 0.0,
+:db_replica_wal_cached_count => 0,
+:db_replica_wal_count => 0,
+:db_write_count => 0,
+:pid => 14529,
+:rate_limiting_gates => [],
+:worker_id => "process_14529",
# ./spec/lib/gitlab/instrumentation_helper_spec.rb:135:in `block (4 levels) in <main>'
# ./spec/spec_helper.rb:413:in `block (3 levels) in <top (required)>'
# ./spec/support/sidekiq_middleware.rb:18:in `with_sidekiq_server_middleware'
# ./spec/spec_helper.rb:405:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:401:in `block (3 levels) in <top (required)>'
# ./lib/gitlab/application_context.rb:59:in `with_raw_context'
# ./spec/spec_helper.rb:401:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:368:in `block (3 levels) in <top (required)>'
# ./lib/gitlab/with_request_store.rb:17:in `enabling_request_store'
# ./lib/gitlab/with_request_store.rb:10:in `with_request_store'
# ./spec/spec_helper.rb:368:in `block (2 levels) in <top (required)>'
# ./spec/spec_helper.rb:241:in `block (2 levels) in <top (required)>'
# ./spec/support/system_exit_detected.rb:7:in `block (2 levels) in <main>'
# ./spec/support/flaky_tests.rb:27:in `block (2 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (3 levels) in <main>'
# ./spec/support/database/prevent_cross_joins.rb:60:in `with_cross_joins_prevented'
# ./spec/support/database/prevent_cross_joins.rb:106:in `block (2 levels) in <main>'
Finished in 3.52 seconds (files took 50.41 seconds to load)
1 example, 1 failure
Failed examples:
rspec ./spec/lib/gitlab/instrumentation_helper_spec.rb:132 # Gitlab::InstrumentationHelper.add_instrumentation_data when logging memory allocations logs memory usage metrics
How to reproduce
-
Ensure Ruby 2.7.7 is installed by running
gdk update
-
Make a below change in
spec/support/memory_instrumentation_helper.rb
diff --git a/spec/support/memory_instrumentation_helper.rb b/spec/support/memory_instrumentation_helper.rb index 84ec02fa5aa0..718a1e33fad4 100644 --- a/spec/support/memory_instrumentation_helper.rb +++ b/spec/support/memory_instrumentation_helper.rb @@ -6,7 +6,7 @@ # - https://github.com/ruby/ruby/pull/3978 module MemoryInstrumentationHelper def skip_memory_instrumentation! - return if ::Gitlab::Memory::Instrumentation.available? + # return if ::Gitlab::Memory::Instrumentation.available? # if we are running in CI, a test cannot be skipped return if ENV['CI']
-
Run
CI=true bundle exec rspec spec/lib/gitlab/memory/instrumentation_spec.rb
Edited by Nao Hashizume