Re: [Libguestfs] running libguestfs as a service?
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/
On Sat, Apr 30, 2011 at 10:32:32AM +0100, Richard W.M. Jones wrote:
Unfortunately (because of a bug) closing the handle does not result in any trace output, except ...
I just pushed this change upstream to fix the bug: http://git.annexia.org/?p=libguestfs.git;a=commitdiff;h=91b35746b438240c0b64... Rich. -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones New in Fedora 11: Fedora Windows cross-compiler. Compile Windows programs, test, and build Windows installers. Over 70 libraries supprt'd http://fedoraproject.org/wiki/MinGW http://www.annexia.org/fedora_mingw
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@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/
On Thu, May 05, 2011 at 12:44:38PM -0400, T Johnson wrote:
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.
There seem to be a number of different things going on, but I really don't have enough detail to be able to fix this. This error seems to be unrelated to the Python issues you were having before. The I/O errors above would be because the underlying disk is somehow read-only to qemu. For NFS I guess this could be because of root_squash-ing. Rich. -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones virt-p2v converts physical machines to virtual machines. Boot with a live CD or over the network (PXE) and turn machines into Xen guests. http://et.redhat.com/~rjones/virt-p2v
On Thu, May 5, 2011 at 10:59 PM, Richard W.M. Jones <rjones@redhat.com> wrote:
On Thu, May 05, 2011 at 12:44:38PM -0400, T Johnson wrote:
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.
There seem to be a number of different things going on, but I really don't have enough detail to be able to fix this. This error seems to be unrelated to the Python issues you were having before.
The I/O errors above would be because the underlying disk is somehow read-only to qemu.
By this you mean the uid the process is running as and not the actual 'qemu' uid, right? Just making sure..
For NFS I guess this could be because of root_squash-ing.
Hmm, ok. I will keep plugging away and update the thread if I discover something. One thing that's curious is I've also played with just using command-line `virt-X` and `guestfish` to upload new files to the same images and haven't had the same write problems and/or process hangs. Secondly, the changes *do* get written to the images so it's certainly not a flat-out permission denied issue. Anyway, thanks for the feedback. TJ
On Fri, May 06, 2011 at 06:10:24PM -0400, T Johnson wrote:
On Thu, May 5, 2011 at 10:59 PM, Richard W.M. Jones <rjones@redhat.com> wrote:
The I/O errors above would be because the underlying disk is somehow read-only to qemu.
By this you mean the uid the process is running as and not the actual 'qemu' uid, right? Just making sure..
No, I mean that libguestfs is unable to open the disk in anything other than read-only mode. The 'qemu' user/uid has nothing to do with this.
For NFS I guess this could be because of root_squash-ing.
Hmm, ok. I will keep plugging away and update the thread if I discover something.
One thing that's curious is I've also played with just using command-line `virt-X` and `guestfish` to upload new files to the same images and haven't had the same write problems and/or process hangs. Secondly, the changes *do* get written to the images so it's certainly not a flat-out permission denied issue.
It's got something to do with what permissions or user your daemon / remote process runs as, but from here it's hard to say exactly what. Rich. -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones libguestfs lets you edit virtual machines. Supports shell scripting, bindings from many languages. http://libguestfs.org
participants (2)
-
Richard W.M. Jones -
T Johnson