[PATCH] selftests: ublk: mark each test start and end time in dmesg

[PATCH] selftests: ublk: mark each test start and end time in dmesg

[Alexander Atanasov]

Log test start and end time in dmesg, so generated log messages
during the test run can be linked to specific test from the test
suite.

Signed-off-by: Alexander Atanasov <alex@zazolabs.com>
---
 tools/testing/selftests/ublk/test_common.sh | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/tools/testing/selftests/ublk/test_common.sh b/tools/testing/selftests/ublk/test_common.sh
index ab1ea5cc904a..5865f1e640ce 100755
--- a/tools/testing/selftests/ublk/test_common.sh
+++ b/tools/testing/selftests/ublk/test_common.sh
@@ -122,6 +122,7 @@ _prep_test() {
 	modprobe ublk_drv > /dev/null 2>&1
 	UBLK_TMP=$(mktemp $TMPDIR/ublk_test_XXXXX)
 	[ "$UBLK_TEST_QUIET" -eq 0 ] && echo "ublk $type: $*"
+	echo "ublk selftest: $TID starting at $(date --iso-8601=sec)" | tee /dev/kmsg
 }
 
 _remove_test_files()
@@ -166,6 +167,7 @@ _cleanup_test() {
 	"${UBLK_PROG}" del -a
 
 	_remove_files
+	echo "ublk selftest: $TID done at $(date --iso-8601=sec)" | tee /dev/kmsg
 }
 
 _have_feature()
-- 
2.43.0

Re: [PATCH] selftests: ublk: mark each test start and end time in dmesg

[Ming Lei]

On Mon, Jan 26, 2026 at 11:25:44AM +0000, Alexander Atanasov wrote:
> Log test start and end time in dmesg, so generated log messages
> during the test run can be linked to specific test from the test
> suite.
> 
> Signed-off-by: Alexander Atanasov <alex@zazolabs.com>
> ---
>  tools/testing/selftests/ublk/test_common.sh | 2 ++
>  1 file changed, 2 insertions(+)
> 
> diff --git a/tools/testing/selftests/ublk/test_common.sh b/tools/testing/selftests/ublk/test_common.sh
> index ab1ea5cc904a..5865f1e640ce 100755
> --- a/tools/testing/selftests/ublk/test_common.sh
> +++ b/tools/testing/selftests/ublk/test_common.sh
> @@ -122,6 +122,7 @@ _prep_test() {
>  	modprobe ublk_drv > /dev/null 2>&1
>  	UBLK_TMP=$(mktemp $TMPDIR/ublk_test_XXXXX)
>  	[ "$UBLK_TEST_QUIET" -eq 0 ] && echo "ublk $type: $*"
> +	echo "ublk selftest: $TID starting at $(date --iso-8601=sec)" | tee /dev/kmsg
>  }
>  
>  _remove_test_files()
> @@ -166,6 +167,7 @@ _cleanup_test() {
>  	"${UBLK_PROG}" del -a
>  
>  	_remove_files
> +	echo "ublk selftest: $TID done at $(date --iso-8601=sec)" | tee /dev/kmsg

This patch is one nice improvement!

But it can't be applied cleanly on block/for-7.0/block, can you base it
against for-7.0/block branch of block tree?

https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux.git/log/?h=for-7.0/block

```
[root@ktest-40 linux]# git am raw.16
Applying: selftests: ublk: mark each test start and end time in dmesg
error: patch failed: tools/testing/selftests/ublk/test_common.sh:122
error: tools/testing/selftests/ublk/test_common.sh: patch does not apply
Patch failed at 0001 selftests: ublk: mark each test start and end time in dmesg
hint: Use 'git am --show-current-patch=diff' to see the failed patch
hint: When you have resolved this problem, run "git am --continue".
hint: If you prefer to skip this patch, run "git am --skip" instead.
hint: To restore the original branch and stop patching, run "git am --abort".
hint: Disable this message with "git config advice.mergeConflict false"
```


Thanks,
Ming

Re: [PATCH] selftests: ublk: mark each test start and end time in dmesg

[Ming Lei]

On Mon, Jan 26, 2026 at 11:25:44AM +0000, Alexander Atanasov wrote:
> Log test start and end time in dmesg, so generated log messages
> during the test run can be linked to specific test from the test
> suite.
> 
> Signed-off-by: Alexander Atanasov <alex@zazolabs.com>
> ---
>  tools/testing/selftests/ublk/test_common.sh | 2 ++
>  1 file changed, 2 insertions(+)
> 
> diff --git a/tools/testing/selftests/ublk/test_common.sh b/tools/testing/selftests/ublk/test_common.sh
> index ab1ea5cc904a..5865f1e640ce 100755
> --- a/tools/testing/selftests/ublk/test_common.sh
> +++ b/tools/testing/selftests/ublk/test_common.sh
> @@ -122,6 +122,7 @@ _prep_test() {
>  	modprobe ublk_drv > /dev/null 2>&1
>  	UBLK_TMP=$(mktemp $TMPDIR/ublk_test_XXXXX)
>  	[ "$UBLK_TEST_QUIET" -eq 0 ] && echo "ublk $type: $*"
> +	echo "ublk selftest: $TID starting at $(date --iso-8601=sec)" | tee /dev/kmsg
>  }
>  
>  _remove_test_files()
> @@ -166,6 +167,7 @@ _cleanup_test() {
>  	"${UBLK_PROG}" del -a
>  
>  	_remove_files
> +	echo "ublk selftest: $TID done at $(date --iso-8601=sec)" | tee /dev/kmsg
>  }

Also `date "+%F %T"`(which is taken by blktests project) looks more readable, such as:

[root@ktest-40 blktests]# date "+%F %T"
2026-01-26 14:00:51
[root@ktest-40 blktests]# date --iso-8601=sec
2026-01-26T14:01:54+00:00

So would you like to consider it too?



Thanks,
Ming

Re: [PATCH] selftests: ublk: mark each test start and end time in dmesg

[Alexander Atanasov]

On 26.01.26 16:03, Ming Lei wrote:
> On Mon, Jan 26, 2026 at 11:25:44AM +0000, Alexander Atanasov wrote:
>> Log test start and end time in dmesg, so generated log messages
>> during the test run can be linked to specific test from the test
>> suite.

[snip]

>>   _remove_test_files()
>> @@ -166,6 +167,7 @@ _cleanup_test() {
>>   	"${UBLK_PROG}" del -a
>>   
>>   	_remove_files
>> +	echo "ublk selftest: $TID done at $(date --iso-8601=sec)" | tee /dev/kmsg
>>   }
> 
> Also `date "+%F %T"`(which is taken by blktests project) looks more readable, such as:
> 
> [root@ktest-40 blktests]# date "+%F %T"
> 2026-01-26 14:00:51
> [root@ktest-40 blktests]# date --iso-8601=sec
> 2026-01-26T14:01:54+00:00
> 
> So would you like to consider it too?

I saw this a bit late. I choose iso-8601=sec since it is mid ground 
between readable and reliable to parse. But if other test use +%F +%T 
i'll cook a v3 with it, no point to deviate.