11:44 a.m.
Hello,
I've been strapped for time to work on this lately, but have a couple
updates. I have been using the updated RHEL 6.1 packages, so
unfortunately that doesn't seem to solve the problem yet.
I'm still having some trouble capturing all the output, but I have
manged to collect this verbose output after aborting a "stalled"
request:
[ 35.206396] end_request: I/O error, dev vda, sector 2048
[ 35.207363] Buffer I/O error on device vda1, logical block 0
[ 35.207384] lost page write due to I/O error on vda1
[ 35.207384] Buffer I/O error on device vda1, logical block 1
[ 35.207384] lost page write due to I/O error on vda1
[ 35.207384] end_request: I/O error, dev vda, sector 1574912
[ 35.207384] Buffer I/O error on device vda1, logical block 196608
[ 35.207384] lost page write due to I/O error on vda1
[ 35.207384] end_request: I/O error, dev vda, sector 1575624
[ 35.207384] Buffer I/O error on device vda1, logical block 196697
[ 35.207384] lost page write due to I/O error on vda1
check_for_daemon_cancellation_or_eof: 0x1786f80 g->state = 3, fd = 66
child_cleanup: 0x1786f80: child process died
I should probably note that this is being done over NFS mounted
images. I'm fairly sure there aren't NFS problems though, as the NFS
mounts are quite stable and otherwise seem to respond just fine
against the same mounts at the same time this problem occurs.
I'm hoping the above might trigger some ideas but I'm still working on
trying to figure out the lack of verbose data to stderr otherwise.
Thanks,
TJ
On Sat, Apr 30, 2011 at 5:32 AM, Richard W.M. Jones <rjones(a)redhat.com> wrote:
On Sat, Apr 30, 2011 at 01:10:57AM -0400, T Johnson wrote:
> Thanks for responding. I'm by no means a python expert so I could very
> well be doing something wrong, but I've been playing a bit with what
> you've suggested and noted a few interesting things.
>
> 1) As soon as I create 'g', something seems to take over stderr and
> stdout so I can no longer print debugging output like you suggested.
This is very odd. AFAIK nothing in libguestfs should affect stdout or
stderr.
When you say "create 'g'" do you mean "g = guestfs.GuestFS()"
(ie.
create the handle) or "g.launch ()" (ie. launch the subprocess)? I
guess it is possible that something in g.launch (ie. forking off a
subprocess) might affect stdout/stderr, although we use it in an awful
lot of other programs and no one has noticed anything before.
Here's my test program:
----------------------------------------------------------------------
#!/usr/bin/python
import sys
import guestfs
print >> sys.stderr, "creating the handle"
g = guestfs.GuestFS()
print >> sys.stderr, "add_drive_ro"
g.add_drive_ro ("/dev/null")
print >> sys.stderr, "launch"
g.launch ()
print >> sys.stderr, "set_verbose"
g.set_verbose (1)
print >> sys.stderr, "delete the handle"
#g.close ()
del g
print >> sys.stderr, "finished"
----------------------------------------------------------------------
BTW you can't directly call g.close() from Python because that method
is not exposed (instead, it is called implicitly when you delete g).
So your program ought to be throwing an exception when you try to call
g.close(). I'm not sure why you are not seeing that.
You're not trying to create the underlying libguestfsmod objects
directly? Don't do that.
Here is the output from my test program:
----------------------------------------------------------------------
creating the handle
add_drive_ro
launch
set_verbose
delete the handle
libguestfs: closing guestfs handle 0x25106a0 (state 2)
libguestfs: send_to_daemon: 44 bytes: 00 00 00 28 | 20 00 f5 f5 | 00 00 00 04 | 00 00 01
1a | 00 00 00 00 | ...
libguestfs: recv_from_daemon: 40 bytes: 20 00 f5 f5 | 00 00 00 04 | 00 00 01 1a | 00 00
00 01 | 00 12 34 00 | ...
libguestfs: sending SIGTERM to process 13874
finished
----------------------------------------------------------------------
As you can see it's completely as expected
(python-libguestfs-1.11.3-1.fc16.x86_64).
> 2) (I assume) because of #1, g.set_verbose(1) results in no output to
> stdout/stderr either, so it hasn't been helpful so far.
>
> 3) However, I then decided to try g.set_trace(1) and that does provide
> output. In the example I provided before I get this (editing config
> settings in /etc/sysconfig/network):
Unfortunately (because of a bug) closing the handle does not result
in any trace output, except ...
> libguestfs: trace: add_drive "/mnt/images/test_server.img"
> libguestfs: trace: add_drive = 0
> libguestfs: trace: launch
> libguestfs: trace: launch = 0
> libguestfs: trace: mount "/dev/vda1" "/"
> libguestfs: trace: mount = 0
> libguestfs: trace: write "/etc/sysconfig/network" "..."
> libguestfs: trace: write = 0
>
> I can't seem to get any other ouput.. but it is very interesting that
> once I kill the process I see the remainder of the calls failing from
> trace output:
>
> libguestfs: trace: umount_all
> libguestfs: trace: umount_all = -1 (error)
> libguestfs: trace: sync
> libguestfs: trace: sync = -1 (error)
> libguestfs: trace: umount_all
> libguestfs: trace: umount_all = -1 (error)
> libguestfs: trace: sync
> libguestfs: trace: sync = -1 (error)
... when you close a handle which has autosync enabled, which is now
the default, you'll see output like this. It seems like all your
handles are getting closed at once. I have no idea why.
> So, I guess that is what's failing.. but I haven't been able to
> determine why yet.
>
> This is something I've been running into on much older versions of
> libguestfs all the way up to now which I'm trying your recent
> "1.7.17-17.el6" RPMs for rhel6.
Ah, so this could be RHEL 6.0? This could well be a RHEL 6.0 bug.
Definitely try out the RHEL 6.1 packages from:
http://people.redhat.com/~rjones/rhel6.1-libguestfs-preview/
You'll find a lot of things are better. It's much faster for one.
Rich.
--
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
virt-df lists disk usage of guests without needing to install any
software inside the virtual machine. Supports Linux and Windows.
http://et.redhat.com/~rjones/virt-df/