Bug 673477

Summary: Add a grep-friendly string to LIBGUESTFS_TRACE output
Product: Red Hat Enterprise Linux 6 Reporter: Matthew Booth <mbooth>
Component: libguestfsAssignee: Richard W.M. Jones <rjones>
Status: CLOSED ERRATA QA Contact: Virtualization Bugs <virt-bugs>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 6.1CC: leiwang, mshao
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: libguestfs-1.7.17-12.el6 Doc Type: Bug Fix
Doc Text:
Separating libguestfs trace output from debug output was difficult. A string (libguestfs: trace:) is now added to the beginning of each line of the trace output so that it can be easily distinguished and filtered out of logs with the grep command or similar.
Story Points: ---
Clone Of:
: 673479 (view as bug list) Environment:
Last Closed: 2011-05-19 11:44:15 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 673479    
Bug Blocks:    

Description Matthew Booth 2011-01-28 10:58:36 UTC
When debugging virt-v2v problems, the most useful debug information is normally LIBGUESTFS_TRACE. Occasionally LIBGUESTFS_DEBUG is also useful, but less often. However, it is a problem when these 2 outputs are mixed. DEBUG is significantly more verbose than TRACE (about 100:1 iirc), and it is not trivial to separate their outputs.

It would greatly simplify debugging instructions to users if we could simply request both outputs. The result should:

* Be simple to view mixed, chronologically
* Be simple to separate

Adding a grep-friendly string to TRACE and/or DEBUG output would achieve this. It doesn't really matter what the string(s) is/are.

Comment 1 Richard W.M. Jones 2011-01-28 11:06:03 UTC
To test this:

$ guestfish -x -N fs exit
is_config = 1
add_drive "test1.img" = 0
is_config = 1
launch = 0
part_disk "/dev/sda" "mbr" = 0
mkfs "ext2" "/dev/sda1" = 0
umount_all = 0
sync = 0
kill_subprocess = 0

Notice that each trace line just has the command.

When we patch libguestfs, we will add some (undecided) prefix
to each line, so in the output above each line would have a prefix.

Also note that 'guestfish -x -N fs exit' won't work at all in the
RHEL 6.0 libguestfs.

Comment 2 Richard W.M. Jones 2011-01-28 11:14:03 UTC
This is the output when patched:

$ guestfish -x -N fs exit
libguestfs: trace: is_config = 1
libguestfs: trace: add_drive "test1.img" = 0
libguestfs: trace: is_config = 1
libguestfs: trace: launch = 0
libguestfs: trace: part_disk "/dev/sda" "mbr" = 0
libguestfs: trace: mkfs "ext2" "/dev/sda1" = 0
libguestfs: trace: umount_all = 0
libguestfs: trace: sync = 0
libguestfs: trace: kill_subprocess = 0

Comment 3 Richard W.M. Jones 2011-01-28 16:24:03 UTC
Ignore comment 2.  The final patch upstream makes
the output look like this which each call having a
call and return value on separate lines:

libguestfs: trace: is_config
libguestfs: trace: is_config = 1
libguestfs: trace: add_drive "test1.img"
libguestfs: trace: add_drive = 0
libguestfs: trace: is_config
libguestfs: trace: is_config = 1
libguestfs: trace: launch
libguestfs: trace: launch = 0
libguestfs: trace: part_disk "/dev/sda" "mbr"
libguestfs: trace: part_disk = 0

etc.

Comment 4 Richard W.M. Jones 2011-01-31 13:22:23 UTC
https://brewweb.devel.redhat.com/buildinfo?buildID=155740

Comment 6 Richard W.M. Jones 2011-02-03 13:18:51 UTC
Note to self:

The following patches are required to fully fix this:

(1) http://git.annexia.org/?p=libguestfs.git;a=commitdiff;h=1d999540bddd7aea7c2d0fef8b15223d4acc645f
Add a prefix to output when tracing (RHBZ#673479).

(2) http://git.annexia.org/?p=libguestfs.git;a=commitdiff;h=b6c70b3f50472e20a33320e7d76887b011f33c64
Fix test-guestfish-a.sh regression test for new trace format.

(3) http://git.annexia.org/?p=libguestfs.git;a=commitdiff;h=f2a4020caf0bc3dd63e9eae95dfc1814f051f87e
regressions: Fix rhbz557655.sh so it works with tracing enabled.

Unfortunately we screwed up and only (1) and (2) are applied
to the RHEL 6.1 package.  I'm not going to rebuild this
again now, so (3) will need to be added in RHEL 6.2.

Comment 7 Lei Wang 2011-02-10 03:32:16 UTC
Test with libguestfs-1.7.17-10.el6:

# guestfish -x -N fs exit
is_config = 1
add_drive "test1.img" = 0
is_config = 1
launch = 0
part_disk "/dev/sda" "mbr" = 0
mkfs "ext2" "/dev/sda1" = 0
umount_all = 0
sync = 0
kill_subprocess = 0

with libguestfs-1.7.17-12.el6:

# guestfish -x -N fs exit
libguestfs: trace: is_config
libguestfs: trace: is_config = 1
libguestfs: trace: add_drive "test1.img"
libguestfs: trace: add_drive = 0
libguestfs: trace: is_config
libguestfs: trace: is_config = 1
libguestfs: trace: launch
libguestfs: trace: launch = 0
libguestfs: trace: part_disk "/dev/sda" "mbr"
libguestfs: trace: part_disk = 0
... 

So move to VERIFIED.

Comment 10 Laura Bailey 2011-04-20 01:03:39 UTC
    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
Separating libguestfs trace output from debug output was difficult. A string (libguestfs: trace:) is now added to the beginning of each line of the trace output so that it can be easily distinguished and filtered out of logs with the grep command or similar.

Comment 11 Richard W.M. Jones 2011-04-20 07:42:59 UTC
This is fine, thanks.

Comment 12 errata-xmlrpc 2011-05-19 11:44:15 UTC
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2011-0586.html

Comment 13 errata-xmlrpc 2011-05-19 13:10:54 UTC
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2011-0586.html