Output constant must match the constantized class name

[jrafanie]

Constantize can demodulize to an incorrect class, so we should skip any class
names that don't constantize to the expected class.

In this example, if you do the following in rails console, you'll get the
following:

Autoload the base manager eventcatcher:

ManageIQ::Providers::BaseManager::EventCatcher

Try to constantize a non existing event catcher in a valid provider namespace:
"ManageIQ::Providers::Foreman::ProvisioningManager::EventCatcher".constantize
=> ManageIQ::Providers::BaseManager::EventCatcher

Seen in the logs for https://bugzilla.redhat.com/show_bug.cgi?id=1759711

[d-m-u]

👍 🐉
I don't think I have a better idea.

[jrafanie]

@bdunne @Fryguy @d-m-u what do you think of this? We don't know if the user in the referenced BZ actually added a new worker type for the foreman event catcher without adding the class for it but we definitely see the logs indicating the base manager event catcher started. We should never have gotten to this point... sync_workers should never try to call sync_workers on a class that doesn't match the name in our list of worker classes.

WARN -- : MIQ(ManageIQ::Providers::BaseManager::EventCatcher#status_update) No such process [Event Monitor for Provider: YYYY Configuration Manager] with PID=[XXXX], aborting worker.

[jrafanie]

haha, this is what the logging looks like... I didn't do an miq exception because I think we want the backtrace here:

[----] E, [2019-10-15T13:26:26.482463 #40209:3fe439834e6c] ERROR -- : MIQ(MiqServer#sync_workers) Failed to sync_workers for class: ManageIQ::Providers::Foreman::ProvisioningManager::EventCatcher
[----] E, [2019-10-15T13:26:26.482647 #40209:3fe439834e6c] ERROR -- : [NameError]: Constant problem: expected: ManageIQ::Providers::Foreman::ProvisioningManager::EventCatcher, constantized: ManageIQ::Providers::BaseManager::EventCatcher  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2019-10-15T13:26:26.482765 #40209:3fe439834e6c] ERROR -- : /Users/joerafaniello/Code/manageiq/app/models/miq_server/worker_management/monitor.rb:53:in `block in sync_workers'
/Users/joerafaniello/Code/manageiq/app/models/miq_server/worker_management/monitor.rb:50:in `each'
/Users/joerafaniello/Code/manageiq/app/models/miq_server/worker_management/monitor.rb:50:in `sync_workers'
...

[bdunne]

This is probably a good idea regardless, but I'm not sure it's the source of the problem. If you add the same provider type, do you seen the same errors in your logs?

[jrafanie]

This is probably a good idea regardless, but I'm not sure it's the source of the problem. If you add the same provider type, do you seen the same errors in your logs?

Yes.

With just this change:

index c692917d17..9e055ee4cd 100644
--- a/lib/workers/miq_worker_types.rb
+++ b/lib/workers/miq_worker_types.rb
@@ -16,6 +16,7 @@ MIQ_WORKER_TYPES = {
   "ManageIQ::Providers::AzureStack::CloudManager::RefreshWorker"                => %i[manageiq_default],
   "ManageIQ::Providers::AzureStack::NetworkManager::RefreshWorker"              => %i[manageiq_default],
   "ManageIQ::Providers::Foreman::ConfigurationManager::RefreshWorker"           => %i(manageiq_default),
+  "ManageIQ::Providers::Foreman::ProvisioningManager::EventCatcher"             => %i(manageiq_default),
   "ManageIQ::Providers::Foreman::ProvisioningManager::RefreshWorker"            => %i(manageiq_default),
   "ManageIQ::Providers::Google::CloudManager::EventCatcher"                     => %i(manageiq_default),
   "ManageIQ::Providers::Google::CloudManager::MetricsCollectorWorker"           => %i(manageiq_default),

rake evm:start logs this branch's error:

[----] I, [2019-10-15T15:09:42.919778 #43078:3fc13a036e6c]  INFO -- : MIQ(MiqQueue.put) Message id: [4],  id: [], Zone: [default], Role: [], Server: [60fe7d04-b998-4fc6-a9a9-88f539d3ec6c], MiqTask id: [], Ident: [generic], Target id: [], Instance id: [1], Task id: [], Command: [MiqServer.delete_active_log_collections], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[----] I, [2019-10-15T15:09:43.118382 #43078:3fc13a036e6c]  INFO -- :
---
:kill_algorithm:
  :name: :used_swap_percent_gt_value
  :value: 80
:miq_server_time_threshold: 120
:nice_delta: 1
:poll: 2
:start_algorithm:
  :name: :used_swap_percent_lt_value
  :value: 60
:sync_interval: 1800
:wait_for_started_timeout: 600
[----] E, [2019-10-15T15:09:43.199842 #43078:3fc13a036e6c] ERROR -- : MIQ(MiqServer#sync_workers) Failed to sync_workers for class: ManageIQ::Providers::Foreman::ProvisioningManager::EventCatcher
[----] E, [2019-10-15T15:09:43.199955 #43078:3fc13a036e6c] ERROR -- : [NameError]: Constant problem: expected: ManageIQ::Providers::Foreman::ProvisioningManager::EventCatcher, constantized: ManageIQ::Providers::BaseManager::EventCatcher  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2019-10-15T15:09:43.200001 #43078:3fc13a036e6c] ERROR -- : /Users/joerafaniello/Code/manageiq/app/models/miq_server/worker_management/monitor.rb:53:in `block in sync_workers'
/Users/joerafaniello/Code/manageiq/app/models/miq_server/worker_management/monitor.rb:50:in `each'
/Users/joerafaniello/Code/manageiq/app/models/miq_server/worker_management/monitor.rb:50:in `sync_workers'
/Users/joerafaniello/Code/manageiq/app/models/miq_server.rb:156:in `start'
/Users/joerafaniello/Code/manageiq/app/models/miq_server.rb:247:in `start'
/Users/joerafaniello/Code/manageiq/lib/workers/evm_server.rb:27:in `start'
/Users/joerafaniello/Code/manageiq/lib/workers/evm_server.rb:48:in `start'
/Users/joerafaniello/Code/manageiq/lib/workers/bin/evm_server.rb:4:in `<main>'

[Fryguy]

I'm not sure I like bandaid-ing an issue we don't really understand.

This feels like a bug with constantize. How can it resolve an unknown constant?

[Fryguy]

Ohhh...it's the 'ol find the constant in the nearest class issue... Similar to String::Hash, but not exactly.

😩

[miq-bot]

Checked commit jrafanie@afe1f02 with ruby 2.4.6, rubocop 0.69.0, haml-lint 0.20.0, and yamllint 1.10.0
2 files checked, 0 offenses detected
Everything looks fine. 🍰

[bdunne]

So, do we know where the source of this issue is?

[kbrock]

this is great.
Is the rails way of coding (i.e. not using requires) the cause of the issue?
Will this issue change when we change the loader? (that happens in 5.2 or 6.0 right?)

[jrafanie]

this is great.
Is the rails way of coding (i.e. not using requires) the cause of the issue?

Technically, yes, because autoload uses const_get.

Will this issue change when we change the loader? (that happens in 5.2 or 6.0 right?)

I don't know. I will have to check that out. The problem is const_get . Rails autoload is just a victim of it doing the wrong thing:

irb(main):001:0> ManageIQ::Providers::BaseManager::EventCatcher
PostgreSQLAdapter#log_after_checkout, connection_pool: size: 5, connections: 1, in use: 1, waiting_in_queue: 0
=> ManageIQ::Providers::BaseManager::EventCatcher(id: integer, guid: string, status: string, started_on: datetime, stopped_on: datetime, last_heartbeat: datetime, pid: integer, queue_name: string, type: string, percent_memory: float, percent_cpu: float, cpu_time: float, os_priority: integer, memory_usage: decimal, memory_size: decimal, uri: string, miq_server_id: integer, sql_spid: integer, proportional_set_size: decimal, unique_set_size: decimal, href_slug: string, region_number: integer, region_description: string, friendly_name: string, uri_or_queue_name: string)
irb(main):002:0> Object.const_get("ManageIQ::Providers::Foreman::ProvisioningManager::EventCatcher")
=> ManageIQ::Providers::BaseManager::EventCatcher(id: integer, guid: string, status: string, started_on: datetime, stopped_on: datetime, last_heartbeat: datetime, pid: integer, queue_name: string, type: string, percent_memory: float, percent_cpu: float, cpu_time: float, os_priority: integer, memory_usage: decimal, memory_size: decimal, uri: string, miq_server_id: integer, sql_spid: integer, proportional_set_size: decimal, unique_set_size: decimal, href_slug: string, region_number: integer, region_description: string, friendly_name: string, uri_or_queue_name: string)

[djberg96]

Late to the party, but I thought safe_constantize was the currently preferred approach everywhere. Or doesn't it really matter here?

[jrafanie]

Late to the party, but I thought safe_constantize was the currently preferred approach everywhere. Or doesn't it really matter here?

even later to the party... yeah, I don't think it matters here if it's uses constantize or safe_constantize, the only different is the former raises NameError if the constant isn't found whereas the latter returns nil.

[Fryguy]

Right...in this case, the constant is always "found" (and thus no NameError nor nil); it just happens to not be the constant you asked for.

Example:

[1] pry(main)> String.const_get("String")
=> String

That being said, I think this is all fixed in newer Rails / Ruby

[kbrock]

There is a second parameter (that defaults to true):

String.const_get("String", false) # => NameError

I couldn`t find any way to say don't be so liberal but don't freak out