1. Feature Overview: Feature Id: [71085] a. Name of Feature: [6.2 FEAT] Event logging framework for libvirt b. Feature Description Libvirt is an important component of the Linux virtualization stack. Its been found that for better understanding and debugging of the virtualization infrastructure, a lightweight framework to track libvirt event infrastructure state changes with an accurate timestamp is absolutely necessary. We are working on an ancillary framework that would either be a daemon or integrated with libvirt, through which we can track the state changes with accurate timestamping for a low overhead time ordered event logging framework. This is under development and we intend to push this to the upstream libvirt repository. 2. Feature Details: Sponsor: LTC RAS Architectures: x86, x86_64, Arch Specificity: purely common code Affects Kernel Modules: No Delivery Mechanism: Direct from Community Category: other Request Type: Toolchain - Enhancement from Upstream d. Upstream Acceptance: Not Started Sponsor Priority P3 f. Severity: normal IBM Confidential: No Code Contribution: IBM code g. Component Version Target: --- 3. Business Case As virtualization becomes de-facto for cloud solutions and critical customer deployments, ability to understand the transitions and workings of the full stack is imperative in order for service personnel and sysamdin to understand the path and timeline of code execution and state transitions for debugging, tuning and development of features in the virtualization stack. Currently libvirt is an opaque layer in the virtualization infrastructure stack and this work will help mitigate the situation to an extent. 4. Primary contact at Red Hat: John Jarvis, jjarvis 5. Primary contacts at Partner: Project Management Contact: Michael W. Wortman, wortman.com Technical contact(s): Ananth Narayan M G, ananth.narayan.com
Since RHEL 6.1 External Beta has begun, and this bug remains unresolved, it has been rejected as it is not proposed as exception or blocker. Red Hat invites you to ask your support representative to propose this request, if appropriate and relevant, in the next release of Red Hat Enterprise Linux.
------- Comment From skannery.com 2011-05-20 07:35 EDT------- As part of making libvirt and virsh logging infrastruture better, added environment variable support for virsh logging. Please find details of the patches sent upstream: 1. commit : 3c36f936b98e76cefbc088620d91b08dd3b81116 2. Discussion thread: http://www.mail-archive.com/libvir-list@redhat.com/msg37353.html Currently a virsh process logs traces to the file specified in the command line (-l option). Multiple instances of virsh, thus requires same log file to be mentioned in command line of each of the instances. To avoid this, two new environment variables are used to control virsh log level and log file - "VIRSH_DEBUG" and "VIRSH_LOG_FILE" Will be attaching the ported patch soon. Please let me know if you need any more info related to this feature.
Created attachment 500083 [details] Patch for enabling env variable support for virsh logging ------- Comment on attachment From skannery.com 2011-05-20 11:39 EDT------- Attaching the patch for enabling environment variable support for virsh logging. Two new environment variables are defined: a. VIRSH_DEBUG=<log_level> log_level can be a value between 0 - 4, where 0 -> "DEBUG" 1 -> "INFO" 2 -> "NOTICE" 3 -> "WARNING" 4 -> "ERROR" b. VIRSH_LOG_FILE=<logfile-path-and-name> logfile-path-and-name is the name and complete path for the log file.
This is now implemented upstream by v0.9.1-213-g3c36f93: commit 3c36f936b98e76cefbc088620d91b08dd3b81116 Author: Supriya Kannery <supriyak.com> Date: Mon May 9 12:38:06 2011 +0530 virsh: Use Env variables for debug level and logfile Use variables VIRSH_DEBUG and VIRSH_LOG_FILE for controlling virsh logging. Signed-off-by: Supriya Kannery <supriyak.com>
Actually, that patch seems to be just one small part of this feature. Resetting back to ASSIGNED.
Can someone from IBM comment on whether IBM will be submitting further work in this area?
------- Comment From skannery.com 2011-06-16 10:57 EDT------- (In reply to comment #10) > Can someone from IBM comment on whether IBM will be submitting further work in > this area? With the existing libvirt tracing infrastructure and virsh tracing patch we submitted, the event tracing infrastructure requirement for libvirt is already addressed. Yet, we would like to get both virsh and libvirt log into a single file. So we have plans to submit patches for the same.
The upstream code acceptance deadline was actually today, although we can certainly make an exception for this code if you feel like you can get it submitted relatively quickly. When do you think you might be able to submit it?
------- Comment From skannery.com 2011-06-17 00:35 EDT------- (In reply to comment #12) > The upstream code acceptance deadline was actually today, although we can > certainly make an exception for this code if you feel like you can get it > submitted relatively quickly. When do you think you might be able to submit > it? Necessary patches for 6.2 are done. So the patches that I mentioned in my previous comment (combining virsh and libvirt logging), we can possibly get those done for 6.3 .
Ok, thanks; I'll put this BZ in POST to reflect that the VIRSH_DEBUG and VIRSH_LOG_FILE environment variable work is done. Would you mind filing a separate bug for any further work you are planning?
This should be fixed by the libvirt-0.9.2-1.el6 rebase
According to Comment #13, I only check VIRSH_DEBUG and VIRSH_LOG_FILE environment variables in this bug. From the steps below I think the variables can work. But log in debug,info and error mode seems the same. I think log in debug mode should only display with *debug* info, log in error mode should display *debug/info/notice/warning/error* all info. Please confirm if it is right, thanks Environment: 2.6.32-156.el6.x86_64 qemu-kvm-0.12.1.2-2.165.el6.x86_64 libvirt-0.9.2-1.el6.x86_64 Steps: 1.####Check debug level as Debug#### # export VIRSH_LOG_FILE=/tmp/debug.log # export VIRSH_DEBUG=0 # echo $VIRSH_DEBUG 0 # echo $VIRSH_LOG_FILE /tmp/debug.log # ll /tmp/debug.log ls: cannot access /tmp/debug.log: No such file or directory # virsh list --all Id Name State ---------------------------------- - rhel61 shut off # virsh start rhel61 Domain rhel61 started # cat /tmp/debug.log [2011.06.23 13:49:28 virsh 25068] DEBUG start: found option <domain>: rhel61 [2011.06.23 13:49:28 virsh 25068] DEBUG start: <domain> trying as domain NAME # virsh start rhel61 error: Domain is already active # cat /tmp/debug.log [2011.06.23 13:49:28 virsh 25068] DEBUG start: found option <domain>: rhel61 [2011.06.23 13:49:28 virsh 25068] DEBUG start: <domain> trying as domain NAME [2011.06.23 13:49:44 virsh 25124] DEBUG start: found option <domain>: rhel61 [2011.06.23 13:49:44 virsh 25124] DEBUG start: <domain> trying as domain NAME [2011.06.23 13:49:44 virsh 25124] ERROR Domain is already active # ll /tmp/debug.log -rw-r--r--. 1 root root 375 Jun 23 13:49 /tmp/debug.log 2. #####Check debug level as error#### # export VIRTSH_DEBUG=4 # echo $VIRSH_DEBUG 4 # export VIRSH_LOG_FILE=/tmp/error.log # echo $VIRSH_LOG_FILE /tmp/error.log # ll /tmp/error.log ls: cannot access /tmp/error.log: No such file or directory # virsh list --all Id Name State ---------------------------------- 2 rhel61 running # virsh destroy rhel61 Domain rhel61 destroyed # cat /tmp/error.log [2011.06.23 14:12:52 virsh 25452] DEBUG destroy: found option <domain>: rhel61 [2011.06.23 14:12:52 virsh 25452] DEBUG destroy: <domain> trying as domain NAME # virsh destroy rhel61 libvir: QEMU error : Requested operation is not valid: domain is not running error: Failed to destroy domain rhel61 error: Requested operation is not valid: domain is not running # cat /tmp/error.log [2011.06.23 14:12:52 virsh 25452] DEBUG destroy: found option <domain>: rhel61 [2011.06.23 14:12:52 virsh 25452] DEBUG destroy: <domain> trying as domain NAME [2011.06.23 14:17:34 virsh 25548] DEBUG destroy: found option <domain>: rhel61 [2011.06.23 14:17:34 virsh 25548] DEBUG destroy: <domain> trying as domain NAME [2011.06.23 14:17:34 virsh 25548] ERROR Failed to destroy domain rhel61 [2011.06.23 14:17:34 virsh 25548] ERROR Requested operation is not valid: domain is not running 3. ####Set debug level as Info##### # export VIRSH_DEBUG=1 # echo $VIRSH_DEBUG 1 # export VIRSH_LOG_FILE=/tmp/info.log # echo $VIRSH_LOG_FILE /tmp/info.log # ll /tmp/info.log ls: cannot access /tmp/info.log: No such file or directory # virsh destroy rhel61 libvir: QEMU error : Requested operation is not valid: domain is not running error: Failed to destroy domain rhel61 error: Requested operation is not valid: domain is not running # virsh start rhel61 Domain rhel61 started # ll /tmp/info.log -rw-r--r--. 1 root root 482 Jun 23 14:29 /tmp/info.log # cat /tmp/info.log [2011.06.23 14:29:30 virsh 25651] DEBUG destroy: found option <domain>: rhel61 [2011.06.23 14:29:30 virsh 25651] DEBUG destroy: <domain> trying as domain NAME [2011.06.23 14:29:30 virsh 25651] ERROR Failed to destroy domain rhel61 [2011.06.23 14:29:30 virsh 25651] ERROR Requested operation is not valid: domain is not running [2011.06.23 14:29:35 virsh 25659] DEBUG start: found option <domain>: rhel61 [2011.06.23 14:29:35 virsh 25659] DEBUG start: <domain> trying as domain NAME ------- I can reproduce with Old pkg:libvirt-0.9.1-1.el6.x86_64, nothing will take effect for these 2 environment variable. Steps: # echo $VIRSH_LOG_FILE /tmp/virsh.log # echo $VIRSH_DEBUG 0 # ll /tmp/virsh.log ls: cannot access /tmp/virsh.log: No such file or directory # virsh start rhel61 Domain rhel61 started # virsh destroy rhel61 Domain rhel61 destroyed # ll /tmp/virsh.log ls: cannot access /tmp/virsh.log: No such file or directory
Also I find another issue about virsh help/man page about debug level. Pls keep the consistence about debug level (0-4 or 0-5?) in help page and man page. Would these will be fixed in this bug? Or should we file a new bug to track? Please help to confirm, thanks New pkg:libvirt-0.9.2-1.el6.x86_64 # virsh --help |grep debug -d | --debug <num> debug level [0-4] # man virsh ... -d, --debug LEVEL Enable debug messages at integer LEVEL and above. LEVEL can range from 0 (default) to 5. LIBVIRT_DEBUG=LEVEL Turn on verbose debugging of all libvirt API calls. Valid levels are · LIBVIRT_DEBUG=1 Messages at level DEBUG or above · LIBVIRT_DEBUG=2 Messages at level INFO or above · LIBVIRT_DEBUG=3 Messages at level WARNING or above · LIBVIRT_DEBUG=4 Messages at level ERROR or above Old pkg:libvirt-0.9.1-1.el6.x86_64 1. # virsh -h |grep debug -d | --debug <num> debug level [0-5] 2. # man virsh ... -d, --debug LEVEL Enable debug messages at integer LEVEL and above. LEVEL can range from 0 (default) to 5. ... LIBVIRT_DEBUG=LEVEL Turn on verbose debugging of all libvirt API calls. Valid levels are · LIBVIRT_DEBUG=1 Messages at level DEBUG or above · LIBVIRT_DEBUG=2 Messages at level INFO or above · LIBVIRT_DEBUG=3 Messages at level WARNING or above · LIBVIRT_DEBUG=4 Messages at level ERROR or above
------- Comment From skannery.com 2011-06-24 07:21 EDT------- (In reply to comment #14) For any further work, we will file new bug.
Heh, I should have looked at this series closer. The patch, the rest of the series was actually never finished by its author and thus not applied. Logging in virsh is currently just a big mess and setting VIRSH_DEBUG=N (or virsh -d N) has basically no effect for any N.
------- Comment From skannery.com 2011-06-24 07:30 EDT------- (In reply to comment #16) > According to Comment #13, I only check VIRSH_DEBUG and VIRSH_LOG_FILE > environment variables in this bug. From the steps below I think the variables > can work. But log in debug,info and error mode seems the same. I think log in > debug mode should only display with *debug* info, log in error mode should > display *debug/info/notice/warning/error* all info. Please confirm if it is > right, thanks > Previous to this patch, virsh logging had the order that you specified, where for "DEBUG" only the debug messages logged and for "ERROR" messages at all the levels get logged. But libvirt logging is done the other way, where "DEBUG" level displays messages from "ALL" other levels and "ERROR" displays 'ONLY' error messages. And that is the right usage of DEBUG and ERROR levels. So in this feature, I changed virsh logging to align to libvirt logging as specified under the section "Configuring logging in the library" at http://libvirt.org/logging.html. Thanks, Supriya
------- Comment From skannery.com 2011-06-24 07:44 EDT------- (In reply to comment #17) > Also I find another issue about virsh help/man page about debug level. Pls keep > the consistence about debug level (0-4 or 0-5?) in help page and man page. > Would these will be fixed in this bug? Or should we file a new bug to track? > Please help to confirm, thanks > virsh can take log levels from 0 - 4 only as per how its coded. Debug level '5' mentioned in man page is a defect. There are few more existing defects with virsh tracing and logging that we need to resolve like a. Usage of magic numbers for logging instead of using log level variables in the code. b. Uses log level '5' for logging message whereas '5' is not a valid log level. c. discrepencies between the code and documentation on log levels These defects can be tracked through a new bug report. Can you please raise one?
------- Comment From skannery.com 2011-06-24 08:02 EDT------- (In reply to comment #20) > Heh, I should have looked at this series closer. The patch, the rest of the > series was actually never finished by its author and thus not applied. Logging > in virsh is currently just a big mess and setting VIRSH_DEBUG=N (or virsh -d N) > has basically no effect for any N. The core patch that contained the changes for applying environment variables has been accepted upstream and I have backported only that patch for inclusion into RHEL. Rest of the patches in the patchset were actually for resolving issues like magic number usage, incorrect log level order etc..(those I listed in comment #21) which are existing issues with virsh logging. I will be resending those patches for fixing these defects upstream. Please open a bug report for the same. Thanks, Supriya
According to comment #22, I have filed a new Bug 716888 to track log level and usage issue.
OK, since this BZ is only tracking the env. variable addition, which was already done (see comment #6), I'm moving this back to MODIFIED.
This enhancement request was evaluated by the full Red Hat Enterprise Linux team for inclusion in a Red Hat Enterprise Linux minor release. As a result of this evaluation, Red Hat has tentatively approved inclusion of this feature in the next Red Hat Enterprise Linux Update minor release. While it is a goal to include this enhancement in the next minor release of Red Hat Enterprise Linux, the enhancement is not yet committed for inclusion in the next minor release pending the next phase of actual code integration and successful Red Hat and partner testing.
According to Comment #6 and Comment #25, Move to VERIFIED
------- Comment From skannery.com 2011-10-25 07:33 EDT------- Verified in RHEL6.2 Snapshot2. Env variables for virsh for debug level and log file are working fine. Only part missing is the updation of these variables and their usage in virsh.pod file. Patches posted and accepted upstream, related to this, are discussed in bug #72823 (Redhat bug #716888) . Upstream discussion link : https://www.redhat.com/archives/libvir-list/2011-June/msg01574.html - thanks, Supriya
(In reply to comment #29) > Only part missing is the updation of these variables and their usage in > virsh.pod file. Patches posted and accepted upstream, related to this, are > discussed in bug #72823 (Redhat bug #716888) . bug 716888 is marked as fixed in libvirt-0.9.3-4.el6. > > Upstream discussion link : > https://www.redhat.com/archives/libvir-list/2011-June/msg01574.html The patches in that email series were already included in upstream 0.9.4. I don't see anything that you mentioned that should not already be present in RHEL6.2 Snapshot2.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. http://rhn.redhat.com/errata/RHBA-2011-1513.html