search

ManageIQ / manageiq-providers-oracle_cloud

ManageIQ Provider for Oracle Cloud
Apache License 2.0
7 stars 17 forks source link

TooManyRequests errors with OCI #100

Open prasadanvekar opened 6 months ago

prasadanvekar commented 6 months ago

Getting the below error post adding the Oracle cloud. Error - 10 Minutes Ago { 'message': 'Too many requests for the tenant', 'status': 429, 'code': 'TooManyRequests', 'opc-request-id':

Step 1: Add the oracle cloud provider for one region Step 2: Add another oracle cloud provider for another region Step 3: Error is display after sometime. This might take sometime to appear.

- Version: Pretrosian: latest /Oparin : latest - Environment : - Manageiq: Oracle_cloud - @miq-bot
Fryguy commented 6 months ago

@agrare Can you please take a look?

agrare commented 6 months ago

@prasadanvekar we need to know what API calls were causing the too many requests error, can you find in the logs what the refresh worker was doing prior to this error? You can enable api client debug logging by going to advanced settings and setting level_oracle to debug

prasadanvekar commented 6 months ago

@agrare Please find the logs below. I will enable the api client debug logs and share it shortly

{"@timestamp":"2024-03-06T04:57:39.240981","hostname":"db25335dca64","pid":660,"tid":"94d4","service":"evm","level":"info","message":"EMS: [Cloud18-Vinhedo], id: [26] Saving EMS Inventory..."}
{"@timestamp":"2024-03-06T04:57:39.614604","hostname":"db25335dca64","pid":660,"tid":"94d4","service":"production","level":"warning","message":"Scoped order is ignored, it's forced to be batch order."}
{"@timestamp":"2024-03-06T04:57:39.623551","hostname":"db25335dca64","pid":660,"tid":"94d4","service":"evm","level":"info","message":"EMS: [Cloud18-Vinhedo], id: [26] Saving EMS Inventory...Complete"}
{"@timestamp":"2024-03-06T04:57:39.623751","hostname":"db25335dca64","pid":660,"tid":"94d4","service":"evm","level":"info","message":"MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh_targets_for_ems) EMS: [Cloud18-Vinhedo], id: [26] Refreshing target ManageIQ::Providers::OracleCloud::CloudManager [Cloud18-Vinhedo] id [26]...Complete"}
{"@timestamp":"2024-03-06T04:57:39.623850","hostname":"db25335dca64","pid":660,"tid":"94d4","service":"evm","level":"info","message":"MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh) EMS: [Cloud18-Vinhedo], id: [26] Refreshing targets for EMS...Complete - Timings {:collect_inventory_for_targets=>0.051198720932006836, :parse_targeted_inventory=>63.27961182594299, :save_inventory=>0.3933141231536865, :publish_inventory=>2.5033950805664062e-05, :ems_refresh=>63.72442889213562}"}{"@timestamp":"2024-03-06T04:57:39.637005","hostname":"db25335dca64","pid":660,"tid":"94d4","service":"evm","level":"info","message":"MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh) Refreshing all targets...Complete"}
{"@timestamp":"2024-03-06T04:57:39.637184","hostname":"db25335dca64","pid":660,"tid":"94d4","service":"evm","level":"info","message":"MIQ(MiqQueue#delivered) Message id: [844223], State: [ok], Delivered in [63.739651834] seconds"}
{"@timestamp":"2024-03-06T04:57:40.094600","hostname":"db25335dca64","pid":600,"tid":"94d4","service":"evm","level":"info","message":"MIQ(MiqQueue.put) Message id: [844238], Zone: [], Role: [], Server: [], MiqTask id: [], Handler id: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqQueue.check_for_timeout], Timeout: [600], Priority: [50], State: [ready], Deliver On: [], Data: [], Args: []"}# => 200 OK | application/json 45 bytes, 2.13s
{"@timestamp":"2024-03-06T04:57:41.712237","hostname":"db25335dca64","pid":592,"tid":"94d4","service":"evm","level":"err","message":"MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh) EMS: [cloud18-SaoPaulo], id: [16] Refresh failed"}
{"@timestamp":"2024-03-06T04:57:41.712431","hostname":"db25335dca64","pid":592,"tid":"94d4","service":"evm","level":"err","message":"[OCI::Errors::ServiceError]: Too many requests for the user  Method:[block (2 levels) in <class:LogProxy>]"}
{"@timestamp":"2024-03-06T04:57:41.712509","hostname":"db25335dca64","pid":592,"tid":"94d4","service":"evm","level":"err","message":"/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/api_client.rb:478:in `handle_non_success_response'\n/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/api_client.rb:390:in `call_api_inner'\n/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/api_client.rb:143:in `block in call_api'\n/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/api_client.rb:146:in `call_api'\n/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/core/virtual_network_client.rb:13156:in `block in list_vcns'\n/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/retry/retry.rb:24:in `make_retrying_call'\n/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/core/virtual_network_client.rb:13155:in `list_vcns'\n/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:76:in `block in vcns'\n/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:75:in `each'\n/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:75:in `flat_map'\n/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:75:in `vcns'\n/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/parser.rb:194:in `virtual_cloud_networks'\n/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/parser.rb:17:in `parse'\n/var/www/miq/vmdb/app/models/manageiq/providers/inventory.rb:42:in `block in parse'\n/var/www/miq/vmdb/app/models/manageiq/providers/inventory.rb:39:in `each'\n/var/www/miq/vmdb/app/models/manageiq/providers/inventory.rb:39:in `parse'\n/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:131:in `parse_targeted_inventory'\n/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:96:in `block in refresh_targets_for_ems'\n/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'\n/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'\n/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:95:in `refresh_targets_for_ems'\n/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:41:in `block (2 levels) in refresh'\n/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'\n/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'\n/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:41:in `block in refresh'\n/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:31:in `each'\n/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:31:in `refresh'\n/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:11:in `refresh'\n/var/www/miq/vmdb/app/models/ems_refresh.rb:74:in `block in refresh'\n/var/www/miq/vmdb/app/models/ems_refresh.rb:73:in `each'\n/var/www/miq/vmdb/app/models/ems_refresh.rb:73:in `refresh'\n/var/www/miq/vmdb/app/models/miq_queue.rb:517:in `block in dispatch_method'\n/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:189:in `block in timeout'\n/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:36:in `block in catch'\n/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:36:in `catch'\n/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:36:in `catch'\n/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:198:in `timeout'\n/var/www/miq/vmdb/app/models/miq_queue.rb:515:in `dispatch_method'\n/var/www/miq/vmdb/app/models/miq_queue.rb:484:in `block in deliver'\n/var/www/miq/vmdb/app/models/user.rb:382:in `with_user_group'\n/var/www/miq/vmdb/app/models/miq_queue.rb:484:in `deliver'\n/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:98:in `deliver_queue_message'\n/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:124:in `deliver_message'\n/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `block in do_work'\n/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:142:in `loop'\n/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:142:in `do_work'\n/var/www/miq/vmdb/app/models/miq_worker/runner.rb:295:in `block in do_work_loop'\n/var/www/miq/vmdb/app/models/miq_worker/runner.rb:292:in `loop'\n/var/www/miq/vmdb/app/models/miq_worker/runner.rb:292:in `do_work_loop'\n/var/www/miq/vmdb/app/models/miq_worker/runner.rb:142:in `run'\n/var/www/miq/vmdb/app/models/miq_worker/runner.rb:100:in `start_rails_worker'\n/var/www/miq/vmdb/app/models/miq_worker/runner.rb:95:in `start'\n/var/www/miq/vmdb/lib/workers/bin/run_single_worker.rb:128:in `<main>'"}
{"@timestamp":"2024-03-06T04:57:41.712594","hostname":"db25335dca64","pid":592,"tid":"94d4","service":"evm","level":"err","message":"MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh) EMS: [cloud18-SaoPaulo], id: [16] Unable to perform refresh for the following targets:"}
{"@timestamp":"2024-03-06T04:57:41.712674","hostname":"db25335dca64","pid":592,"tid":"94d4","service":"evm","level":"err","message":"MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh)  --- ManageIQ::Providers::OracleCloud::CloudManager [cloud18-SaoPaulo] id [16]"}
{"@timestamp":"2024-03-06T04:57:41.725801","hostname":"db25335dca64","pid":592,"tid":"94d4","service":"evm","level":"info","message":"MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh) Refreshing all targets...Complete"}
{"@timestamp":"2024-03-06T04:57:41.726047","hostname":"db25335dca64","pid":592,"tid":"94d4","service":"evm","level":"err","message":"MIQ(MiqQueue#deliver) Message id: [844224], Error: [{ 'message': 'Too many requests for the user', '**status': 429,** 'code': 'TooManyRequests', 'opc-request-id': 'E9E71D24E15845EB81622205E4185921/910186F4A582A7841B6B6E3C55E10836/D7E9E1CB660F7005A1E012CB2D5D25BA' }]"}
{"@timestamp":"2024-03-06T04:57:41.726200","hostname":"db25335dca64","pid":592,"tid":"94d4","service":"evm","level":"err","message":"[ManageIQ::Providers::BaseManager::Refresher::PartialRefreshError]: { 'message': 'Too many requests for the user', '**status': 429,** 'code': 'TooManyRequests', 'opc-request-id': 'E9E71D24E15845EB81622205E4185921/910186F4A582A7841B6B6E3C55E10836/D7E9E1CB660F7005A1E012CB2D5D25BA' }  Method:[block (2 levels) in <class:LogProxy>]"}
Fryguy commented 6 months ago

@agrare Loggified:

[----] I, [2024-03-06T04:57:39.240981#660:94d4]  INFO -- evm: EMS: [Cloud18-Vinhedo], id: [26] Saving EMS Inventory...
[----] W, [2024-03-06T04:57:39.614604#660:94d4] WARNI -- production: Scoped order is ignored, it's forced to be batch order.
[----] I, [2024-03-06T04:57:39.623551#660:94d4]  INFO -- evm: EMS: [Cloud18-Vinhedo], id: [26] Saving EMS Inventory...Complete
[----] I, [2024-03-06T04:57:39.623751#660:94d4]  INFO -- evm: MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh_targets_for_ems) EMS: [Cloud18-Vinhedo], id: [26] Refreshing target ManageIQ::Providers::OracleCloud::CloudManager [Cloud18-Vinhedo] id [26]...Complete
[----] I, [2024-03-06T04:57:39.637184#660:94d4]  INFO -- evm: MIQ(MiqQueue#delivered) Message id: [844223], State: [ok], Delivered in [63.739651834] seconds
[----] E, [2024-03-06T04:57:41.712237#592:94d4]   ERR -- evm: MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh) EMS: [cloud18-SaoPaulo], id: [16] Refresh failed
[----] E, [2024-03-06T04:57:41.712431#592:94d4]   ERR -- evm: [OCI::Errors::ServiceError]: Too many requests for the user  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2024-03-06T04:57:41.712509#592:94d4]   ERR -- evm: /opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/api_client.rb:478:in `handle_non_success_response'
/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/api_client.rb:390:in `call_api_inner'
/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/api_client.rb:143:in `block in call_api'
/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/api_client.rb:146:in `call_api'
/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/core/virtual_network_client.rb:13156:in `block in list_vcns'
/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/retry/retry.rb:24:in `make_retrying_call'
/opt/manageiq/manageiq-gemset/gems/oci-2.18.0/lib/oci/core/virtual_network_client.rb:13155:in `list_vcns'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:76:in `block in vcns'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:75:in `each'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:75:in `flat_map'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:75:in `vcns'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/parser.rb:194:in `virtual_cloud_networks'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-2036978e352a/app/models/manageiq/providers/oracle_cloud/inventory/parser.rb:17:in `parse'
/var/www/miq/vmdb/app/models/manageiq/providers/inventory.rb:42:in `block in parse'
/var/www/miq/vmdb/app/models/manageiq/providers/inventory.rb:39:in `each'
/var/www/miq/vmdb/app/models/manageiq/providers/inventory.rb:39:in `parse'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:131:in `parse_targeted_inventory'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:96:in `block in refresh_targets_for_ems'
/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/manageiq/providers/base_manager/refresher.rb:95:in `refresh_targets_for_ems'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:41:in `block (2 levels) in refresh'
/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/app/models/manageiq/providers/base_manager/refresher.rb:41:in `block in refresh'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:31:in `each'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:31:in `refresh'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/refresher.rb:11:in `refresh'
/var/www/miq/vmdb/app/models/ems_refresh.rb:74:in `block in refresh'
/var/www/miq/vmdb/app/models/ems_refresh.rb:73:in `each'
/var/www/miq/vmdb/app/models/ems_refresh.rb:73:in `refresh'
/var/www/miq/vmdb/app/models/miq_queue.rb:517:in `block in dispatch_method'
/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:189:in `block in timeout'
/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:36:in `block in catch'
/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:36:in `catch'
/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:36:in `catch'
/opt/manageiq/manageiq-gemset/gems/timeout-0.3.2/lib/timeout.rb:198:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:515:in `dispatch_method'
/var/www/miq/vmdb/app/models/miq_queue.rb:484:in `block in deliver'
/var/www/miq/vmdb/app/models/user.rb:382:in `with_user_group'
/var/www/miq/vmdb/app/models/miq_queue.rb:484:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:98:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:124:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:142:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:142:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:295:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:292:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:292:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:142:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:100:in `start_rails_worker'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:95:in `start'
/var/www/miq/vmdb/lib/workers/bin/run_single_worker.rb:128:in `<main>'
[----] E, [2024-03-06T04:57:41.712594#592:94d4]   ERR -- evm: MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh) EMS: [cloud18-SaoPaulo], id: [16] Unable to perform refresh for the following targets:
[----] E, [2024-03-06T04:57:41.712674#592:94d4]   ERR -- evm: MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh)  --- ManageIQ::Providers::OracleCloud::CloudManager [cloud18-SaoPaulo] id [16]
[----] I, [2024-03-06T04:57:41.725801#592:94d4]  INFO -- evm: MIQ(ManageIQ::Providers::OracleCloud::CloudManager::Refresher#refresh) Refreshing all targets...Complete
[----] E, [2024-03-06T04:57:41.726047#592:94d4]   ERR -- evm: MIQ(MiqQueue#deliver) Message id: [844224], Error: [{ 'message': 'Too many requests for the user', '**status': 429,** 'code': 'TooManyRequests', 'opc-request-id': 'E9E71D24E15845EB81622205E4185921/910186F4A582A7841B6B6E3C55E10836/D7E9E1CB660F7005A1E012CB2D5D25BA' }]
[----] E, [2024-03-06T04:57:41.726200#592:94d4]   ERR -- evm: [ManageIQ::Providers::BaseManager::Refresher::PartialRefreshError]: { 'message': 'Too many requests for the user', '**status': 429,** 'code': 'TooManyRequests', 'opc-request-id': 'E9E71D24E15845EB81622205E4185921/910186F4A582A7841B6B6E3C55E10836/D7E9E1CB660F7005A1E012CB2D5D25BA' }  Method:[block (2 levels) in <class:LogProxy>]
miq-bot commented 3 months ago

This issue has been automatically marked as stale because it has not been updated for at least 3 months.

If you can still reproduce this issue on the current release or on master, please reply with all of the information you have about it in order to keep the issue open.

miq-bot commented 1 week ago

This issue has been automatically marked as stale because it has not been updated for at least 3 months.

If you can still reproduce this issue on the current release or on master, please reply with all of the information you have about it in order to keep the issue open.