Re: [Qemu-devel] [PATCH v4 4/4] iotests: use python logging for iotests.log()
On 9/17/19 7:35 AM, Vladimir Sementsov-Ogievskiy wrote:
> 12.09.2019 3:16, John Snow wrote:
>> We can turn logging on/off globally instead of per-function.
>>
>> Remove use_log from run_job, and use python logging to turn on
>> diffable output when we run through a script entry point.
>>
>> iotest 245 changes output order due to buffering reasons.
>>
>> Signed-off-by: John Snow
>> ---
>> tests/qemu-iotests/030| 4 +--
>> tests/qemu-iotests/245| 1 +
>> tests/qemu-iotests/245.out| 24 +-
>> tests/qemu-iotests/iotests.py | 47 +--
>> 4 files changed, 43 insertions(+), 33 deletions(-)
>>
>> diff --git a/tests/qemu-iotests/030 b/tests/qemu-iotests/030
>> index f3766f2a81..01aa96ed16 100755
>> --- a/tests/qemu-iotests/030
>> +++ b/tests/qemu-iotests/030
>> @@ -411,8 +411,8 @@ class TestParallelOps(iotests.QMPTestCase):
>> result = self.vm.qmp('block-job-set-speed', device='drive0',
>> speed=0)
>> self.assert_qmp(result, 'return', {})
>>
>> -self.vm.run_job(job='drive0', auto_dismiss=True, use_log=False)
>> -self.vm.run_job(job='node4', auto_dismiss=True, use_log=False)
>> +self.vm.run_job(job='drive0', auto_dismiss=True)
>> +self.vm.run_job(job='node4', auto_dismiss=True)
>> self.assert_no_active_block_jobs()
>>
>> # Test a block-stream and a block-commit job in parallel
>> diff --git a/tests/qemu-iotests/245 b/tests/qemu-iotests/245
>> index 41218d5f1d..eba2157cff 100644
>> --- a/tests/qemu-iotests/245
>> +++ b/tests/qemu-iotests/245
>> @@ -1000,5 +1000,6 @@ class TestBlockdevReopen(iotests.QMPTestCase):
>> self.reopen(opts, {'backing': 'hd2'})
>>
>> if __name__ == '__main__':
>> +iotests.activate_logging()
>
> or it may be a parameter for main().. But I'm OK with this too, of course.
>
I think most of the unittest style tests don't need or want logged
output in this way, but we can always do it later if we want.
>> iotests.main(supported_fmts=["qcow2"],
>>supported_protocols=["file"])
>> diff --git a/tests/qemu-iotests/245.out b/tests/qemu-iotests/245.out
>> index a19de5214d..15c3630e92 100644
>> --- a/tests/qemu-iotests/245.out
>> +++ b/tests/qemu-iotests/245.out
>> @@ -1,17 +1,17 @@
>> +{"execute": "job-finalize", "arguments": {"id": "commit0"}}
>> +{"return": {}}
>> +{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING",
>> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
>> +{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed":
>> 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
>> {"microseconds": "USECS", "seconds": "SECS"}}
>> +{"execute": "job-finalize", "arguments": {"id": "stream0"}}
>> +{"return": {}}
>> +{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
>> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
>> +{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed":
>> 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
>> {"microseconds": "USECS", "seconds": "SECS"}}
>> +{"execute": "job-finalize", "arguments": {"id": "stream0"}}
>> +{"return": {}}
>> +{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
>> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
>> +{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed":
>> 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
>> {"microseconds": "USECS", "seconds": "SECS"}}
>> ..
>> --
>> Ran 18 tests
>>
>> OK
>> -{"execute": "job-finalize", "arguments": {"id": "commit0"}}
>> -{"return": {}}
>> -{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING",
>> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
>> -{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed":
>> 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
>> {"microseconds": "USECS", "seconds": "SECS"}}
>> -{"execute": "job-finalize", "arguments": {"id": "stream0"}}
>> -{"return": {}}
>> -{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
>> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
>> -{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed":
>> 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
>> {"microseconds": "USECS", "seconds": "SECS"}}
>> -{"execute": "job-finalize", "arguments": {"id": "stream0"}}
>> -{"return": {}}
>> -{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
>> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
>> -{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed":
>> 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
>> {"microseconds": "USECS",
Re: [Qemu-devel] [PATCH v4 4/4] iotests: use python logging for iotests.log()
12.09.2019 3:16, John Snow wrote:
> We can turn logging on/off globally instead of per-function.
>
> Remove use_log from run_job, and use python logging to turn on
> diffable output when we run through a script entry point.
>
> iotest 245 changes output order due to buffering reasons.
>
> Signed-off-by: John Snow
> ---
> tests/qemu-iotests/030| 4 +--
> tests/qemu-iotests/245| 1 +
> tests/qemu-iotests/245.out| 24 +-
> tests/qemu-iotests/iotests.py | 47 +--
> 4 files changed, 43 insertions(+), 33 deletions(-)
>
> diff --git a/tests/qemu-iotests/030 b/tests/qemu-iotests/030
> index f3766f2a81..01aa96ed16 100755
> --- a/tests/qemu-iotests/030
> +++ b/tests/qemu-iotests/030
> @@ -411,8 +411,8 @@ class TestParallelOps(iotests.QMPTestCase):
> result = self.vm.qmp('block-job-set-speed', device='drive0',
> speed=0)
> self.assert_qmp(result, 'return', {})
>
> -self.vm.run_job(job='drive0', auto_dismiss=True, use_log=False)
> -self.vm.run_job(job='node4', auto_dismiss=True, use_log=False)
> +self.vm.run_job(job='drive0', auto_dismiss=True)
> +self.vm.run_job(job='node4', auto_dismiss=True)
> self.assert_no_active_block_jobs()
>
> # Test a block-stream and a block-commit job in parallel
> diff --git a/tests/qemu-iotests/245 b/tests/qemu-iotests/245
> index 41218d5f1d..eba2157cff 100644
> --- a/tests/qemu-iotests/245
> +++ b/tests/qemu-iotests/245
> @@ -1000,5 +1000,6 @@ class TestBlockdevReopen(iotests.QMPTestCase):
> self.reopen(opts, {'backing': 'hd2'})
>
> if __name__ == '__main__':
> +iotests.activate_logging()
or it may be a parameter for main().. But I'm OK with this too, of course.
> iotests.main(supported_fmts=["qcow2"],
>supported_protocols=["file"])
> diff --git a/tests/qemu-iotests/245.out b/tests/qemu-iotests/245.out
> index a19de5214d..15c3630e92 100644
> --- a/tests/qemu-iotests/245.out
> +++ b/tests/qemu-iotests/245.out
> @@ -1,17 +1,17 @@
> +{"execute": "job-finalize", "arguments": {"id": "commit0"}}
> +{"return": {}}
> +{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING",
> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
> +{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed":
> 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
> {"microseconds": "USECS", "seconds": "SECS"}}
> +{"execute": "job-finalize", "arguments": {"id": "stream0"}}
> +{"return": {}}
> +{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
> +{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed":
> 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
> {"microseconds": "USECS", "seconds": "SECS"}}
> +{"execute": "job-finalize", "arguments": {"id": "stream0"}}
> +{"return": {}}
> +{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
> +{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed":
> 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
> {"microseconds": "USECS", "seconds": "SECS"}}
> ..
> --
> Ran 18 tests
>
> OK
> -{"execute": "job-finalize", "arguments": {"id": "commit0"}}
> -{"return": {}}
> -{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING",
> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
> -{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed":
> 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
> {"microseconds": "USECS", "seconds": "SECS"}}
> -{"execute": "job-finalize", "arguments": {"id": "stream0"}}
> -{"return": {}}
> -{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
> -{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed":
> 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
> {"microseconds": "USECS", "seconds": "SECS"}}
> -{"execute": "job-finalize", "arguments": {"id": "stream0"}}
> -{"return": {}}
> -{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
> "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
> -{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed":
> 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
> {"microseconds": "USECS", "seconds": "SECS"}}
> diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
> index 92117a64bc..7e46fb2754 100644
> --- a/tests/qemu-iotests/iotests.py
> +++ b/tests/qemu-iotests/iotests.py
> @@ -35,6 +35,13 @@ from collections import OrderedDict
>
[Qemu-devel] [PATCH v4 4/4] iotests: use python logging for iotests.log()
We can turn logging on/off globally instead of per-function.
Remove use_log from run_job, and use python logging to turn on
diffable output when we run through a script entry point.
iotest 245 changes output order due to buffering reasons.
Signed-off-by: John Snow
---
tests/qemu-iotests/030| 4 +--
tests/qemu-iotests/245| 1 +
tests/qemu-iotests/245.out| 24 +-
tests/qemu-iotests/iotests.py | 47 +--
4 files changed, 43 insertions(+), 33 deletions(-)
diff --git a/tests/qemu-iotests/030 b/tests/qemu-iotests/030
index f3766f2a81..01aa96ed16 100755
--- a/tests/qemu-iotests/030
+++ b/tests/qemu-iotests/030
@@ -411,8 +411,8 @@ class TestParallelOps(iotests.QMPTestCase):
result = self.vm.qmp('block-job-set-speed', device='drive0', speed=0)
self.assert_qmp(result, 'return', {})
-self.vm.run_job(job='drive0', auto_dismiss=True, use_log=False)
-self.vm.run_job(job='node4', auto_dismiss=True, use_log=False)
+self.vm.run_job(job='drive0', auto_dismiss=True)
+self.vm.run_job(job='node4', auto_dismiss=True)
self.assert_no_active_block_jobs()
# Test a block-stream and a block-commit job in parallel
diff --git a/tests/qemu-iotests/245 b/tests/qemu-iotests/245
index 41218d5f1d..eba2157cff 100644
--- a/tests/qemu-iotests/245
+++ b/tests/qemu-iotests/245
@@ -1000,5 +1000,6 @@ class TestBlockdevReopen(iotests.QMPTestCase):
self.reopen(opts, {'backing': 'hd2'})
if __name__ == '__main__':
+iotests.activate_logging()
iotests.main(supported_fmts=["qcow2"],
supported_protocols=["file"])
diff --git a/tests/qemu-iotests/245.out b/tests/qemu-iotests/245.out
index a19de5214d..15c3630e92 100644
--- a/tests/qemu-iotests/245.out
+++ b/tests/qemu-iotests/245.out
@@ -1,17 +1,17 @@
+{"execute": "job-finalize", "arguments": {"id": "commit0"}}
+{"return": {}}
+{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING",
"timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
+{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed": 0,
"type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
{"microseconds": "USECS", "seconds": "SECS"}}
+{"execute": "job-finalize", "arguments": {"id": "stream0"}}
+{"return": {}}
+{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
"timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
+{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0,
"type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
{"microseconds": "USECS", "seconds": "SECS"}}
+{"execute": "job-finalize", "arguments": {"id": "stream0"}}
+{"return": {}}
+{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
"timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
+{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0,
"type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
{"microseconds": "USECS", "seconds": "SECS"}}
..
--
Ran 18 tests
OK
-{"execute": "job-finalize", "arguments": {"id": "commit0"}}
-{"return": {}}
-{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING",
"timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
-{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed": 0,
"type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
{"microseconds": "USECS", "seconds": "SECS"}}
-{"execute": "job-finalize", "arguments": {"id": "stream0"}}
-{"return": {}}
-{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
"timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
-{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0,
"type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
{"microseconds": "USECS", "seconds": "SECS"}}
-{"execute": "job-finalize", "arguments": {"id": "stream0"}}
-{"return": {}}
-{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING",
"timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
-{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0,
"type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp":
{"microseconds": "USECS", "seconds": "SECS"}}
diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index 92117a64bc..7e46fb2754 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -35,6 +35,13 @@ from collections import OrderedDict
sys.path.append(os.path.join(os.path.dirname(__file__), '..', '..', 'python'))
from qemu import qtest
+# Use this logger for logging messages directly from the iotests module
+logger = logging.getLogger(__name__)
+logger.addHandler(logging.NullHandler())
+
+# Use this logger for messages that ought to be used for diff output.
+test_logger =
