Observing Errors in Logs - Systemd Worker Monitoring Issue in ManageIQ

[rabah-beldi]

We encountered an error during the monitoring of systemd workers in our ManageIQ environment. The error occurs when the application attempts to access an array element that is nil. This issue appears every 15 seconds in the logs.

Detailed error message in Logs:

The error appears every 15 seconds in the logs:

evm[2511]: ERROR -- evm: MIQ(MiqServer#monitor) undefined method `[]' for nil:NilClass
Nov 27 11:12:31 XXXX evm[2511]: ERROR -- evm: [NoMethodError]: undefined method `[]' for nil:NilClass  Method:[block (2 levels) in <class:LogProxy>]
Nov 27 11:12:31 XXXX evm[2511]: ERROR -- evm: /var/www/miq/vmdb/app/models/miq_server/worker_management/systemd.rb:14:in `block in sync_starting_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/systemd.rb:10:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/systemd.rb:10:in `sync_starting_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:26:in `monitor_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:214:in `block in monitor'
/opt/manageiq/manageiq-gemset/gems/more_core_extensions-4.4.0/lib/more_core_extensions/core_ext/benchmark/realtime_store.rb:20:in `realtime_store'
/opt/manageiq/manageiq-gemset/gems/more_core_extensions-4.4.0/lib/more_core_extensions/core_ext/benchmark/realtime_store.rb:56:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:214:in `monitor'
/var/www/miq/vmdb/lib/workers/evm_server.rb:142:in `block in monitor'
/opt/manageiq/manageiq-gemset/gems/more_core_extensions-4.4.0/lib/more_core_extensions/core_ext/benchmark/realtime_store.rb:20:in `realtime_store'
/opt/manageiq/manageiq-gemset/gems/more_core_extensions-4.4.0/lib/more_core_extensions/core_ext/benchmark/realtime_store.rb:62:in `realtime_block'
/var/www/miq/vmdb/lib/workers/evm_server.rb:142:in `monitor'
/var/www/miq/vmdb/lib/workers/evm_server.rb:51:in `block (2 levels) in monitor_servers'
/var/www/miq/vmdb/lib/workers/evm_server.rb:273:in `block in as_each_server'
/var/www/miq/vmdb/lib/workers/evm_server.rb:271:in `each'
/var/www/miq/vmdb/lib/workers/evm_server.rb:271:in `as_each_server'
/var/www/miq/vmdb/lib/workers/evm_server.rb:51:in `block in monitor_servers'
/var/www/miq/vmdb/lib/workers/evm_server.rb:49:in `loop'
/var/www/miq/vmdb/lib/workers/evm_server.rb:49:in `monitor_servers'
/var/www/miq/vmdb/lib/workers/evm_server.rb:31:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:84:in `start'
lib/workers/bin/evm_server.rb:4:in `<main>'

4. Describe of the environment:
   • Version : quinteros-2.2.20241113183051_fc4741c
   • Environment
     • For ManageIQ: EC2 appliance
     • For gems:
       `RubyGems Environment:

• RUBYGEMS VERSION: 3.2.33
• RUBY VERSION: 3.0.4 (2022-04-12 patchlevel 208) [x86_64-linux]
• INSTALLATION DIRECTORY: /opt/manageiq/manageiq-gemset
• USER INSTALLATION DIRECTORY: /root/.gem/ruby
• RUBY EXECUTABLE: /usr/bin/ruby
• GIT EXECUTABLE: /usr/bin/git
• EXECUTABLE DIRECTORY: /opt/manageiq/manageiq-gemset/bin
• SPEC CACHE DIRECTORY: /root/.gem/specs
• SYSTEM CONFIGURATION DIRECTORY: /etc
• RUBYGEMS PLATFORMS:
  • ruby
  • x86_64-linux
• GEM PATHS:
  • /opt/manageiq/manageiq-gemset
  • /usr/share/gems
  • /usr/local/share/gems
• GEM CONFIGURATION:
  • :update_sources => true
  • :verbose => true
  • :backtrace => false
  • :bulk_threshold => 1000
  • "gem" => "--install-dir=/usr/local/share/gems --bindir /usr/local/bin"
• REMOTE SOURCES:
  • https://rubygems.org/
• SHELL PATH:
  • /opt/manageiq/manageiq-gemset/bin
  • /usr/local/sbin
  • /usr/local/bin
  • /usr/sbin
  • /usr/bin
  • /root/bin

ruby -v

ruby 3.0.4p208 (2022-04-12 revision 3fa771dded) [x86_64-linux]`

[agrare]

This bug was fixed by #22942 and will be in the radjabov release. I added the quinteros backport label but I don't think we're going to be doing a quinteros-3
cc @Fryguy

[rabah-beldi]

Hi @Fryguy @agrare

I would like to get additional information regarding this issue affecting our production environment. We are observing several abnormal behaviors:

Database disconnections/reconnections occurring every 15 seconds.
Since the upgrade to quinteros version, we have experienced several critical incidents where all requests remained stuck in pending state. In each case, we were forced to restart the appliance to restore service.

Could you confirm if you are aware of these impacts on production? Given the severity of these issues, we would also like to know if a quinteros-3 version could be provided in the near future.

Here is the evmserverd status on our environnements (dev and prd):
`systemctl status evmserverd
● evmserverd.service - EVM server daemon
Loaded: loaded (/usr/lib/systemd/system/evmserverd.service; enabled; vendor preset: disabled)
Active: active (running) since Thu 2025-02-20 10:19:22 CET; 1h 18min ago
Main PID: 2526 (ruby)
Tasks: 4 (limit: 200388)
Memory: 505.5M
CGroup: /system.slice/evmserverd.service
└─2526 MIQ Server

Feb 20 11:37:54 XXXX evm[2526]: INFO -- evm: MIQ(MiqServer#heartbeat) Heartbeat [2025-02-20 10:37:54 UTC]...Complete
Feb 20 11:37:59 XXXX evm[2526]: INFO -- evm: MIQ(MiqQueue.get) Message id: [21342852], Zone: [Internal], Role: [], Server: [83e5279b-ba89-4832-acfd-7ddafd5f5faf], MiqTask id: [], Handler id: [MiqServer 5], Ident:>
Feb 20 11:37:59 XXXX evm[2526]: INFO -- evm: MIQ(MiqQueue#deliver) Message id: [21342852], Delivering...
Feb 20 11:37:59 XXXX evm[2526]: INFO -- evm: MIQ(MiqQueue#delivered) Message id: [21342852], State: [ok], Delivered in [0.052106838] seconds
Feb 20 11:38:06 XXXX evm[2526]: ERROR -- evm: MIQ(MiqServer#monitor) undefined method []' for nil:NilClass Feb 20 11:38:06 XXXX evm[2526]: ERROR -- evm: [NoMethodError]: undefined method []' for nil:NilClass Method:[block (2 levels) in class:LogProxy]
Feb 20 11:38:06 XXXX evm[2526]: ERROR -- evm: /var/www/miq/vmdb/app/models/miq_server/worker_management/systemd.rb:14:in block in sync_starting_workers' /var/www/miq/vmdb/app/models/miq_server/worker_management/systemd.rb:10:in each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/systemd.rb:10:in sync_starting_workers' /var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:26:in monitor_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:214:in block in monitor' /opt/manageiq/manageiq-gemset/gems/more_core_extensions-4.4.0/lib/more_core_extensions/core_ext/benchmark/realtime_store.rb:20:in realtime_store'
/opt/manageiq/manageiq-gemset/gems/more_core_extensions-4.4.0/lib/more_core_extensions/core_ext/benchmark/realtime_store.rb:56:in realtime_block' /var/www/miq/vmdb/app/models/miq_server.rb:214:in monitor'
/var/www/miq/vmdb/lib/workers/evm_server.rb:142:in block in monitor' /opt/manageiq/manageiq-gemset/gems/more_core_extensions-4.4.0/lib/more_core_extensions/core_ext/benchmark/realtime_store.rb:20:in realtime_store'
/opt/manageiq/manageiq-gemset/gems/more_core_extensions-4.4.0/lib/more_core_extensions/core_ext/benchmark/realtime_store.rb:62:in realtime_block' /var/www/miq/vmdb/lib/workers/evm_server.rb:142:in monitor'
/var/www/miq/vmdb/lib/workers/evm_server.rb:51:in block (2 levels) in monitor_servers' /var/www/miq/vmdb/lib/workers/evm_server.rb:273:in block in as_each_server'
/var/www/miq/vmdb/lib/workers/evm_server.rb:271:in each' /var/www/miq/vmdb/lib/workers/evm_server.rb:271:in as_each_server'
/var/www/miq/vmdb/lib/workers/evm_server.rb:51:in block in monitor_servers' /var/www/miq/vmdb/lib/workers/evm_server.rb:49:in loop'
/var/www/miq/vmdb/lib/workers/evm_server.rb:49:in monitor_servers' /var/www/miq/vmdb/lib/workers/evm_server.rb:31:in start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:84:in start' lib/workers/bin/evm_server.rb:4:in

'
Feb 20 11:38:06 XXXX evm[2526]: INFO -- evm: MIQ(MiqServer#monitor) Reconnecting to database after error...
Feb 20 11:38:06 XXXX evm[2526]: INFO -- evm: MIQ(MiqServer#monitor) Reconnecting to database after error...Successful
Feb 20 11:38:06 XXXX evm[2526]: INFO -- evm: MIQ(EvmServer#monitor) Server Monitoring Complete - Timings: {:server_dequeue=>0.0052280426025390625, :role_monitor=>0.0017230510711669922, :worker_monitor=>2.012697458267>`

Thank you in advance for your help.