Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1519953 - Logging of the server process memory/cpu (MiqServer.log_status) is incorrect
Summary: Logging of the server process memory/cpu (MiqServer.log_status) is incorrect
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Appliance
Version: 5.7.0
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: GA
: 5.10.0
Assignee: Joe Rafaniello
QA Contact: Dmitry Misharov
URL:
Whiteboard:
Depends On:
Blocks: 1519986 1519987 1519988
TreeView+ depends on / blocked
 
Reported: 2017-12-01 18:56 UTC by Joe Rafaniello
Modified: 2018-06-21 20:47 UTC (History)
6 users (show)

Fixed In Version: 5.10.0.0
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1519986 1519987 1519988 (view as bug list)
Environment:
Last Closed: 2018-06-21 20:47:44 UTC
Category: ---
Cloudforms Team: ---


Attachments (Terms of Use)

Description Joe Rafaniello 2017-12-01 18:56:06 UTC
Description of problem: According to the MiqServer.log_status log lines, the same server process cpu time and memory jumps up and down.  It is actually logging the process information for the worker running the task, not the actual server process itself.


Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1. Run an appliance for more than 10 minutes
2. Look at the MiqServer.log_status log lines every 5 minutes
3. CPU Time is clearly wrong as this value should never go down, but it does in our logs with several workers. 

Actual results:

CPU time goes from 47,331,089 to 15,970,987 five minutes later and back to 47,336,822 minutes later.  Note, the memory is going up and down.

[----] I, [2017-10-27T03:38:05.397959 #1906:9d3140]  INFO -- : Q-task_id([log_status]) MIQ(MiqServer.log_status) [EVM Server (2485)] Process info: Memory Usage [1216200704], Memory Size [2563485696], Proportional Set Size: [1108330000], Memory % [7.3], CPU Time [10606001.0], CPU % [1.26], Priority [30]
[----] I, [2017-10-27T03:43:08.426006 #60405:9d3140]  INFO -- : Q-task_id([log_status]) MIQ(MiqServer.log_status) [EVM Server (2485)] Process info: Memory Usage [652361728], Memory Size [1021591552], Proportional Set Size: [580377000], Memory % [3.92], CPU Time [47331089.0], CPU % [5.62], Priority [21]
[----] I, [2017-10-27T03:48:02.865969 #44140:9d3140]  INFO -- : Q-task_id([log_status]) MIQ(MiqServer.log_status) [EVM Server (2485)] Process info: Memory Usage [1107316736], Memory Size [2548826112], Proportional Set Size: [995872000], Memory % [6.65], CPU Time [15970987.0], CPU % [3.59], Priority [30]
[----] I, [2017-10-27T03:53:03.344190 #1922:9d3140]  INFO -- : Q-task_id([log_status]) MIQ(MiqServer.log_status) [EVM Server (2485)] Process info: Memory Usage [652374016], Memory Size [1021591552], Proportional Set Size: [580378000], Memory % [3.92], CPU Time [47336822.0], CPU % [5.62], Priority [21]
[----] I, [2017-10-27T03:58:06.160892 #1906:9d3140]  INFO -- : Q-task_id([log_status]) MIQ(MiqServer.log_status) [EVM Server (2485)] Process info: Memory Usage [1216172032], Memory Size [2563485696], Proportional Set Size: [1108302000], Memory % [7.3], CPU Time [10617177.0], CPU % [1.26], Priority [30]

Expected results:  MiqServer.log_status should show the actual server process memory/cpu information and not the worker process that handles the message.  :-(



Additional info:

Comment 2 Joe Rafaniello 2017-12-01 18:57:17 UTC
Upstream PR merged: https://github.com/ManageIQ/manageiq/pull/16460


Note You need to log in before you can comment on or make changes to this bug.