Oracle Cloud provider shows Forbidden after successful verification

[imphocused]

Hello,

After creating a new API keypair (thanks!) I'm able to successfully verify the connection, but after saving, the provider fails to authenticate:

Last Refresh Status

Error - Less Than A Minute Ago { 'message': 'Forbidden', 'status': 403, 'code': 'Forbidden', 'opc-request-id': '2086A74374A247729EA710BFD1BD8B99/61F...

The same credentials work fine in the oci-cli. Unfortunately there is little/no reference to this error in the docker console/log output

[agrare]

Hey @imphocused can you post the evm.log for the refresh that has this error? Everything from Refreshing all targets... to Refreshing all targets...Complete

[imphocused]

Attached (with ocid changed)

evm.log

[agrare]

Perfect thanks @imphocused here is the full backtrace:

[----] E, [2022-05-12T03:38:19.957186 #8846:2b2420c0794c] ERROR -- evm: [OCI::Errors::ServiceError]: Forbidden  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2022-05-12T03:38:19.957556 #8846:2b2420c0794c] ERROR -- evm: /opt/manageiq/manageiq-gemset/gems/oci-2.16.0/lib/oci/api_client.rb:478:in `handle_non_success_response'
/opt/manageiq/manageiq-gemset/gems/oci-2.16.0/lib/oci/api_client.rb:390:in `call_api_inner'
/opt/manageiq/manageiq-gemset/gems/oci-2.16.0/lib/oci/api_client.rb:143:in `block in call_api'
/opt/manageiq/manageiq-gemset/gems/oci-2.16.0/lib/oci/api_client.rb:146:in `call_api'
/opt/manageiq/manageiq-gemset/gems/oci-2.16.0/lib/oci/database/database_client.rb:9860:in `block in list_autonomous_databases'
/opt/manageiq/manageiq-gemset/gems/oci-2.16.0/lib/oci/retry/retry.rb:24:in `make_retrying_call'
/opt/manageiq/manageiq-gemset/gems/oci-2.16.0/lib/oci/database/database_client.rb:9859:in `list_autonomous_databases'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-733aa46b3353/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:58:in `block in oracle_databases'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-733aa46b3353/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:57:in `each'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-733aa46b3353/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:57:in `flat_map'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-733aa46b3353/app/models/manageiq/providers/oracle_cloud/inventory/collector.rb:57:in `oracle_databases'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-733aa46b3353/app/models/manageiq/providers/oracle_cloud/inventory/parser.rb:56:in `databases'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-oracle_cloud-733aa46b3353/app/models/manageiq/providers/oracle_cloud/inventory/parser.rb:11:in `parse'

It makes it through most of the collections but fails on collecting databases, it appears that the API Key you've provided does not have sufficient permissions to list oracle and mysql type databases.

[imphocused]

Thank you for taking a look, I appreciate the feedback. I've reached out to Oracle, as their support says they can give more detail on the error provided in the 'opc-request-id' response.

{ 'message': 'Forbidden', 'status': 403, 'code': 'Forbidden', 'opc-request-id': '2EECC402E8A940B88A72D4FC90919646/CD022E0222526F223FBAF9D9EE20E448/B158AF7DB811D744193DCBF2AE3F0AA6' }

My tenancy (root tenancy) only has my sole account which is an Administrator. The attached logs show these commands working successfully from the 'oci' command.

oci_output_2022-05-12-1256.log

• Is there a way to debug and get the actual urls/calls being made?
• Are there any 'oci' commands I can/should try to compare results?

ManageIQ Morphy Version morphy-1.20220210224352_1e24154

[agrare]

Thanks @imphocused we get fetch both types of databases, MySQL and Oracle Autonomous Databases. Your OCI command only tried to list mysql ones. I don't have the oci command locally but try listing autonomous databases.

[agrare]

Is there a way to debug and get the actual urls/calls being made?

@imphocused That is a great question, we should have a log/oracle.log with the API calls being made to cloud.oracle.com. I will work on adding this now.

[imphocused]

The log I provided shows the 'autonomous-databases' as the first command tried, and mysql as the second. Both went through successfully. After a few days of back and forth with Oracle support, the best they could narrow it down to was:

(A) 403 NotAllowedThis operation must be directed at the home region. (B) 403 NotAuthorizedYou do not have authorization to update one or more of the fields included in this request. (C) 403 SignUpRequiredThis operation requires opt-in before it may be called. have you tried this in you home region? Additionally, please make sure that you have authorization to perform the task. And lastly,Have you seen the option somewhere in the process, for opt-in before attempting this task

[agrare]

Okay thanks @imphocused I think the best course of action would be to grab the latest devel appliance image that includes https://github.com/ManageIQ/manageiq-providers-oracle_cloud/pull/62, set the log level for the oracle logger to debug, and re-run the refresh to see the exact API call being made.

[imphocused]

Thank you for the updated version. I've enabled debug and this is the section where the failure appears (/var/www/miq/vmdb/log/oracle.log)

[----] D, [2022-05-25T19:03:38.420248 #7860:9330] DEBUG -- oracle: Calling operation BlockstorageClient#list_boot_volumes.
[----] D, [2022-05-25T19:03:38.421053 #7860:9330] DEBUG -- oracle: HTTP request body param ~BEGIN~

~END~

[----] D, [2022-05-25T19:03:38.692052 #7860:9330] DEBUG -- oracle: HTTP response body ~BEGIN~
[]
~END~

[----] D, [2022-05-25T19:03:38.692708 #7860:9330] DEBUG -- oracle: API Response Received:
Data: []
Status code: 200
Headers: #<Net::HTTPOK:0x00005621507fc750>
[----] I, [2022-05-25T19:03:38.698050 #7860:9330]  INFO -- oracle: DatabaseClient endpoint set to 'https://database.us-ashburn-1.oraclecloud.com/20160918 from region us-ashburn-1'.
[----] I, [2022-05-25T19:03:38.698442 #7860:9330]  INFO -- oracle: DatabaseClient endpoint set to 'https://database.us-ashburn-1.oraclecloud.com/20160918'.
[----] D, [2022-05-25T19:03:38.698815 #7860:9330] DEBUG -- oracle: Calling operation DatabaseClient#list_autonomous_databases.
[----] D, [2022-05-25T19:03:38.699469 #7860:9330] DEBUG -- oracle: HTTP request body param ~BEGIN~

~END~

[----] D, [2022-05-25T19:03:39.411719 #7860:9330] DEBUG -- oracle: HTTP response body ~BEGIN~
[]
~END~

[----] D, [2022-05-25T19:03:39.412167 #7860:9330] DEBUG -- oracle: API Response Received:
Data: []
Status code: 200
Headers: #<Net::HTTPOK:0x0000562150fedfe0>
[----] D, [2022-05-25T19:03:39.412550 #7860:9330] DEBUG -- oracle: Calling operation DatabaseClient#list_autonomous_databases.
[----] D, [2022-05-25T19:03:39.413187 #7860:9330] DEBUG -- oracle: HTTP request body param ~BEGIN~

~END~

[----] D, [2022-05-25T19:03:39.820541 #7860:9330] DEBUG -- oracle: HTTP response body ~BEGIN~
{
  "code" : "Forbidden",
  "message" : "Forbidden"
}
~END~

[----] D, [2022-05-25T19:03:54.809818 #7857:f000] DEBUG -- oracle: Calling operation StreamClient#get_messages.
[----] D, [2022-05-25T19:03:54.810685 #7857:f000] DEBUG -- oracle: HTTP request body param ~BEGIN~

~END~

[----] D, [2022-05-25T19:03:55.119606 #7857:f000] DEBUG -- oracle: HTTP response body ~BEGIN~
[]
~END~

[----] D, [2022-05-25T19:03:55.120050 #7857:f000] DEBUG -- oracle: API Response Received:
Data: []
Status code: 200
Headers: #<Net::HTTPOK:0x00005589e3419200>
[----] D, [2022-05-25T19:04:15.120849 #7857:f000] DEBUG -- oracle: Calling operation StreamClient#get_messages.
[----] D, [2022-05-25T19:04:15.121992 #7857:f000] DEBUG -- oracle: HTTP request body param ~BEGIN~

~END~

[----] D, [2022-05-25T19:04:15.348264 #7857:f000] DEBUG -- oracle: HTTP response body ~BEGIN~
[]
~END~

This same command from the oci cli utility doesn't return any errors:

% oci -d db autonomous-database list --compartment-id <ocid-tenancy-id>
DEBUG:oci_cli.cli_metrics: 2022-05-25 23:18:11.596826: Metrics is not enabled
macOS-12.3.1-arm64-arm-64bit
System name: Darwin
System release : 21.4.0
System version: Darwin Kernel Version 21.4.0: Fri Mar 18 00:46:32 PDT 2022; root:xnu-8020.101.4~15/RELEASE_ARM64_T6000

env OCI_PYTHON_SDK_NO_SERVICE_IMPORTS is set
DEBUG:oci_cli.cli_util:Config File: dict_keys(['log_requests', 'additional_user_agent', 'pass_phrase', 'user', 'fingerprint', 'key_file', 'tenancy', 'region'])
DEBUG:oci_cli.cli_util:region: Environment Variable or Parameter
DEBUG:oci.base_client.4393667072:Endpoint: https://database.us-ashburn-1.oraclecloud.com/20160918
INFO:oci.base_client.4393667072: 2022-05-25 23:18:11.627570: Request: GET https://database.us-ashburn-1.oraclecloud.com/20160918/autonomousDatabases
Not using Expect header...
send: b'GET /20160918/autonomousDatabases?compartmentId=<ocid-tenancy-id> HTTP/1.1\r\nuser-agent: Oracle-PythonSDK/2.66.0 (python 3.10.4; arm64-Darwin) Oracle-PythonCLI/3.8.1\r\naccept-encoding: gzip, deflate\r\naccept: application/json\r\nconnection: keep-alive\r\ncontent-type: application/json\r\nopc-request-id: CFB257D922BD468C9F865F9E37057C5F\r\nopc-client-retries: true\r\nopc-client-info: Oracle-PythonSDK/2.66.0\r\ndate: Wed, 25 May 2022 23:18:11 GMT\r\nhost: database.us-ashburn-1.oraclecloud.com\r\nauthorization: Signature algorithm="rsa-sha256",headers="date (request-target) host",keyId="<ocid-tenancy-id>/<ocid-user-id>/eb:b9:8d:d5:02:00:00:00:00:00:5e:1d:ed:74",signature="H7pRZLz6xXZwfFxo3G3j1AJONkLjVfAhcwpL0xjtGTYBqt7eaau9CHAMMKfWDoIbcMARvsOjSdT+AcmZyBLORvrBgMxcPYUK6Ih/ol7eFsme2JTKs5+C88NbtDmkT2zx/jLv2m39N.......gIWiFcyH0J/W7HFvJAjHqk7Gfg4JZ5r1bCwSP/l3/AfIShTXzZ3rpWclhElwOfQKPMJE120avNhGaZVtO+60Vi+LHDDKfNbr/fs5szRPzKxqEP1nAaTtU5eTwI2bKWjMD5llw==",version="1"\r\n\r\n'
reply: 'HTTP/1.1 200 OK\r\n'
header: Date: Wed, 25 May 2022 23:18:11 GMT
header: opc-request-id: CFB257D922BD468C9F865F9E37057C5F/F53A4824A894538E366F055B0BE23D3D/8459C7A16EBFBC7837D56F96B86C2086
header: Content-Type: application/json
header: Vary: Accept-Encoding
header: X-Content-Type-Options: nosniff
header: Content-Length: 2
DEBUG:oci.base_client.4393667072: 2022-05-25 23:18:12.931709: time elapsed for request CFB257D922BD468C9F865F9E37057C5F: 1.3040682920254767
DEBUG:oci.base_client.4393667072: 2022-05-25 23:18:12.932097: time elapsed in response: 0:00:01.297733
DEBUG:oci.base_client.4393667072: 2022-05-25 23:18:12.932138: Response status: 200
DEBUG:oci.base_client.4393667072: 2022-05-25 23:18:12.932642: python SDK time elapsed for deserializing: 0.0003414170350879431
DEBUG:oci.base_client.4393667072: 2022-05-25 23:18:12.932702: Response returned
DEBUG:oci.base_client.4393667072:time elapsed for request: 1.3051819999236614

[miq-bot]

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.

Thank you for all your contributions! More information about the ManageIQ triage process can be found in the triage process documentation.

[miq-bot]

This issue has been automatically closed because it has not been updated for at least 3 months.

Feel free to reopen this issue if this issue is still valid.

Thank you for all your contributions! More information about the ManageIQ triage process can be found in the triage process documentation.