Bug 2115621

The error message is horrible, but the actual error is:

virt-v2v: error: filesystem was mounted read-only, even though we asked
 for it to be mounted read-write.  This usually means that the filesystem was no
t cleanly unmounted.  Possible causes include trying to convert a guest which is
 running, or using Windows Hibernation or Fast Restart.

This is caused by:

https://libguestfs.org/virt-v2v.1.html#windows-8-fast-startup-is-incompatible-with-virt-v2v

There may be an issue that the above error was not visible.  It should
be displayed clearly in the window during conversion and debug messages
should be hidden.  Did you see the error clearly?  (If not, could be
worth a screenshot so we can see what virt-p2v actually shows and if we
can improve the output).

Hi Tingting,

"virt-v2v-conversion-log.txt" from comment 0 contains the following:

> The disk contains an unclean file system (0, 0).
> Metadata kept in Windows cache, refused to mount.
> Falling back to read-only mount because the NTFS partition is in an
> unsafe state. Please resume and shutdown Windows fully (no hibernation
> or fast restarting.)
> Could not mount read-write, trying read-only

and then

> virt-v2v: error: filesystem was mounted read-only, even though we
> asked for it to be mounted read-write.  This usually means that the
> filesystem was not cleanly unmounted.  Possible causes include trying
> to convert a guest which is running, or using Windows Hibernation or
> Fast Restart.

This is documented in the manual, too:

https://libguestfs.org/virt-v2v.1.html#windows-8-fast-startup-is-incompatible-with-virt-v2v

and

https://libguestfs.org/guestfs.3.html#windows-hibernation-and-windows-8-fast-startup

So it does not look like a P2V or V2V problem; the problem is with the
system under conversion -- it was not correctly shut down. Please
disable Fast Startup in Windows (see the manual links above) and retry
the conversion.

(In reply to Richard W.M. Jones from comment #1)
> The error message is horrible, but the actual error is:
> 
> virt-v2v: error: filesystem was mounted read-only, even though we asked
>  for it to be mounted read-write.  This usually means that the filesystem
> was no
> t cleanly unmounted.  Possible causes include trying to convert a guest
> which is
>  running, or using Windows Hibernation or Fast Restart.
> 
> This is caused by:
> 
> https://libguestfs.org/virt-v2v.1.html#windows-8-fast-startup-is-
> incompatible-with-virt-v2v
> 
> There may be an issue that the above error was not visible.  It should
> be displayed clearly in the window during conversion and debug messages
> should be hidden.  Did you see the error clearly?  (If not, could be
> worth a screenshot so we can see what virt-p2v actually shows and if we
> can improve the output).

Converted to 2 different hosts, the error info are different, the 2 screenshots have been attached.

When virt-v2v exits due to the error at hand, the nbdkit processes (running the "nbd" plugin <https://libguestfs.org/nbdkit-nbd-plugin.1.html>) on the conversion server exit too. I think that a lot of tearing-down happens in quick succession, the ssh data connections (with reverse port forwarding) are closed too, the nbdkit servers that are local to the p2v machine should be exiting as well. That probably leads to a bunch of nbdkit error messages too, which may obscure the main reason. I think we could solve this if we logged all the nbdkit messages to separate files.

The long-standing issue here is that virt-v2v output is all sent to two streams
(stdout and stderr).  We actually need at least three streams to do this properly.
It's also complicated by the fact that virt-v2v runs many subprocesses, some of which
use stdout/stderr inconsistently.

At the moment:

stdout = where ordinary messages go, such as:

  [   0.0] Setting up the source: -i disk fedora-35.img
  [   1.1] Opening the source

and warnings like:

  virt-v2v: warning: /files/boot/grub2/device.map/hd0 references unknown 
  device "vda".  You may have to fix this entry manually after conversion.

stderr = error messages, like:

  virt-v2v: error: inspection could not detect the source guest (or physical 
  machine).

and debug messages.

Another complexity here is that we want to capture the full debug log in all
customer cases routinely (ideally with the debug log containing the stdout).

Virt-p2v uses some complicated gymnastics to ensure that stdout + stderr are
captured in a single debug log, and only stdout is displayed to the user during the
conversion (with colours!).

https://github.com/libguestfs/virt-p2v/blob/a1eeb11c87f9591dfe7115d23ce432f8b06613c9/conversion.c#L563

In the error case, virt-v2v dumps the last N (50?) lines of the log (which is
stdout + stderr) in the hope that the error message appears and isn't swamped
by too much debugging output.  This fails in the current case.

We have looked at this problem over the years and failed to come up with
a good solution to it.  (IMS had a similar problem with v2v).  I feel it might be
solved with a 3rd channel for debugging messages, to separate those from
error messages, but there are basically several requirements that conflict
with each other which makes this a hard problem.

> I think we could solve this if we logged all the nbdkit messages to separate files.

This doesn't really solve it.  In the debug log that we get back we need those
messages, and we need them in the same file so we can see the order that debug
messages were printed relative to regular messages.

(In reply to Laszlo Ersek from comment #2)
> Hi Tingting,
> 
> "virt-v2v-conversion-log.txt" from comment 0 contains the following:
> 
> > The disk contains an unclean file system (0, 0).
> > Metadata kept in Windows cache, refused to mount.
> > Falling back to read-only mount because the NTFS partition is in an
> > unsafe state. Please resume and shutdown Windows fully (no hibernation
> > or fast restarting.)
> > Could not mount read-write, trying read-only
> 
> and then
> 
> > virt-v2v: error: filesystem was mounted read-only, even though we
> > asked for it to be mounted read-write.  This usually means that the
> > filesystem was not cleanly unmounted.  Possible causes include trying
> > to convert a guest which is running, or using Windows Hibernation or
> > Fast Restart.
> 
> This is documented in the manual, too:
> 
> https://libguestfs.org/virt-v2v.1.html#windows-8-fast-startup-is-
> incompatible-with-virt-v2v
> 
> and
> 
> https://libguestfs.org/guestfs.3.html#windows-hibernation-and-windows-8-fast-
> startup
> 
> So it does not look like a P2V or V2V problem; the problem is with the
> system under conversion -- it was not correctly shut down. Please
> disable Fast Startup in Windows (see the manual links above) and retry
> the conversion.

Checked the os, Windows Hibernation and Fast Restart are not enabled, maybe the os is not shutdown fully as I operate via virtual media.

Tried again to shutdown the os fully and then tried virt-p2v, the os can be converted successfully.

As discussed above, we should hide debug message in virt-p2v window, then I change the title of the bug, thanks.

Some more brain dumps following on from comment 7:

Possible sources of error messages (all hard-coded to stderr):

 - virt-v2v itself

 - nbdkit

 - qemu-nbd

 - nbdcopy

 - some smaller utilities that we run

Possible sources of debug messages:

 - libguestfs : can be redirected using event callbacks

 - virt-v2v : always go to stderr, see Tools_utils.debug

 - nbdkit : always go to stderr

 - nbdcopy : always go to stderr, but we don't enable them unless
   you edit the virt-v2v source

In the past we tried to do "structured messages", see the --machine-readable
option.  TBH it was a failed experiment.  It's hard to do it from virt-v2v
because of all the different sources of messages, and it's doubly hard for
consumers because they end up having to do complex parsing stuff.  Most
consumers of virt-v2v want logs to go to a file and not to have to worry
about it beyond that.  The current --machine-readable=format option doesn't work
properly and should be removed to save people from trying to use it.

I think the big disconnect here is that we are trying to produce message streams that address different audiences at the same time.

Most utilities (outside of the v2v space) allow the user to change the log level, but then the user gets *everything* in one big sequence. That means:

- if the "user" is a developer, they run the tool at DEBUG most of the time, they get all messages (which they understand), so OK

- if the "user" is a customer, they run the tool at ERROR; they only get grave error messages. Possibly they run the tool at INFO, so they get INFO and ERROR (which they still understand), so OK

- if the "user" is a customer and encounter a problem, they ratchet the log level to DEBUG; they get all messages in one big sequence, but that's fine, as they won't try to understand it (they already have a problem they're asking for help with), they just send the captured log to the developers.

Additionally, *all* diagnostics (fine-tuned as described above) go to stderr (or syslog, or to a file), regardless of the log level configured, and stdin/stdout is only used for *data processing*.

This is how most tools work in practice, in my experience.

With virt-p2v in particular, we're trying to do something very different. We want to address multiple audiences with different log messages in a single invocation of the tool (i.e., as part of a single conversion). At the same time, we still send both debug and error messages to stderr, which is much more appropriate for the other approach (see above). We can't run p2v / v2v at ERROR level only, because if something goes wrong, the customer will have to rerun the conversion just to collect DEBUG and upwards messages, and that's very inconvenient for the customer. So we run basically at DEBUG by default, but that's too noisy for the customer most of the time. Furthermore, we output some messages to stdout, even though I'd call stdout whole-sale inappropriate for diagnostics. I figure stdout may be an attempt to separate the "audiences" (but not a very successful one).

We should
- never print anything to stdout,
- send INFO and ERROR to stderr,
- if debug capture is enabled, send DEBUG, INFO and ERROR to a separate file descriptor. In this mode, INFO and ERROR would be duplicated to stderr and the separate file descriptor.

Now, about specifying the separate file descriptor... It should be done with a new command line option. And, if -v and/or -x are present on the command line, but the new option is absent, we should forcibly redirect the debug capture to a regular file we'd create. I've not seen a single case where the huge dump produced by -v and/or -x was useful *in a terminal*.

In the virt-p2v case, virt-v2v's stderr (with INFO and ERROR messages) would be shown in the virt-p2v window, while the full debug log (written to the other file descriptor) would be redirected to a regular file on the conversion server.

Virt-v2v isn't doing data processing like sort(1) so I don't understand why:

> - never print anything to stdout,

Plenty of programs produce informational status on stdout, eg (picking
one at random) "systemctl status".  And then:

> - send INFO and ERROR to stderr,

which is sending non-errors to stderr, not as bad as sending errors
to stdout (hello, Python programs), but still.

We can send normal (INFO) messages to stdout and ERROR to stderr
and virt-p2v will be happy.

I do though think we probably need an extra file descriptor or file
which would get INFO + ERROR + DEBUG.  Hence my comment above about
"We actually need at least three streams to do this properly".

Implementing this is a pain in the rear.

OK.

See also:
https://listman.redhat.com/archives/libguestfs/2022-September/029805.html