Bug 1416328 - Move multiple REGEX from logger DEBUG level to INFO in vdsm.log
Summary: Move multiple REGEX from logger DEBUG level to INFO in vdsm.log
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: BLL.Storage
Version: 4.1.0
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: ovirt-4.2.0
: ---
Assignee: Benny Zlotnik
QA Contact: Raz Tamir
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-01-25 09:54 UTC by Raz Tamir
Modified: 2017-02-20 12:25 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-02-20 12:25:50 UTC
oVirt Team: Storage
ylavi: ovirt-4.2+


Attachments (Terms of Use)

Description Raz Tamir 2017-01-25 09:54:43 UTC
Description of problem:
Since moving the vdsm.log to INFO level, we have issues to track some operations:

* To see the amount of running tasks:
In INFO level it is missing. in DEBUG level:
2017-01-25 11:21:49,317 DEBUG (tasks/0) [storage.ThreadPool] Number of running tasks: 0 (threadPool:60)

* "lvextend" 

* "mount -t glusterfs -o backup-volfile-servers=%s %s

* 'dd.* if=/dev/zero.* of=.*/%s'

* "refreshStoragePool"  --> After activating a second SD

* connectStoragePool.*domainsMap={(%s|%s)}  --> After activating a second SD

* Run and protect: extendVolumeSize

* LSM:
- 'createVolume'
- 'cloneImageStructure'
- 'syncImageData'
- 'deleteImage'


We need those REGEX to appear in INFO level


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


How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:

Comment 1 Tal Nisan 2017-01-25 10:53:08 UTC
Nir, what's your take on that?

Comment 2 Nir Soffer 2017-01-25 11:26:22 UTC
We cannot have these logs in info level, but we can add proper info level logs for
system state changes that are not logged now.

Please explain in more details why do you need each log (what are you trying to do
with each of these logs).

Comment 3 Raz Tamir 2017-01-25 15:41:25 UTC
We have a tool (log_listener.py) that search for a regular expression in the logs (vdsm.log, engine.log, ...) and when it appears, we can perform any operation we like - restart of services, modify iptables, create/remove files, ...

The idea is to wait for a regex, for example 'cloneImageStructure' which is a step of LSM, and restart the SPM when it appears.

The 'dd.* if=/dev/zero.* of=.*/%s' for example is to ensure that the wipe after delete operation is actually happening.

Comment 4 Nir Soffer 2017-02-06 14:35:03 UTC
(In reply to Raz Tamir from comment #3)
> We have a tool (log_listener.py) that search for a regular expression in the
> logs (vdsm.log, engine.log, ...) and when it appears, we can perform any
> operation we like - restart of services, modify iptables, create/remove
> files, ...
> 
> The idea is to wait for a regex, for example 'cloneImageStructure' which is
> a step of LSM, and restart the SPM when it appears.
> 
> The 'dd.* if=/dev/zero.* of=.*/%s' for example is to ensure that the wipe
> after delete operation is actually happening.

The big picture is clear, now what we need is the events that you want to detect.

Basically log INFO is meant for operations that change the system state. If we
have long operation, we generally want one log when starting the operation, and
one long when we finish, with the elapsed time.

If you need more specif log like the the qemu-img command line used, it is
available only in DEBUG level, and we cannot expose it in INFO level.

Comment 5 Raz Tamir 2017-02-20 12:25:50 UTC
Thanks Nir


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