From: Petr Mladek <pmladek@suse.com>
To: Daniil Tatianin <d-tatianin@yandex-team.ru>
Cc: linux-kernel@vger.kernel.org,
Steven Rostedt <rostedt@goodmis.org>,
John Ogness <john.ogness@linutronix.de>,
Sergey Senozhatsky <senozhatsky@chromium.org>
Subject: Re: [PATCH v2 0/2] printk_ringbuffer: don't needlessly wrap data blocks around
Date: Thu, 11 Sep 2025 17:30:32 +0200 [thread overview]
Message-ID: <aMLrGCQSyC8odlFZ@pathway.suse.cz> (raw)
In-Reply-To: <20250905144152.9137-1-d-tatianin@yandex-team.ru>
On Fri 2025-09-05 17:41:50, Daniil Tatianin wrote:
> This series fixes the issue where data blocks would wrap in cases where the last
> data block perfectly fits the ring. This caused whatever was at the beginning of
> the ring to get discarded in this case, and the data block would get put there
> even though it could be put at the end of the data ring just fine without
> discarding anything.
>
> Fixing this issue also allows to simplify the check in data_check_size,
> previously it would ensure there's space for a trailing id, which we
> don't need anymore.
>
> v0->v1:
> - Fix severely broken code alignment
>
> v1->v2:
> - Rename & invert get_next_lpos -> is_blk_wrapped
> - Add a new commit for changing the logic in data_check_size
The patchset looks good to me. But I wanted to do some tests
and it failed. I did the following:
1. Applied this patchset on top of printk/linux.git, branch for-next,
https://git.kernel.org/pub/scm/linux/kernel/git/printk/linux.git/log/?h=for-next
I this branch because it contains a new KUnit test for the printk
ring buffer.
2. I applied the following patch:
+ It reduces the size of the data ring. If I count it correctly
it should be 256 (2 << 8).
+ It increases the maximal size of the text so that the maximal
record size is 256.
3. I built it with Kasan enabled:
$> grep KASAN .config
CONFIG_KASAN_SHADOW_OFFSET=0xdffffc0000000000
CONFIG_HAVE_ARCH_KASAN=y
CONFIG_HAVE_ARCH_KASAN_VMALLOC=y
CONFIG_CC_HAS_KASAN_GENERIC=y
CONFIG_CC_HAS_KASAN_SW_TAGS=y
CONFIG_KASAN=y
CONFIG_CC_HAS_KASAN_MEMINTRINSIC_PREFIX=y
CONFIG_KASAN_GENERIC=y
# CONFIG_KASAN_OUTLINE is not set
CONFIG_KASAN_INLINE=y
CONFIG_KASAN_STACK=y
CONFIG_KASAN_VMALLOC=y
# CONFIG_KASAN_KUNIT_TEST is not set
# CONFIG_KASAN_EXTRA_INFO is not set
4. I loaded the test module:
# depmod
# modprobe printk_ringbuffer_kunit_test
And I got the following:
[ 128.983916] printk_ringbuffer_kunit_test: module verification failed: signature and/or required key missing - tainting kernel
[ 128.993363] KTAP version 1
[ 128.993643] 1..1
[ 128.994282] KTAP version 1
[ 128.994579] # Subtest: printk-ringbuffer
[ 128.994908] # module: printk_ringbuffer_kunit_test
[ 128.994938] 1..1
[ 128.996142] # test_readerwriter: running for 10000 ms
[ 128.997243] # test_readerwriter: start thread 001 (writer)
[ 128.997545] # test_readerwriter: start thread 002 (writer)
[ 128.997767] # test_readerwriter: start thread 003 (writer)
[ 129.000142] # test_readerwriter: start thread 004 (writer)
[ 129.001086] # test_readerwriter: start thread 005 (writer)
[ 129.003865] # test_readerwriter: start thread 006 (writer)
[ 129.004125] # test_readerwriter: start thread 007 (writer)
[ 129.004329] # test_readerwriter: start thread 008 (writer)
[ 129.004584] # test_readerwriter: start thread 009 (writer)
[ 129.004896] # test_readerwriter: start thread 010 (writer)
[ 129.005089] # test_readerwriter: starting test
[ 129.005092] # test_readerwriter: start thread 011 (writer)
[ 129.011876] # test_readerwriter: start reader
[ 129.012639] # test_readerwriter: EXPECTATION FAILED at kernel/printk/printk_ringbuffer_kunit_test.c:80
BAD RECORD: seq=5 size=1145324612 text=
[ 129.014417] # test_readerwriter: EXPECTATION FAILED at kernel/printk/printk_ringbuffer_kunit_test.c:80
BAD RECORD: seq=6 size=165 text=DDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDD
[ 129.017373] ------------[ cut here ]------------
[ 129.017927] WARNING: CPU: 0 PID: 1497 at kernel/printk/printk_ringbuffer.c:1266 get_data+0x240/0x350
[ 129.018920] Modules linked in: printk_ringbuffer_kunit_test(E)
[ 129.019628] CPU: 0 UID: 0 PID: 1497 Comm: kunit_try_catch Tainted: G E N 6.16.0-default+ #159 PREEMPT(full) 20fb7e6f689e04f2e29367f5d7a03c64ac29a9f9
[ 129.021181] Tainted: [E]=UNSIGNED_MODULE, [N]=TEST
[ 129.021746] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.3-2-gc13ff2cd-prebuilt.qemu.org 04/01/2014
[ 129.022898] RIP: 0010:get_data+0x240/0x350
[ 129.023397] Code: 89 4c 24 08 4c 89 1c 24 e8 0d 21 81 00 4c 8b 44 24 20 48 8b 74 24 18 4c 8b 54 24 10 4c 8b 4c 24 08 4c 8b 1c 24 e9 9a fe ff ff <0f> 0b 31 c0 e9 6a ff ff ff 48 89 7c 24 08 48 89 f7 4c 89 44 24 10
[ 129.025323] RSP: 0018:ffffc90004d2f508 EFLAGS: 00010297
[ 129.025935] RAX: ffffffffc02194c0 RBX: ffffffffc0217780 RCX: 0000000000000b00
[ 129.026729] RDX: 00000000000000ff RSI: 0000000000000b00 RDI: 00000000000009b0
[ 129.027522] RBP: 00000000000000f5 R08: ffffc90004d2f5d0 R09: 00000000000009b0
[ 129.028328] R10: 0000000000000000 R11: ffffffffc02177b0 R12: ffffc90004d2f770
[ 129.029122] R13: dffffc0000000000 R14: ffffc90004d2f6b8 R15: 000000000000000c
[ 129.029915] FS: 0000000000000000(0000) GS:ffff888193898000(0000) knlGS:0000000000000000
[ 129.030800] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 129.031457] CR2: 000056180c2595a8 CR3: 000000011caee000 CR4: 0000000000750ef0
[ 129.032271] PKRU: 55555554
[ 129.032637] Call Trace:
[ 129.032976] <TASK>
[ 129.033280] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.033849] ? __asan_memcpy+0x3c/0x60
[ 129.034320] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.034889] _prb_read_valid+0x27e/0x620
[ 129.035397] ? __pfx__prb_read_valid+0x10/0x10
[ 129.035956] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.036531] ? __pfx___kunit_do_failed_assertion+0x10/0x10
[ 129.037176] ? kunit_log_append+0xb3/0xf0
[ 129.037672] ? __pfx_kunit_log_append+0x10/0x10
[ 129.038220] prb_read_valid+0x69/0x90
[ 129.038688] ? __pfx_prb_read_valid+0x10/0x10
[ 129.039214] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.039808] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.040381] prbtest_reader.isra.0+0x2ae/0x75c [printk_ringbuffer_kunit_test c283de0751f9c111bb1c6a71f2f57c1c47bab8d5]
[ 129.041538] ? __pfx_prbtest_reader.isra.0+0x10/0x10 [printk_ringbuffer_kunit_test c283de0751f9c111bb1c6a71f2f57c1c47bab8d5]
[ 129.042779] ? lock_acquire.part.0+0xc7/0x250
[ 129.043308] ? local_clock_noinstr+0xf/0x100
[ 129.043862] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.044428] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.044990] ? __lock_release.isra.0+0x1cb/0x300
[ 129.045547] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.046109] ? rcu_is_watching+0x15/0xb0
[ 129.046600] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.047159] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.047721] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.048324] ? __pfx_wait_for_completion+0x10/0x10
[ 129.048902] ? __pfx_prbtest_wakeup_callback+0x10/0x10 [printk_ringbuffer_kunit_test c283de0751f9c111bb1c6a71f2f57c1c47bab8d5]
[ 129.050107] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.050728] ? wait_for_completion+0x99/0x360
[ 129.051253] ? __pfx_migration_cpu_stop+0x10/0x10
[ 129.051833] ? affine_move_task+0xb41/0x1020
[ 129.052356] ? cpumask_any_and_distribute+0xee/0x130
[ 129.052943] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.053504] ? __set_cpus_allowed_ptr_locked+0x362/0x610
[ 129.054127] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.054689] ? __set_cpus_allowed_ptr+0x1b1/0x2c0
[ 129.055240] ? __pfx_prbtest_kthread_cleanup+0x10/0x10 [printk_ringbuffer_kunit_test c283de0751f9c111bb1c6a71f2f57c1c47bab8d5]
[ 129.056461] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.057019] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.057580] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.058141] ? __pfx___set_cpus_allowed_ptr+0x10/0x10
[ 129.058738] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.059297] ? kunit_log_append+0xb3/0xf0
[ 129.059820] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.060379] ? set_cpus_allowed_ptr+0x80/0xb0
[ 129.060901] ? __pfx_set_cpus_allowed_ptr+0x10/0x10
[ 129.061471] ? kthread_bind+0x14c/0x1a0
[ 129.061962] test_readerwriter.cold+0xd3/0x244 [printk_ringbuffer_kunit_test c283de0751f9c111bb1c6a71f2f57c1c47bab8d5]
[ 129.063106] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.063668] ? lock_acquire.part.0+0xc7/0x250
[ 129.064213] ? __pfx_test_readerwriter+0x10/0x10 [printk_ringbuffer_kunit_test c283de0751f9c111bb1c6a71f2f57c1c47bab8d5]
[ 129.065377] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.065939] ? __lock_release.isra.0+0x1cb/0x300
[ 129.066494] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.067061] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.067627] ? lockdep_hardirqs_on+0x8c/0x130
[ 129.068168] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.068732] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.069293] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.069858] ? ktime_get_ts64+0x80/0x250
[ 129.070356] kunit_try_run_case+0x179/0x290
[ 129.070865] ? __pfx_kunit_try_run_case+0x10/0x10
[ 129.071420] ? __lock_release.isra.0+0x1cb/0x300
[ 129.071995] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.072607] ? rcu_is_watching+0x15/0xb0
[ 129.073088] ? __pfx_kunit_generic_run_threadfn_adapter+0x10/0x10
[ 129.073779] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.074341] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.074906] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.075471] ? lockdep_hardirqs_on+0x8c/0x130
[ 129.076016] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.076588] ? __pfx_kunit_generic_run_threadfn_adapter+0x10/0x10
[ 129.077270] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.077840] ? __pfx_kunit_generic_run_threadfn_adapter+0x10/0x10
[ 129.078529] kunit_generic_run_threadfn_adapter+0x82/0xf0
[ 129.079159] kthread+0x3b0/0x750
[ 129.079576] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.080165] ? local_clock_noinstr+0xf/0x100
[ 129.080689] ? __pfx_kthread+0x10/0x10
[ 129.081157] ? __lock_release.isra.0+0x1cb/0x300
[ 129.081716] ? srso_alias_return_thunk+0x5/0xfbef5
[ 129.082282] ? rcu_is_watching+0x15/0xb0
[ 129.082774] ? __pfx_kthread+0x10/0x10
[ 129.083246] ret_from_fork+0x38e/0x4b0
[ 129.083719] ? __pfx_kthread+0x10/0x10
[ 129.084207] ? __pfx_kthread+0x10/0x10
[ 129.084680] ret_from_fork_asm+0x1a/0x30
[ 129.085195] </TASK>
[ 129.085512] irq event stamp: 1867
[ 129.085930] hardirqs last enabled at (1877): [<ffffffffb56f82de>] __up_console_sem+0x5e/0x70
[ 129.086858] hardirqs last disabled at (1886): [<ffffffffb56f82c3>] __up_console_sem+0x43/0x70
[ 129.087783] softirqs last enabled at (1134): [<ffffffffb55416b2>] handle_softirqs+0x502/0x6b0
[ 129.088744] softirqs last disabled at (1129): [<ffffffffb5541982>] __irq_exit_rcu+0x112/0x230
[ 129.089668] ---[ end trace 0000000000000000 ]---
[ 139.039960] # test_readerwriter: end reader: read=13 seq=15
[ 139.040720] # test_readerwriter: completed test
[ 139.042049] # test_readerwriter: end thread 011: wrote=13124589
[ 139.042860] # test_readerwriter: end thread 010: wrote=13101241
[ 139.043667] # test_readerwriter: end thread 009: wrote=16785932
[ 139.044803] # test_readerwriter: end thread 008: wrote=13123788
[ 139.045626] # test_readerwriter: end thread 007: wrote=16778106
[ 139.046259] # test_readerwriter: end thread 006: wrote=13119340
[ 139.046857] # test_readerwriter: end thread 005: wrote=16800807
[ 139.047457] # test_readerwriter: end thread 004: wrote=13136578
[ 139.048084] # test_readerwriter: end thread 003: wrote=16805445
[ 139.048665] # test_readerwriter: end thread 002: wrote=13156382
[ 139.049232] # test_readerwriter: end thread 001: wrote=16847574
[ 139.050000] # test_readerwriter.speed: slow
[ 139.050034] not ok 1 test_readerwriter
[ 139.050497] not ok 1 printk-ringbuffer
Observation:
1. The test failed very early. The sequence numbers of the broken
records are 5 and 6.
2. The record with the sequence number 5 has very high size:
BAD RECORD: seq=5 size=1145324612 text=
3. It triggered an internal ring buffer warning:
WARNING: CPU: 0 PID: 1497 at
kernel/printk/printk_ringbuffer.c:1266 get_data+0x240/0x350
It is the following one:
static const char *get_data(struct prb_data_ring *data_ring,
struct prb_data_blk_lpos *blk_lpos,
unsigned int *data_size)
{
[...]
/* A valid data block will always have at least an ID. */
if (WARN_ON_ONCE(*data_size < sizeof(db->id)))
return NULL;
It looks to me that the ring buffer got corrupted.
I am not sure if it is caused by this patchset or
if the problem was there even before or
if it is a bug in the KUnit test.
It has to be investigated.
Best Regards,
Petr
next prev parent reply other threads:[~2025-09-11 15:30 UTC|newest]
Thread overview: 32+ messages / expand[flat|nested] mbox.gz Atom feed top
2025-09-05 14:41 [PATCH v2 0/2] printk_ringbuffer: don't needlessly wrap data blocks around Daniil Tatianin
2025-09-05 14:41 ` [PATCH v2 1/2] " Daniil Tatianin
2025-09-05 15:27 ` John Ogness
2025-09-05 15:29 ` Daniil Tatianin
2025-09-05 16:10 ` John Ogness
2025-09-11 8:34 ` Daniil Tatianin
2025-09-11 15:33 ` Petr Mladek
2025-09-05 15:30 ` John Ogness
2025-09-26 14:35 ` Daniil Tatianin
2025-09-26 14:44 ` Petr Mladek
2025-09-26 14:53 ` Daniil Tatianin
2025-10-22 12:46 ` Petr Mladek
2025-09-05 14:41 ` [PATCH v2 2/2] printk_ringbuffer: allow one data block to occupy the entire data ring Daniil Tatianin
2025-09-05 15:27 ` John Ogness
2025-09-11 15:30 ` Petr Mladek [this message]
2025-09-11 15:55 ` [PATCH v2 0/2] printk_ringbuffer: don't needlessly wrap data blocks around Petr Mladek
2025-09-11 16:11 ` Petr Mladek
2025-09-11 15:58 ` Petr Mladek
2025-09-11 16:12 ` John Ogness
2025-09-12 9:25 ` Petr Mladek
2025-09-12 9:54 ` Petr Mladek
2025-09-12 14:49 ` Petr Mladek
2025-09-12 15:15 ` Petr Mladek
2025-09-12 18:43 ` John Ogness
2025-09-13 17:38 ` Daniil Tatianin
2025-09-14 9:23 ` John Ogness
2025-09-14 9:56 ` Daniil Tatianin
2025-09-15 15:07 ` John Ogness
2025-09-15 16:00 ` Petr Mladek
2025-09-15 16:07 ` Daniil Tatianin
2025-09-15 15:08 ` Petr Mladek
2025-09-15 15:25 ` John Ogness
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=aMLrGCQSyC8odlFZ@pathway.suse.cz \
--to=pmladek@suse.com \
--cc=d-tatianin@yandex-team.ru \
--cc=john.ogness@linutronix.de \
--cc=linux-kernel@vger.kernel.org \
--cc=rostedt@goodmis.org \
--cc=senozhatsky@chromium.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.