Created attachment 1490583 [details] logs Description of problem: While going through CFME evm.log, I encountered some inconsistency between what is reported in the log and what can be found in Configuration -> Access control -> Tenant: After trying to create a VM provision request, this failed with the following message in log: [----] D, [2018-10-04T08:34:20.101779 #12091:e52b30] DEBUG -- : Value "Request exceeds maximum allowed for the following: (cpu - Used: 0 plus requested: 4 exceeds quota: 2) (memory - Used: 0 Bytes plus requested: 2 GB exceeds quota: 1 GB) (storage - Used: 0 Bytes plus requested: 14 GB exceeds quota: 2 GB) " After going to Tenant and inspecting resources in use, I found the following values: Name Total Quota In Use Allocated Available Allocated Virtual CPUs Not defined 6 Count 0 Count Not applicable Allocated Memory in GB Not defined 12.0 GB 0.0 GB Not applicable Allocated Storage in GB Not defined 30.0 GB 0.0 GB Not applicable Allocated Number of Virtual Machines Not defined 3 Count 0 Count Not applicable Allocated Number of Templates Not defined 4 Count 0 Count Not applicable Number of CPUs in use reported on the tenant page is correct, but it is weird that the message in log says: cpu - Used: 0 plus requested: 4 exceeds quota: 2. It is possible, that the message in log takes the data from some other source than the Tenant, but from the user's perspective, the log doesn't say where the information about quota was taken from. This is in my opinion a problem, considering that this is a DEBUG level log message. Additionally, I noticed thare is the following ERROR in the log: [----] E, [2018-10-04T08:33:33.706347 #24813:bbf10c] ERROR -- : Q-task_id([miq_provision_request_28]) MIQ(MiqAeEngine.deliver) Error delivering {:event_type=>"request_starting", "EventStream::event_stream"=>463, :event_stream_id=>463} for object [MiqProvisionRequest.28] with state [] to Automate: [----] I, [2018-10-04T08:33:33.706633 #24813:bbf10c] INFO -- : Q-task_id([miq_provision_request_28]) MIQ(MiqProvisionRequest#call_automate_event) Raised event [request_starting] to Automate [----] W, [2018-10-04T08:33:33.706802 #24813:bbf10c] WARN -- : Q-task_id([miq_provision_request_28]) MIQ(MiqProvisionRequest#automate_event_failed?) Aborting because Automate returned ae_result=<error> for event <request_starting> Even if a request is denied, I believe it should not result in ERROR in logs. Version-Release number of selected component (if applicable): Version 5.9.5.0.20180927190514_e161d8f How reproducible: 100% Steps to Reproduce: 1. Provision a VM with quotas that don't allow the provisioning to succeed 2. 3. Actual results: above Expected results: Log messages should give a better idea about how quota limits are calculated. Denial of provision request should not result in ERROR in log. Additional info:
Radim, Can you upload the automation.log? Thanks Billy
Created attachment 1491523 [details] automation.log Regards, Radim.
Hello Ganesh, In the description I mention 2 issues that come from a denied provision request. The first one suggests better description of the denial reason, but this came from my lack of knowledge, because I found later that detailed description can be found in automation.log. So you can ignore this :). The second issue points to an error logged in evm.log upon a request denial, example: [----] E, [2018-10-09T03:19:03.830122 #12891:12ff110] ERROR -- : Q-task_id([miq_provision_request_1]) MIQ(MiqAeEngine.deliver) Error delivering .... This error message is logged when a request is denied because of quota limits and can be found in the logs2 archive. In my opinion, it is not really an error kind of situation from the user perspective and should not be logged as ERROR. Regards, Radim