| Summary: | Message 'Cannot edit VM. Physical Memory Guaranteed cannot exceed Memory Size' is logged as INFO in automation.log | |||
|---|---|---|---|---|
| Product: | Red Hat CloudForms Management Engine | Reporter: | Reartes Guillermo <greartes> | |
| Component: | Automate | Assignee: | William Fitzgerald <wfitzger> | |
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Angelina Vasileva <anikifor> | |
| Severity: | medium | Docs Contact: | ||
| Priority: | medium | |||
| Version: | 5.6.0 | CC: | cpelland, dajohnso, gmccullo, greartes, istein, jhardy, mkanoor, obarenbo, simaishi, tfitzger | |
| Target Milestone: | GA | Keywords: | TestOnly, ZStream | |
| Target Release: | 5.9.0 | |||
| Hardware: | x86_64 | |||
| OS: | All | |||
| Whiteboard: | provision:support | |||
| Fixed In Version: | 5.9.0.1 | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | ||
| Clone Of: | ||||
| : | 1450214 1459243 (view as bug list) | Environment: | ||
| Last Closed: | 2018-03-06 15:16:04 UTC | Type: | Bug | |
| Regression: | --- | Mount Type: | --- | |
| Documentation: | --- | CRM: | ||
| Verified Versions: | Category: | --- | ||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | ||
| Cloudforms Team: | CFME Core | Target Upstream Version: | ||
| Bug Depends On: | ||||
| Bug Blocks: | 1450214, 1459243 | |||
Please verify if this is a duplicate of bug 1337703. You should see the same error coming from the RHEVM UI when trying to provision the template. Seems duplicate of bug 1376528, fixed in CFME-5.6.2.1 While the issue seems like 1337703 (which i solved modifying the template). I opened this BZ for the LOGLEVEL of the message. There is just too much INFO stuff in automation.log. It took me too long to read the original error, because i was using 'grep -v INFO' and some "INFO" messages are encapsulating "ERROR" There is an endless stream of INFO messages, and it bothers me that these can encapsulate ERROR messages. If i set the debug level to ERROR, would i se the INFO messages that are encapsulating ERROR messages inside? (In reply to Reartes Guillermo from comment #4) > While the issue seems like 1337703 (which i solved modifying the template). > > I opened this BZ for the LOGLEVEL of the message. > There is just too much INFO stuff in automation.log. > > It took me too long to read the original error, because i was using 'grep -v > INFO' and some "INFO" messages are encapsulating "ERROR" > > There is an endless stream of INFO messages, and it bothers me that these > can encapsulate ERROR messages. The failed scenario is fixed by Bug 1356468 and Bug 1356193 which cover problematic inputs that might lead to a vm reconfigure failure. AFAICT, the automation.log contains entries of the automation execution, i.e. method invocations, validation, driving the state machine and such, but it doesn't deal with the internals of the flow itself. The flow/providers output is logged to the evm.log which should contain the detailed reason for the failed execution. i.e. the 'reconfigure vm' output is reported to the evm.log, with the expected 'ERROR' severity. Therefore, from providers side, we cannot control the severity of automation log level. > > If i set the debug level to ERROR, would i se the INFO messages that are > encapsulating ERROR messages inside? Not in the automation.log. There isn't any indication of the logged message whether it represents an error or not. The evm.log should be the right place to look for the errors. Greg, Could you share your thoughts about the bug based on comment #5 and comment #6 ? Moti - Your analysis is correct at the use of the logs. The automate log line in question is just a method call during the state machine execution which is an internal call and is not aware that it is passing error data to the method. Having said that, with the change to process events through automate there is a lot of logging (model resolution) happening in automate and it may be a good time to review and see if we can reduce the amount of "noise" being generated without losing the important information captured in the automation.log today. I will take the ticket and have the automate team look into this more. Billy - Can you take a first pass at analyzing the automation.log to see where we can reduce the current noise. It would be good to work against user logs from a production environment to see events and other tasks running through the system. Then we can work with Madhu andTina to suggest/implement changes. New commit detected on ManageIQ/manageiq-content/master: https://github.com/ManageIQ/manageiq-content/commit/008b70dc6e86b81b4405480ba4b9e8cdad37ccc4 commit 008b70dc6e86b81b4405480ba4b9e8cdad37ccc4 Author: william fitzgerald <wfitzger> AuthorDate: Mon Apr 24 19:12:59 2017 -0400 Commit: william fitzgerald <wfitzger> CommitDate: Mon Apr 24 19:12:59 2017 -0400 Change errors in log to error type. Some error messages in log were type info. https://bugzilla.redhat.com/show_bug.cgi?id=1383732 .../StateMachines/Provision.class/__methods__/check_provisioned.rb | 2 +- .../StateMachines/Provision.class/__methods__/check_provisioned.rb | 2 +- .../System/StateMachine/Deployment.class/__methods__/provision.rb | 2 +- .../Generic/StateMachines/GenericLifecycle.class/__methods__/execute.rb | 2 +- .../StateMachines/GenericLifecycle.class/__methods__/preprocess.rb | 2 +- 5 files changed, 5 insertions(+), 5 deletions(-) New commit detected on ManageIQ/manageiq-content/master: https://github.com/ManageIQ/manageiq-content/commit/512b4d6bd94ffd476f8eaa40b3efbd45553d9252 commit 512b4d6bd94ffd476f8eaa40b3efbd45553d9252 Author: william fitzgerald <wfitzger> AuthorDate: Wed Apr 26 12:25:32 2017 -0400 Commit: william fitzgerald <wfitzger> CommitDate: Wed Apr 26 12:25:32 2017 -0400 Change exceeds message in log to warn type. https://bugzilla.redhat.com/show_bug.cgi?id=1383732 @miq-bot add_label bug, fine/yes .../__methods__/validate_request.rb | 6 +++--- .../Methods.class/__methods__/cluster_workload_management.rb | 4 ++-- .../__methods__/validate_request.rb | 8 ++++---- .../QuotaMethods.class/__methods__/validate_quota.rb | 4 ++-- 4 files changed, 11 insertions(+), 11 deletions(-) New commit detected on ManageIQ/manageiq-content/master: https://github.com/ManageIQ/manageiq-content/commit/20fd6fec7e6683677b624866770c6c82dd85c3b3 commit 20fd6fec7e6683677b624866770c6c82dd85c3b3 Author: william fitzgerald <wfitzger> AuthorDate: Wed Apr 26 15:24:25 2017 -0400 Commit: william fitzgerald <wfitzger> CommitDate: Wed Apr 26 15:24:25 2017 -0400 Add error log message for provision error. Log message will match notification message in all 7 methods. https://bugzilla.redhat.com/show_bug.cgi?id=1383732 @miq-bot add_label fine/yes, euwe/yes .../Provision.class/__methods__/update_serviceprovision_status.rb | 1 + .../Provision.class/__methods__/update_serviceprovision_status.rb | 1 + .../VMProvision_VM.class/__methods__/update_provision_status.rb | 1 + .../Provision.class/__methods__/update_serviceprovision_status.rb | 1 + .../VMProvision_Template.class/__methods__/update_provision_status.rb | 1 + .../VMProvision_VM.class/__methods__/update_provision_status.rb | 1 + .../__methods__/update_serviceprovision_status.rb | 1 + 7 files changed, 7 insertions(+) Verified on CFME-5.9.0.20/RHV-4.1.8.2: Steps: Had a template with 2G physical memory, and 2G Guaranteed memory. Provisioned VM from this template on CFME side. Set physical memory to 1G. The provision dialog failed to be submitted. It failed on validation: In CFME UI: 'Hardware/Memory (MB)' Reservation is larger than VM Memory In evm.log: [----] E, [2018-02-13T10:59:29.040147 #6780:44f9e18] ERROR -- : MIQ(vm_infra_controller-pre_prov_continue): 'Hardware/Memory (MB)' Reservation is larger than VM Memory This is expected as the bug report is on having such error appear as INFO in evm.log, instead of error. |
Description of problem: I believe that the message 'Cannot edit VM. Physical Memory Guaranteed cannot exceed Memory Size' should be ERROR or WARN. There is some issue in the provisioning process and it is being logged simply as INFO. Version-Release number of selected component (if applicable): 5.6.1 How reproducible: always Steps to Reproduce: 1. create a catalog item, which uses a template. 2. some other condition or issue 3. provisioning fails (vm is created but not powered on) Actual results: the error is lost in the waterfall of INFO messages Expected results: log the error as ERROR or WARN at least. Additional info: [----] I, [2016-10-11T11:33:04.233649 #3083:d91994] INFO -- : Q-task_id([service_template_provision_task_1000000000000031]) Invoking [inline] method [/ManageIQ/Service/Provisioning/StateMachines/ServiceProvision_Template/update_serviceprovision_status] with inputs [{"status"=>"[Ovirt::Error]: [Cannot edit VM. Physical Memory Guaranteed cannot exceed Memory Size.]"}]