Bug 1314826 - No debug log entry for user executing an action or query
Summary: No debug log entry for user executing an action or query
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: Backend.Core
Version: 4.0.0
Hardware: Unspecified
OS: Unspecified
low
low
Target Milestone: ovirt-3.6.7
: 3.6.7
Assignee: Ravi Nori
QA Contact: Petr Matyáš
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-03-04 16:00 UTC by Ravi Nori
Modified: 2016-07-04 12:32 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-07-04 12:32:45 UTC
oVirt Team: Infra
Embargoed:
rule-engine: ovirt-3.6.z+
mgoldboi: planning_ack+
mperina: devel_ack+
pstehlik: testing_ack+

Attachments (Terms of Use)
engine log (906.42 KB, text/plain)
2016-05-11 15:19 UTC, Petr Matyáš 		no flags Details
View All


Links
System ID Private Priority Status Summary Last Updated
oVirt gerrit 54365 0 master MERGED engine : No debug log entry for user executing an action or query 2016-03-08 15:50:02 UTC
oVirt gerrit 54487 0 ovirt-engine-3.6 MERGED engine : No debug log entry for user executing an action or query 2016-03-09 08:56:19 UTC
oVirt gerrit 57423 0 master MERGED engine : No debug log entry for user executing multiple actions 2016-05-15 09:26:34 UTC
oVirt gerrit 57518 0 ovirt-engine-3.6 MERGED engine : No debug log entry for user executing multiple actions 2016-05-16 19:37:09 UTC

Description Ravi Nori 2016-03-04 16:00:10 UTC 
Description of problem:

There is no debug information in the engine.log to indicate which user is executing a query or action.

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


How reproducible:
Enable debug log level and start engine

Steps to Reproduce:
1. Execute a query or action

Actual results:
engine.log does not have debug log on which query/action is executed by user

Expected results:
There should be an entry in engine.log indicating that a query/action is being executed by a user
Comment 1 Petr Kubica 2016-04-15 13:52:24 UTC 
Hi,
when I removed a VM, I cannot find in log which user did it.
for example:

2016-04-15 15:39:47,224 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp-/127.0.0.1:8702-5) [37107067] Correlation ID: 53754440, Job ID: 6ddf0b06-cc2d-44af-9a1b-223ab9acac66, Call Stack: null, Custom Event ID: -1, Message: VM foofoo was created by admin@internal.
....
2016-04-15 15:40:29,841 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-37) [45d2fb2c] Correlation ID: 45d2fb2c, Job ID: f90bdc36-049d-459d-8013-d65e87afc507, Call Stack: null, Custom Event ID: -1, Message: VM foofoo was successfully removed.

-> missing "by admin@internal"
Comment 2 Red Hat Bugzilla Rules Engine 2016-04-18 10:31:16 UTC 
Target release should be placed once a package build is known to fix a issue. Since this bug is not modified, the target version has been reset. Please use target milestone to plan a fix for a oVirt release.
Comment 3 Ravi Nori 2016-04-19 17:42:41 UTC 
Its a debug log entry please test with debug enabled
Comment 4 Oved Ourfali 2016-05-04 06:27:47 UTC 
Moving to ON_QA until we get feedback from Petr.
Comment 5 Petr Matyáš 2016-05-11 15:19:08 UTC 
Created attachment 1156204 [details]
engine log

After some archaeology work, I didn't find any message in DEBUG related to missing user which deleted a VM. If you want, you can check yourself. I can provide access to a working engine with debug log level which you can use.
Comment 6 Red Hat Bugzilla Rules Engine 2016-05-11 15:19:37 UTC 
Target release should be placed once a package build is known to fix a issue. Since this bug is not modified, the target version has been reset. Please use target milestone to plan a fix for a oVirt release.
Comment 7 Petr Matyáš 2016-05-11 15:20:44 UTC 
Sorry, I forgot to mention I'am using 3.6.6-3
Comment 8 Red Hat Bugzilla Rules Engine 2016-05-11 15:20:50 UTC 
Target release should be placed once a package build is known to fix a issue. Since this bug is not modified, the target version has been reset. Please use target milestone to plan a fix for a oVirt release.
Comment 9 Martin Perina 2016-05-12 08:23:53 UTC 
Just verified that everything works fine on 3.6.6, IMO the issue during verifying the bug is caused by a bit tricky logging configuration. In order to see those debug messages following category has to be enable in ovirt-engine.xml.in:

 <logger category="org.ovirt.engine.core.bll">                                 
   <level name="DEBUG"/>                                 
 </logger>                                          

Using the above you can see debug logs for both commands and queries, for example:

 2016-05-12 10:09:19,442 DEBUG [org.ovirt.engine.core.bll.Backend] (default task-32) [] Executing command AddEmptyStoragePool for user admin@internal-authz.

 2016-05-12 10:09:22,406 DEBUG [org.ovirt.engine.core.bll.Backend] (default task-54) [] Executing query GetConnectionsByDataCenterAndStorageType with isFiltered : false for user admin@internal-authz.
 

Maybe a bit confusing is, that DEBUG logging can be turned on/off for each package (category) and we have following default in ovirt-engine.xml.in:

 <logger category="org.ovirt" use-parent-handlers="false">
   <level name="INFO"/>
   ...
 </logger>

 ...

 <logger category="org.ovirt.engine.core.bll">
   <level name="INFO"/>
 </logger>

So if you change log level to DEBUG for category "org.ovirt", then for category "org.ovirt.engine.core.bll" it's overwritten to INFO. And to show debug logs described in the bug description, we need to have set DEBUG on category "org.ovirt.engine.core.bll" at minimum.

I will try to reach Petr today, check his setup ...
Comment 10 Petr Matyáš 2016-05-12 09:01:05 UTC 
Add VM command is logged, but Remove VM command isn't.
Comment 11 Petr Matyáš 2016-05-26 14:38:40 UTC 
Verified on 3.6.7-1

All actions I checked had findable user id in debug log
Note You need to log in before you can comment on or make changes to this bug.