[PATCH] test-virt-tail: Fix failing cat/test-virt-tail.sh test case
From IRC channel:
<StenaviN> Can someone confirm cat/test-virt-tail.sh works in 'master'? <StenaviN> I get https://pastebin.com/GBkg7Vtw <rwmjones> StenaviN: yes it works for me; the error is not very helpful, you'll need to set LIBGUESTFS_DEBUG=1 LIBGUESTFS_TRACE=1 <StenaviN> https://pastebin.com/yABgCHwV <rwmjones> I think the error is: <rwmjones> libguestfs: trace: statns "/tail" <rwmjones> guestfsd: => mount_options (0x4a) took 0.00 secs <rwmjones> guestfsd: <= statns (0x1a5) request length 52 bytes <rwmjones> [ 0.930738] EXT2-fs (sda1): error: ext2_lookup: deleted inode referenced: 12 <rwmjones> guestfsd: error: /tail: Input/output error <rwmjones> but I don't know exactly why <StenaviN> Yes, I see. Trying to figure out... <rwmjones> actually no, that's not the problem <rwmjones> for some reason two instances of ‘guestfish --remote exit’ run at the same time, but according to the test script only one should run <rwmjones> notice how the cleanup() function is called twice <rwmjones> afaik that should never happen <StenaviN> and I saw two qemu/guestfish processes running. Continue investigating... And here is what I found: Second copy of 'guestfish --listen' process is a child "recovery process" ( https://github.com/libguestfs/libguestfs/blob/master/lib/launch-direct.c#L77...) and that is OK. 'cleanup' was called twice because: 1. call to virt-tail returns non-zero exit code (due to Input/Output error. About this later.) and we trap ERR signal which cause to run 'cleanup' once 2. in 'cleanup' we do 'exit $statuscode' and we trap EXIT and 'cleanup' is called once again It might look confusing but not end of the life. At least there is an explanation if I didn't miss something. Now about failing test case with virt-tail. Jumping ahead, adding extra 'guestfish --remote sync' after 'guestfish --remote rm /tail' in 'cat/test-virt-tail.sh' fixes the test case. virt-tail re-creates overlay image each time it trying to access the file and calls guestfs_statns for the file(s) it watching. guestfs_statns in turn returns NULL indicating an error with exit code EIO instead of ENOENT: 'EXT2-fs (sda1): error: ext2_lookup: deleted inode referenced: 12'. (see pastebin posted in discussion above). So I suspect that changes on original disk made through 'guestfish --remote rm /tail' call were not fully flushed which confirms by proposed patch. It is hard to explain why it works on your system but it might be because of number of factors: 1. Different QEMU caching policy 2. Different caching policy of underlying OS/filesytem 3. etc. -- Nikolay Ivanets Mobile: +380979184774 Skype: n_ivanets
According to http://libguestfs.org/guestfs.3.html#guestfs_sync "You should always call this if you have modified a disk image, before closing the handle." So, I think 'guestfish --remote sync' is required because changes made on the disk (guestfish --remote rm /tail) should be visible to virt-tail which works in different process and also accessing the same disk. -- Nikolay Ivanets Mobile: +380979184774 Skype: n_ivanets 2018-01-03 9:06 GMT+02:00 Nikolay Ivanets <stenavin@gmail.com>:
From IRC channel:
<StenaviN> Can someone confirm cat/test-virt-tail.sh works in 'master'? <StenaviN> I get https://pastebin.com/GBkg7Vtw <rwmjones> StenaviN: yes it works for me; the error is not very helpful, you'll need to set LIBGUESTFS_DEBUG=1 LIBGUESTFS_TRACE=1 <StenaviN> https://pastebin.com/yABgCHwV <rwmjones> I think the error is: <rwmjones> libguestfs: trace: statns "/tail" <rwmjones> guestfsd: => mount_options (0x4a) took 0.00 secs <rwmjones> guestfsd: <= statns (0x1a5) request length 52 bytes <rwmjones> [ 0.930738] EXT2-fs (sda1): error: ext2_lookup: deleted inode referenced: 12 <rwmjones> guestfsd: error: /tail: Input/output error <rwmjones> but I don't know exactly why <StenaviN> Yes, I see. Trying to figure out... <rwmjones> actually no, that's not the problem <rwmjones> for some reason two instances of ‘guestfish --remote exit’ run at the same time, but according to the test script only one should run <rwmjones> notice how the cleanup() function is called twice <rwmjones> afaik that should never happen <StenaviN> and I saw two qemu/guestfish processes running. Continue investigating...
And here is what I found:
Second copy of 'guestfish --listen' process is a child "recovery process" ( https://github.com/libguestfs/libguestfs/blob/master/lib/launch-direct.c# L777) and that is OK.
'cleanup' was called twice because: 1. call to virt-tail returns non-zero exit code (due to Input/Output error. About this later.) and we trap ERR signal which cause to run 'cleanup' once 2. in 'cleanup' we do 'exit $statuscode' and we trap EXIT and 'cleanup' is called once again It might look confusing but not end of the life. At least there is an explanation if I didn't miss something.
Now about failing test case with virt-tail. Jumping ahead, adding extra 'guestfish --remote sync' after 'guestfish --remote rm /tail' in 'cat/test-virt-tail.sh' fixes the test case. virt-tail re-creates overlay image each time it trying to access the file and calls guestfs_statns for the file(s) it watching. guestfs_statns in turn returns NULL indicating an error with exit code EIO instead of ENOENT: 'EXT2-fs (sda1): error: ext2_lookup: deleted inode referenced: 12'. (see pastebin posted in discussion above).
So I suspect that changes on original disk made through 'guestfish --remote rm /tail' call were not fully flushed which confirms by proposed patch. It is hard to explain why it works on your system but it might be because of number of factors: 1. Different QEMU caching policy 2. Different caching policy of underlying OS/filesytem 3. etc.
-- Nikolay Ivanets Mobile: +380979184774 <097%20918%204774> Skype: n_ivanets
On Wednesday, 3 January 2018 08:06:38 CET Nikolay Ivanets wrote:
From IRC channel:
<StenaviN> Can someone confirm cat/test-virt-tail.sh works in 'master'? <StenaviN> I get https://pastebin.com/GBkg7Vtw <rwmjones> StenaviN: yes it works for me; the error is not very helpful, you'll need to set LIBGUESTFS_DEBUG=1 LIBGUESTFS_TRACE=1 <StenaviN> https://pastebin.com/yABgCHwV <rwmjones> I think the error is: <rwmjones> libguestfs: trace: statns "/tail" <rwmjones> guestfsd: => mount_options (0x4a) took 0.00 secs <rwmjones> guestfsd: <= statns (0x1a5) request length 52 bytes <rwmjones> [ 0.930738] EXT2-fs (sda1): error: ext2_lookup: deleted inode referenced: 12 <rwmjones> guestfsd: error: /tail: Input/output error <rwmjones> but I don't know exactly why <StenaviN> Yes, I see. Trying to figure out... <rwmjones> actually no, that's not the problem <rwmjones> for some reason two instances of ‘guestfish --remote exit’ run at the same time, but according to the test script only one should run <rwmjones> notice how the cleanup() function is called twice <rwmjones> afaik that should never happen <StenaviN> and I saw two qemu/guestfish processes running. Continue investigating...
And here is what I found:
Second copy of 'guestfish --listen' process is a child "recovery process" ( https://github.com/libguestfs/libguestfs/blob/master/lib/launch-direct.c#L77...) and that is OK.
'cleanup' was called twice because: 1. call to virt-tail returns non-zero exit code (due to Input/Output error. About this later.) and we trap ERR signal which cause to run 'cleanup' once 2. in 'cleanup' we do 'exit $statuscode' and we trap EXIT and 'cleanup' is called once again It might look confusing but not end of the life. At least there is an explanation if I didn't miss something.
Now about failing test case with virt-tail. Jumping ahead, adding extra 'guestfish --remote sync' after 'guestfish --remote rm /tail' in 'cat/test-virt-tail.sh' fixes the test case. virt-tail re-creates overlay image each time it trying to access the file and calls guestfs_statns for the file(s) it watching. guestfs_statns in turn returns NULL indicating an error with exit code EIO instead of ENOENT: 'EXT2-fs (sda1): error: ext2_lookup: deleted inode referenced: 12'. (see pastebin posted in discussion above).
So I suspect that changes on original disk made through 'guestfish --remote rm /tail' call were not fully flushed which confirms by proposed patch. It is hard to explain why it works on your system but it might be because of number of factors: 1. Different QEMU caching policy 2. Different caching policy of underlying OS/filesytem 3. etc.
I agree with your investigation (which is good, thanks for doing it). Indeed, other changes done via `guestfish --remote` in that tests are flushed via a 'sync' command, so it makes sense for the 'rm /tail' one to be flushed in a similar way. Can you please write a bit more details in the commit message itself, so it is easier to check/inspect later on why the change was done? Thanks, -- Pino Toscano
According to 'guestfs_sync' API method documentation: "You should always call this if you have modified a disk image, before closing the handle." So, 'guestfish --remote sync' is required because changes made on the disk (guestfish --remote rm /tail) should be visible to 'virt-tail' which works in different process and also accessing the same disk. A you can see, other changes done via 'guestfish --remote' in this test are flushed via a 'sync' command. The test is failing spontaneously beasue without 'sync' it very depends on outside factors like qemu caching policy, underlying host filesystem etc. --- cat/test-virt-tail.sh | 1 + 1 file changed, 1 insertion(+) diff --git a/cat/test-virt-tail.sh b/cat/test-virt-tail.sh index 47a5edc..c091eaf 100755 --- a/cat/test-virt-tail.sh +++ b/cat/test-virt-tail.sh @@ -101,6 +101,7 @@ fi # Delete the file. This should cause virt-tail to exit gracefully. guestfish --remote rm /tail +guestfish --remote sync # Wait for virt-tail to finish and check the status. wait "$tailpid" -- 2.9.5
Thanks, I pushed this. Rich. -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com virt-builder quickly builds VMs from scratch http://libguestfs.org/virt-builder.1.html
participants (4)
-
Mykola Ivanets -
Nikolay Ivanets
-
Pino Toscano -
Richard W.M. Jones