[PATCH 0/3] iotests: enable logging prior to notrun() invocation

[PATCH 0/3] iotests: enable logging prior to notrun() invocation

[John Snow]

Hi, you can take just patch 1. patches 2-3 admittedly don't do a whole
heck of a lot, because I didn't realize that ./check discards *all*
output from either stdout or stderr.

The changes are tiny, though, and maybe still worth doing in the long
run? Hm. They are archived on the list now, anyway.

--js

John Snow (3):
  iotests: log messages from notrun()
  iotests: log to stderr instead of stdout
  iotests: Categorize NOTRUN messages as INFO, not WARNING

 tests/qemu-iotests/iotests.py | 17 ++++++++++-------
 1 file changed, 10 insertions(+), 7 deletions(-)

-- 
2.21.1

[PATCH 1/3] iotests: log messages from notrun()

[John Snow]

Shift the logging initialization up to occur prior to validation checks,
so that notrun() messages still get printed to console.

(Also, remove the "debugging messages active" message, because we don't
need to see that hundreds of times per iotest suite run.)

Signed-off-by: John Snow <jsnow@redhat.com>
---
 tests/qemu-iotests/iotests.py | 11 +++++------
 1 file changed, 5 insertions(+), 6 deletions(-)

diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index 6c0e781af7..1caa7812de 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -1168,18 +1168,17 @@ def execute_setup_common(supported_fmts: Sequence[str] = (),
         sys.stderr.write('Please run this test via the "check" script\n')
         sys.exit(os.EX_USAGE)
 
+    debug = '-d' in sys.argv
+    if debug:
+        sys.argv.remove('-d')
+    logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN))
+
     _verify_image_format(supported_fmts, unsupported_fmts)
     _verify_protocol(supported_protocols, unsupported_protocols)
     _verify_platform(supported=supported_platforms)
     _verify_cache_mode(supported_cache_modes)
     _verify_aio_mode(supported_aio_modes)
 
-    debug = '-d' in sys.argv
-    if debug:
-        sys.argv.remove('-d')
-    logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN))
-    logger.debug("iotests debugging messages active")
-
     return debug
 
 def execute_test(*args, test_function=None, **kwargs):
-- 
2.21.1

[PATCH 2/3] iotests: log to stderr instead of stdout

[John Snow]

Separate the streams; stdout is for test diff output, stderr is for
control messages and things for the human to look at.

(Cough, unfortunately, I didn't realize that ./check actually just
always redirects both, so even on STDERR, you can't see warnings.
Oh well...)

Signed-off-by: John Snow <jsnow@redhat.com>
---
 tests/qemu-iotests/iotests.py | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index 1caa7812de..9231767acf 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -1171,7 +1171,11 @@ def execute_setup_common(supported_fmts: Sequence[str] = (),
     debug = '-d' in sys.argv
     if debug:
         sys.argv.remove('-d')
-    logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN))
+
+    logging.basicConfig(
+        level=logging.DEBUG if debug else logging.WARN,
+        stream=sys.stderr,
+    )
 
     _verify_image_format(supported_fmts, unsupported_fmts)
     _verify_protocol(supported_protocols, unsupported_protocols)
-- 
2.21.1

[PATCH 3/3] iotests: Categorize NOTRUN messages as INFO, not WARNING

[John Snow]

It's not really a warning; we don't want to see it if we're not running
in at least a verbose mode. We can see it on the test summary just fine.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 tests/qemu-iotests/iotests.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index 9231767acf..8e479e1c6f 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -986,7 +986,7 @@ def notrun(reason):
     seq = os.path.basename(sys.argv[0])
 
     open('%s/%s.notrun' % (output_dir, seq), 'w').write(reason + '\n')
-    logger.warning("%s not run: %s", seq, reason)
+    logger.info("%s not run: %s", seq, reason)
     sys.exit(0)
 
 def case_notrun(reason):
-- 
2.21.1

Re: [PATCH 0/3] iotests: enable logging prior to notrun() invocation

[Kevin Wolf]

Am 14.05.2020 um 22:16 hat John Snow geschrieben:
> Hi, you can take just patch 1.

Thanks, I'm doing that now.

> patches 2-3 admittedly don't do a whole heck of a lot, because I
> didn't realize that ./check discards *all* output from either stdout
> or stderr.

It doesn't discard it, but it compares it to the reference output and
prints a diff if it's non-empty.

At least for bash scripts, stderr contains important test output. Not
sure what the *_log() functions in iotests.py do, maybe they redirect
the stderr output from tools to stdout.

> The changes are tiny, though, and maybe still worth doing in the long
> run? Hm. They are archived on the list now, anyway.

We can still take these patches for a later pull request if you think we
should, though I'm not sure if they are useful given how things actually
work. I don't have a strong opinion either way (except that I don't want
to see more than a single line per test without -d, but these patches
don't try to do this even though you wrote them under the assumption
that this is how things work).

Kevin

Re: [PATCH 0/3] iotests: enable logging prior to notrun() invocation

[John Snow]

On 5/15/20 5:57 AM, Kevin Wolf wrote:
> Am 14.05.2020 um 22:16 hat John Snow geschrieben:
>> Hi, you can take just patch 1.
> 
> Thanks, I'm doing that now.
> 
>> patches 2-3 admittedly don't do a whole heck of a lot, because I
>> didn't realize that ./check discards *all* output from either stdout
>> or stderr.
> 
> It doesn't discard it, but it compares it to the reference output and
> prints a diff if it's non-empty.
> 

notrun cases do effectively discard that output, though. I guess that's
fine if it gets logged as output otherwise.

> At least for bash scripts, stderr contains important test output. Not
> sure what the *_log() functions in iotests.py do, maybe they redirect
> the stderr output from tools to stdout.
> 
>> The changes are tiny, though, and maybe still worth doing in the long
>> run? Hm. They are archived on the list now, anyway.
> 
> We can still take these patches for a later pull request if you think we
> should, though I'm not sure if they are useful given how things actually
> work. I don't have a strong opinion either way (except that I don't want
> to see more than a single line per test without -d, but these patches
> don't try to do this even though you wrote them under the assumption
> that this is how things work).
> 

Nah, it's fine. Bigger fish to fry. Thanks!