Libguestfs - Aug 2018 - [PATCH nbdkit] tests: Adjust test-fua.sh for correct use .prepare in log filter.

Commit b5ce88e889a2df4baa0b73033f7302e5b40f0570 fixed the cases where
multiple filters are placed in front of a plugin, so that now .prepare
and .finalize methods are called properly in the second and subsequent
filters.

This causes an additional log message to be emitted (correctly) from
the newly called .prepare method in the log filter:

  2018-08-01 15:17:45.249533 connection=1 Connect [...]

However this extra log message incidentally breaks the FUA test.

Fix this by filtering out the additional log message before counting
the instances of the fua=1 flag in this test.

Thanks: Eric Blake.
---
 tests/test-fua.sh | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tests/test-fua.sh b/tests/test-fua.sh
index 8a8c7fc..0329807 100755
--- a/tests/test-fua.sh
+++ b/tests/test-fua.sh
@@ -132,14 +132,14 @@ test $(grep -c 'connection=1 Flush' fua1.log) -lt
\
 # all earlier parts of the transaction do not have fua
 flush1=$(grep -c 'connection=1 Flush' fua2.log || :)
 flush2=$(grep -c 'connection=2 Flush' fua2.log || :)
-fua=$(grep -c 'connection=2.*fua=1' fua2.log || :)
+fua=$(grep -v "Connect" fua2.log | grep -c
'connection=2.*fua=1' || :)
 test $(( $flush2 - $flush1 + $fua )) = 2
 
 # Test 3: every part of split has fua, and no flushes are added
 flush1=$(grep -c 'connection=1 Flush' fua3.log || :)
 flush2=$(grep -c 'connection=2 Flush' fua3.log || :)
 test $flush1 = $flush2
-test $(grep -c 'connection=2.*fua=1' fua3.log) = 32
+test $(grep -v "Connect" fua3.log | grep -c
'connection=2.*fua=1') = 32
 
 # Test 4: flush is no-op, and every transaction has fua
 if grep 'fua=0' fua4.log; then
-- 
2.18.0

On 08/01/2018 10:21 AM, Richard W.M. Jones wrote:
> Commit b5ce88e889a2df4baa0b73033f7302e5b40f0570 fixed the cases where
> multiple filters are placed in front of a plugin, so that now .prepare
> and .finalize methods are called properly in the second and subsequent
> filters.
> 
> This causes an additional log message to be emitted (correctly) from
> the newly called .prepare method in the log filter:
> 
>    2018-08-01 15:17:45.249533 connection=1 Connect [...]
> 
> However this extra log message incidentally breaks the FUA test.
> 
> Fix this by filtering out the additional log message before counting
> the instances of the fua=1 flag in this test.
> 
> Thanks: Eric Blake.
> ---
>   tests/test-fua.sh | 4 ++--
>   1 file changed, 2 insertions(+), 2 deletions(-)
I did something similar, but with fewer processes and therefore a 
slightly smaller change:

I'll go ahead and push mine, since we both see the issue.

 From c50e60f66ca5b6b0e0bb572551cd56ef29cd0904 Mon Sep 17 00:00:00 2001
From: Eric Blake <eblake@redhat.com>
Date: Wed, 1 Aug 2018 10:43:03 -0500
Subject: [nbdkit PATCH] tests: Adjust test-fua.sh for fixed multi-filter
  output

Commit b5ce88e8 fixed the cases where multiple filters in front
of a plugin did not all have their .prepare callback utilized,
which (correctly) results in more output from the log filter.
Adjust the grep of the test output for FUA to not be confused by
those extra lines.

Signed-off-by: Eric Blake <eblake@redhat.com>
---
  tests/test-fua.sh | 4 ++--
  1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tests/test-fua.sh b/tests/test-fua.sh
index 8a8c7fc..22e0fa6 100755
--- a/tests/test-fua.sh
+++ b/tests/test-fua.sh
@@ -132,14 +132,14 @@ test $(grep -c 'connection=1 Flush' fua1.log) -lt
\
  # all earlier parts of the transaction do not have fua
  flush1=$(grep -c 'connection=1 Flush' fua2.log || :)
  flush2=$(grep -c 'connection=2 Flush' fua2.log || :)
-fua=$(grep -c 'connection=2.*fua=1' fua2.log || :)
+fua=$(grep -c 'connection=2.*fua=1 \.' fua2.log || :)
  test $(( $flush2 - $flush1 + $fua )) = 2

  # Test 3: every part of split has fua, and no flushes are added
  flush1=$(grep -c 'connection=1 Flush' fua3.log || :)
  flush2=$(grep -c 'connection=2 Flush' fua3.log || :)
  test $flush1 = $flush2
-test $(grep -c 'connection=2.*fua=1' fua3.log) = 32
+test $(grep -c 'connection=2.*fua=1 \.' fua3.log) = 32

  # Test 4: flush is no-op, and every transaction has fua
  if grep 'fua=0' fua4.log; then
-- 
2.14.4

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org

On Wed, Aug 01, 2018 at 10:48:26AM -0500, Eric Blake
wrote:
> On 08/01/2018 10:21 AM, Richard W.M. Jones wrote:
> >Commit b5ce88e889a2df4baa0b73033f7302e5b40f0570 fixed the cases where
> >multiple filters are placed in front of a plugin, so that now .prepare
> >and .finalize methods are called properly in the second and subsequent
> >filters.
> >
> >This causes an additional log message to be emitted (correctly) from
> >the newly called .prepare method in the log filter:
> >
> >   2018-08-01 15:17:45.249533 connection=1 Connect [...]
> >
> >However this extra log message incidentally breaks the FUA test.
> >
> >Fix this by filtering out the additional log message before counting
> >the instances of the fua=1 flag in this test.
> >
> >Thanks: Eric Blake.
> >---
> >  tests/test-fua.sh | 4 ++--
> >  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> I did something similar, but with fewer processes and therefore a
> slightly smaller change:
> 
> I'll go ahead and push mine, since we both see the issue.
Can confirm this fixes it too, thanks.

Rich.
> From c50e60f66ca5b6b0e0bb572551cd56ef29cd0904 Mon Sep 17 00:00:00 2001
> From: Eric Blake <eblake@redhat.com>
> Date: Wed, 1 Aug 2018 10:43:03 -0500
> Subject: [nbdkit PATCH] tests: Adjust test-fua.sh for fixed multi-filter
>  output
> 
> Commit b5ce88e8 fixed the cases where multiple filters in front
> of a plugin did not all have their .prepare callback utilized,
> which (correctly) results in more output from the log filter.
> Adjust the grep of the test output for FUA to not be confused by
> those extra lines.
> 
> Signed-off-by: Eric Blake <eblake@redhat.com>
> ---
>  tests/test-fua.sh | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/tests/test-fua.sh b/tests/test-fua.sh
> index 8a8c7fc..22e0fa6 100755
> --- a/tests/test-fua.sh
> +++ b/tests/test-fua.sh
> @@ -132,14 +132,14 @@ test $(grep -c 'connection=1 Flush' fua1.log)
-lt \
>  # all earlier parts of the transaction do not have fua
>  flush1=$(grep -c 'connection=1 Flush' fua2.log || :)
>  flush2=$(grep -c 'connection=2 Flush' fua2.log || :)
> -fua=$(grep -c 'connection=2.*fua=1' fua2.log || :)
> +fua=$(grep -c 'connection=2.*fua=1 \.' fua2.log || :)
>  test $(( $flush2 - $flush1 + $fua )) = 2
> 
>  # Test 3: every part of split has fua, and no flushes are added
>  flush1=$(grep -c 'connection=1 Flush' fua3.log || :)
>  flush2=$(grep -c 'connection=2 Flush' fua3.log || :)
>  test $flush1 = $flush2
> -test $(grep -c 'connection=2.*fua=1' fua3.log) = 32
> +test $(grep -c 'connection=2.*fua=1 \.' fua3.log) = 32
> 
>  # Test 4: flush is no-op, and every transaction has fua
>  if grep 'fua=0' fua4.log; then
> -- 
> 2.14.4
> 
> -- 
> Eric Blake, Principal Software Engineer
> Red Hat, Inc.           +1-919-301-3266
> Virtualization:  qemu.org | libvirt.org
-- 
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
virt-top is 'top' for virtual machines.  Tiny program with many
powerful monitoring features, net stats, disk stats, logging, etc.
http://people.redhat.com/~rjones/virt-top