On Wed, 28 Jun 2023 at 15:49, Tetsuo Handa
<[email protected]> wrote:
>
> syzbot is reporting uninit-value at aes_encrypt(), for block cipher assumes
> that bytes to encrypt/decrypt is multiple of block size for that cipher but
> tls_alloc_encrypted_msg() is not initializing padding bytes when
> required_size is not multiple of block cipher's block size.
>
> In order to make sure that padding bytes are automatically initialized,
> enable __GFP_ZERO flag when setsockopt(SOL_TCP, TCP_ULP, "tls") is called.
>
> Reported-by: syzbot <[email protected]>
> Closes: https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d
Maybe I am missing something, but this syzkaller report appears to b a
huge collection of uninit-value reports, of which only one is related
to bpx_tx_verdict(), and that one has nor reproducer.
So even if this would be the right fix, I don't think closing that
issue makes sense, so? The issue refers to a couple of other
occcurences of uninit-value in aesti_encrypt, which do seem related.
> Signed-off-by: Tetsuo Handa <[email protected]>
> ---
> According to C reproducer, this problem happens when bpf_exec_tx_verdict() is
> called with lower 4 bits of required_size being 0001 and does not happen when
> being 0100. Thus, I assumed that this problem is caused by lack of initializing
> padding bytes.
> But I couldn't figure out why KMSAN reports this problem when bpf_exec_tx_verdict()
> is called with lower 4 bits of required_size being 0001 for the second time and
> does not report this problem when bpf_exec_tx_verdict() is called with lower
> 4 bits of required_size being 0001 for the first time. More deeper problem exists?
> KMSAN reporting this problem when accessing u64 relevant?
>
As Eric pointed out as well, zeroing the allocation papers over the problem.
Why are you sending this now? Do you have a reproducer for this issue?
> net/tls/tls_main.c | 1 +
> 1 file changed, 1 insertion(+)
>
> diff --git a/net/tls/tls_main.c b/net/tls/tls_main.c
> index f2e7302a4d96..cd5366966864 100644
> --- a/net/tls/tls_main.c
> +++ b/net/tls/tls_main.c
> @@ -1025,6 +1025,7 @@ static int tls_init(struct sock *sk)
> struct tls_context *ctx;
> int rc = 0;
>
> + sk->sk_allocation |= __GFP_ZERO;
> tls_build_proto(sk);
>
> #ifdef CONFIG_TLS_TOE
> --
> 2.34.1
>
On 2023/06/30 18:36, Ard Biesheuvel wrote:
> Why are you sending this now?
Just because this is currently top crasher and I can reproduce locally.
> Do you have a reproducer for this issue?
Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
<[email protected]> wrote:
>
> On 2023/06/30 18:36, Ard Biesheuvel wrote:
> > Why are you sending this now?
>
> Just because this is currently top crasher and I can reproduce locally.
>
> > Do you have a reproducer for this issue?
>
> Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
>
Could you please share your kernel config and the resulting kernel log
when running the reproducer? I'll try to reproduce locally as well,
and see if I can figure out what is going on in the crypto layer
On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
>
> On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
> <[email protected]> wrote:
> >
> > On 2023/06/30 18:36, Ard Biesheuvel wrote:
> > > Why are you sending this now?
> >
> > Just because this is currently top crasher and I can reproduce locally.
> >
> > > Do you have a reproducer for this issue?
> >
> > Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
> >
>
> Could you please share your kernel config and the resulting kernel log
> when running the reproducer? I'll try to reproduce locally as well,
> and see if I can figure out what is going on in the crypto layer
The config together with the repro is available at
https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
latest row of the "Crashes" table that contains a C repro.
Config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=ee5f7a0b2e48ed66
Report: https://syzkaller.appspot.com/text?tag=CrashReport&x=1325260d900000
Syz repro: https://syzkaller.appspot.com/text?tag=ReproSyz&x=11af973e900000
C repro: https://syzkaller.appspot.com/text?tag=ReproC&x=163a1e45900000
The bug is reproducible for me locally as well (and Tetsuo's patch
makes it disappear, although I have no opinion on its correctness).
On Fri, 30 Jun 2023 at 12:11, Alexander Potapenko <[email protected]> wrote:
>
> On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
> >
> > On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
> > <[email protected]> wrote:
> > >
> > > On 2023/06/30 18:36, Ard Biesheuvel wrote:
> > > > Why are you sending this now?
> > >
> > > Just because this is currently top crasher and I can reproduce locally.
> > >
> > > > Do you have a reproducer for this issue?
> > >
> > > Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
> > >
> >
> > Could you please share your kernel config and the resulting kernel log
> > when running the reproducer? I'll try to reproduce locally as well,
> > and see if I can figure out what is going on in the crypto layer
>
> The config together with the repro is available at
> https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
> latest row of the "Crashes" table that contains a C repro.
Could you explain why that bug contains ~50 reports that seem entirely
unrelated? AIUI, this actual issue has not been reproduced since
2020??
> Config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=ee5f7a0b2e48ed66
> Report: https://syzkaller.appspot.com/text?tag=CrashReport&x=1325260d900000
> Syz repro: https://syzkaller.appspot.com/text?tag=ReproSyz&x=11af973e900000
> C repro: https://syzkaller.appspot.com/text?tag=ReproC&x=163a1e45900000
>
> The bug is reproducible for me locally as well (and Tetsuo's patch
> makes it disappear, although I have no opinion on its correctness).
What I'd like to do is run a kernel plus initrd locally in OVMF and
reproduce the issue - can I do that without all the syzkaller
machinery?
On 2023/06/30 19:18, Ard Biesheuvel wrote:
> On Fri, 30 Jun 2023 at 12:11, Alexander Potapenko <[email protected]> wrote:
>>
>> On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
>>>
>>> On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
>>> <[email protected]> wrote:
>>>>
>>>> On 2023/06/30 18:36, Ard Biesheuvel wrote:
>>>>> Why are you sending this now?
>>>>
>>>> Just because this is currently top crasher and I can reproduce locally.
>>>>
>>>>> Do you have a reproducer for this issue?
>>>>
>>>> Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
>>>>
>>>
>>> Could you please share your kernel config and the resulting kernel log
>>> when running the reproducer? I'll try to reproduce locally as well,
>>> and see if I can figure out what is going on in the crypto layer
>>
>> The config together with the repro is available at
>> https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
>> latest row of the "Crashes" table that contains a C repro.
Kernel is commit e6bc8833d80f of https://github.com/google/kmsan/commits/master .
Config is available in the dashboard page, but a smaller one is available at
https://I-love.SAKURA.ne.jp/tmp/config-6.4.0-rc7-kmsan .
I'm using a debug printk() patch shown below.
----------------------------------------
diff --git a/net/tls/tls_sw.c b/net/tls/tls_sw.c
index 1a53c8f481e9..b32bb015995c 100644
--- a/net/tls/tls_sw.c
+++ b/net/tls/tls_sw.c
@@ -1210,7 +1210,8 @@ static int tls_sw_do_sendpage(struct sock *sk, struct page *page,
if (!sk_stream_memory_free(sk))
goto wait_for_sndbuf;
alloc_payload:
- ret = tls_alloc_encrypted_msg(sk, required_size);
+ ret = tls_alloc_encrypted_msg(sk, required_size); /////
+ pr_info("required_size=%d ret=%d\n", required_size, ret);
if (ret) {
if (ret != -ENOSPC)
goto wait_for_memory;
@@ -1232,7 +1233,9 @@ static int tls_sw_do_sendpage(struct sock *sk, struct page *page,
tls_ctx->pending_open_record_frags = true;
if (full_record || eor || sk_msg_full(msg_pl)) {
- ret = bpf_exec_tx_verdict(msg_pl, sk, full_record,
+ pr_info("full_record=%d eor=%d sk_msg_full(msg_pl)=%d copied=%d\n",
+ full_record, eor, sk_msg_full(msg_pl), copied);
+ ret = bpf_exec_tx_verdict(msg_pl, sk, full_record, /////
record_type, &copied, flags);
if (ret) {
if (ret == -EINPROGRESS)
----------------------------------------
Output (on Ubuntu 22.04 on Oracle VM VirtualBox) is shown below.
Please check tendency of the sum of required_size= values up to the full_record= line.
It seems that the value of required_size= might vary depending on the timings, but
the sum of the values seems to have some rule.
4125+8221+12317+16413=41076 (the lower 4 bits are 0100)
2461+6557+10653+14749+16413=50833 (the lower 4 bits are 0001)
2461+6573+10669+14765+16413=50881 (the lower 4 bits are 0001)
KMSAN reports this problem when the lower 4 bits became 0001 for the second time.
Unless KMSAN's reporting is asynchronous, maybe the reason of "for the second time"
part is that the previous state is relevant...
----------------------------------------
[ 157.471712][ T3414] required_size=4125 ret=0
[ 157.475879][ T3414] required_size=8221 ret=0
[ 157.480471][ T3414] required_size=12317 ret=0
[ 157.484604][ T3414] required_size=16413 ret=0
[ 157.490499][ T3414] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=4096
[ 157.513772][ T3414] required_size=4125 ret=0
[ 157.523782][ T3414] required_size=8221 ret=0
[ 157.533658][ T3414] required_size=12317 ret=0
[ 157.539579][ T3414] required_size=16413 ret=0
[ 157.543785][ T3414] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=4096
[ 157.572869][ T3414] required_size=4125 ret=0
[ 157.579350][ T3414] required_size=8221 ret=0
[ 157.584699][ T3414] required_size=12317 ret=0
[ 157.591756][ T3414] required_size=16413 ret=0
[ 157.595891][ T3414] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=4096
[ 157.790734][ T3424] required_size=2461 ret=0
[ 157.800725][ T3424] required_size=6557 ret=0
[ 157.804560][ T3424] required_size=10653 ret=0
[ 157.808433][ T3424] required_size=14749 ret=0
[ 157.810125][ T3424] required_size=16413 ret=0
[ 157.829564][ T3424] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=1664
[ 157.848397][ T3424] required_size=2461 ret=0
[ 157.854875][ T3424] required_size=6573 ret=0
[ 157.860883][ T3424] required_size=10669 ret=0
[ 157.865463][ T3424] required_size=14765 ret=0
[ 157.871794][ T3424] required_size=16413 ret=0
[ 157.877333][ T3424] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=1648
[ 157.885187][ T3424] =====================================================
[ 157.887262][ T3424] BUG: KMSAN: uninit-value in aes_encrypt+0x1692/0x1fa0
[ 157.887262][ T3424] aes_encrypt+0x1692/0x1fa0
[ 157.887262][ T3424] aesti_encrypt+0xe1/0x160
[ 157.887262][ T3424] crypto_cipher_encrypt_one+0x1d1/0x2e0
[ 157.887262][ T3424] crypto_cbcmac_digest_update+0x3ff/0x5a0
[ 157.887262][ T3424] shash_ahash_finup+0x79d/0xd00
[ 157.887262][ T3424] shash_async_finup+0xbf/0x110
[ 157.887262][ T3424] crypto_ahash_finup+0x244/0x500
[ 157.887262][ T3424] crypto_ccm_auth+0x14df/0x15a0
[ 157.887262][ T3424] crypto_ccm_encrypt+0x2ad/0x8b0
[ 157.887262][ T3424] crypto_aead_encrypt+0x116/0x1a0
[ 157.887262][ T3424] tls_push_record+0x2bbe/0x3bf0
[ 157.887262][ T3424] bpf_exec_tx_verdict+0x5ba/0x2530
[ 157.887262][ T3424] tls_sw_do_sendpage+0x1779/0x21f0
[ 157.887262][ T3424] tls_sw_sendpage+0x247/0x2b0
[ 157.887262][ T3424] inet_sendpage+0x1de/0x2f0
[ 157.887262][ T3424] kernel_sendpage+0x4cc/0x940
[ 158.004827][ T3424] sock_sendpage+0x162/0x220
[ 158.004827][ T3424] pipe_to_sendpage+0x3df/0x4f0
[ 158.004827][ T3424] __splice_from_pipe+0x5c7/0x1010
[ 158.004827][ T3424] generic_splice_sendpage+0x1c6/0x2a0
[ 158.004827][ T3424] do_splice+0x26d8/0x32f0
[ 158.004827][ T3424] __se_sys_splice+0x81f/0xba0
[ 158.004827][ T3424] __x64_sys_splice+0x1a1/0x200
[ 158.004827][ T3424] do_syscall_64+0x41/0x90
[ 158.004827][ T3424] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 158.004827][ T3424]
[ 158.004827][ T3424] Uninit was stored to memory at:
[ 158.004827][ T3424] __crypto_xor+0x285/0x1700
[ 158.004827][ T3424] crypto_cbcmac_digest_update+0x2ba/0x5a0
[ 158.004827][ T3424] shash_ahash_finup+0x79d/0xd00
[ 158.004827][ T3424] shash_async_finup+0xbf/0x110
[ 158.004827][ T3424] crypto_ahash_finup+0x244/0x500
[ 158.004827][ T3424] crypto_ccm_auth+0x14df/0x15a0
[ 158.004827][ T3424] crypto_ccm_encrypt+0x2ad/0x8b0
[ 158.004827][ T3424] crypto_aead_encrypt+0x116/0x1a0
[ 158.004827][ T3424] tls_push_record+0x2bbe/0x3bf0
[ 158.004827][ T3424] bpf_exec_tx_verdict+0x5ba/0x2530
[ 158.004827][ T3424] tls_sw_do_sendpage+0x1779/0x21f0
[ 158.004827][ T3424] tls_sw_sendpage+0x247/0x2b0
[ 158.004827][ T3424] inet_sendpage+0x1de/0x2f0
[ 158.004827][ T3424] kernel_sendpage+0x4cc/0x940
[ 158.004827][ T3424] sock_sendpage+0x162/0x220
[ 158.004827][ T3424] pipe_to_sendpage+0x3df/0x4f0
[ 158.004827][ T3424] __splice_from_pipe+0x5c7/0x1010
[ 158.004827][ T3424] generic_splice_sendpage+0x1c6/0x2a0
[ 158.004827][ T3424] do_splice+0x26d8/0x32f0
[ 158.004827][ T3424] __se_sys_splice+0x81f/0xba0
[ 158.004827][ T3424] __x64_sys_splice+0x1a1/0x200
[ 158.004827][ T3424] do_syscall_64+0x41/0x90
[ 158.004827][ T3424] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 158.004827][ T3424]
[ 158.004827][ T3424] Uninit was created at:
[ 158.004827][ T3424] __alloc_pages+0x925/0x1050
[ 158.004827][ T3424] alloc_pages+0xe30/0x11b0
[ 158.004827][ T3424] skb_page_frag_refill+0x362/0x910
[ 158.004827][ T3424] sk_page_frag_refill+0xa2/0x1c0
[ 158.004827][ T3424] sk_msg_alloc+0x278/0x1560
[ 158.004827][ T3424] tls_sw_do_sendpage+0xbec/0x21f0
[ 158.004827][ T3424] tls_sw_sendpage+0x247/0x2b0
[ 158.004827][ T3424] inet_sendpage+0x1de/0x2f0
[ 158.004827][ T3424] kernel_sendpage+0x4cc/0x940
[ 158.004827][ T3424] sock_sendpage+0x162/0x220
[ 158.004827][ T3424] pipe_to_sendpage+0x3df/0x4f0
[ 158.004827][ T3424] __splice_from_pipe+0x5c7/0x1010
[ 158.004827][ T3424] generic_splice_sendpage+0x1c6/0x2a0
[ 158.260226][ T3424] do_splice+0x26d8/0x32f0
[ 158.260226][ T3424] __se_sys_splice+0x81f/0xba0
[ 158.260226][ T3424] __x64_sys_splice+0x1a1/0x200
[ 158.260226][ T3424] do_syscall_64+0x41/0x90
[ 158.260226][ T3424] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 158.260226][ T3424]
[ 158.260226][ T3424] CPU: 7 PID: 3424 Comm: a.out Not tainted 6.4.0-rc7-ge6bc8833d80f-dirty #26
[ 158.260226][ T3424] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[ 158.260226][ T3424] =====================================================
[ 158.260226][ T3424] Disabling lock debugging due to kernel taint
[ 158.260226][ T3424] Kernel panic - not syncing: kmsan.panic set ...
[ 158.260226][ T3424] CPU: 7 PID: 3424 Comm: a.out Tainted: G B 6.4.0-rc7-ge6bc8833d80f-dirty #26
[ 158.320898][ T3424] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[ 158.334186][ T3424] Call Trace:
[ 158.334186][ T3424] <TASK>
[ 158.334186][ T3424] dump_stack_lvl+0x1f6/0x280
[ 158.334186][ T3424] dump_stack+0x29/0x30
[ 158.334186][ T3424] panic+0x4e7/0xc60
[ 158.334186][ T3424] ? add_taint+0x185/0x210
[ 158.334186][ T3424] kmsan_report+0x2d1/0x2e0
[ 158.334186][ T3424] ? __msan_warning+0x98/0x120
[ 158.334186][ T3424] ? aes_encrypt+0x1692/0x1fa0
[ 158.334186][ T3424] ? aesti_encrypt+0xe1/0x160
[ 158.334186][ T3424] ? crypto_cipher_encrypt_one+0x1d1/0x2e0
[ 158.334186][ T3424] ? crypto_cbcmac_digest_update+0x3ff/0x5a0
[ 158.334186][ T3424] ? shash_ahash_finup+0x79d/0xd00
[ 158.334186][ T3424] ? shash_async_finup+0xbf/0x110
[ 158.334186][ T3424] ? crypto_ahash_finup+0x244/0x500
[ 158.334186][ T3424] ? crypto_ccm_auth+0x14df/0x15a0
[ 158.334186][ T3424] ? crypto_ccm_encrypt+0x2ad/0x8b0
[ 158.334186][ T3424] ? crypto_aead_encrypt+0x116/0x1a0
[ 158.334186][ T3424] ? tls_push_record+0x2bbe/0x3bf0
[ 158.334186][ T3424] ? bpf_exec_tx_verdict+0x5ba/0x2530
[ 158.334186][ T3424] ? tls_sw_do_sendpage+0x1779/0x21f0
[ 158.334186][ T3424] ? tls_sw_sendpage+0x247/0x2b0
[ 158.334186][ T3424] ? inet_sendpage+0x1de/0x2f0
[ 158.334186][ T3424] ? kernel_sendpage+0x4cc/0x940
[ 158.334186][ T3424] ? sock_sendpage+0x162/0x220
[ 158.334186][ T3424] ? pipe_to_sendpage+0x3df/0x4f0
[ 158.334186][ T3424] ? __splice_from_pipe+0x5c7/0x1010
[ 158.334186][ T3424] ? generic_splice_sendpage+0x1c6/0x2a0
[ 158.334186][ T3424] ? do_splice+0x26d8/0x32f0
[ 158.334186][ T3424] ? __se_sys_splice+0x81f/0xba0
[ 158.334186][ T3424] ? __x64_sys_splice+0x1a1/0x200
[ 158.334186][ T3424] ? do_syscall_64+0x41/0x90
[ 158.334186][ T3424] ? entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 158.334186][ T3424] ? filter_irq_stacks+0xb9/0x230
[ 158.334186][ T3424] ? __stack_depot_save+0x22/0x490
[ 158.334186][ T3424] ? kmsan_internal_set_shadow_origin+0x66/0xe0
[ 158.334186][ T3424] ? kmsan_internal_chain_origin+0x110/0x120
[ 158.334186][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[ 158.334186][ T3424] __msan_warning+0x98/0x120
[ 158.334186][ T3424] aes_encrypt+0x1692/0x1fa0
[ 158.334186][ T3424] aesti_encrypt+0xe1/0x160
[ 158.334186][ T3424] crypto_cipher_encrypt_one+0x1d1/0x2e0
[ 158.334186][ T3424] ? aesti_set_key+0xb0/0xb0
[ 158.334186][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[ 158.334186][ T3424] crypto_cbcmac_digest_update+0x3ff/0x5a0
[ 158.334186][ T3424] ? crypto_cbcmac_digest_init+0x140/0x140
[ 158.334186][ T3424] shash_ahash_finup+0x79d/0xd00
[ 158.334186][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[ 158.334186][ T3424] shash_async_finup+0xbf/0x110
[ 158.334186][ T3424] crypto_ahash_finup+0x244/0x500
[ 158.334186][ T3424] ? shash_async_final+0x3d0/0x3d0
[ 158.334186][ T3424] crypto_ccm_auth+0x14df/0x15a0
[ 158.334186][ T3424] crypto_ccm_encrypt+0x2ad/0x8b0
[ 158.334186][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[ 158.334186][ T3424] ? crypto_ccm_setauthsize+0x100/0x100
[ 158.334186][ T3424] crypto_aead_encrypt+0x116/0x1a0
[ 158.653332][ T3424] tls_push_record+0x2bbe/0x3bf0
[ 158.653332][ T3424] bpf_exec_tx_verdict+0x5ba/0x2530
[ 158.653332][ T3424] ? _printk+0x181/0x1b0
[ 158.653332][ T3424] ? tls_sw_do_sendpage+0xc81/0x21f0
[ 158.653332][ T3424] tls_sw_do_sendpage+0x1779/0x21f0
[ 158.653332][ T3424] tls_sw_sendpage+0x247/0x2b0
[ 158.653332][ T3424] ? tls_sw_do_sendpage+0x21f0/0x21f0
[ 158.653332][ T3424] inet_sendpage+0x1de/0x2f0
[ 158.653332][ T3424] ? inet_sendmsg+0x1d0/0x1d0
[ 158.653332][ T3424] kernel_sendpage+0x4cc/0x940
[ 158.653332][ T3424] sock_sendpage+0x162/0x220
[ 158.653332][ T3424] pipe_to_sendpage+0x3df/0x4f0
[ 158.653332][ T3424] ? sock_fasync+0x240/0x240
[ 158.653332][ T3424] __splice_from_pipe+0x5c7/0x1010
[ 158.653332][ T3424] ? generic_splice_sendpage+0x2a0/0x2a0
[ 158.653332][ T3424] generic_splice_sendpage+0x1c6/0x2a0
[ 158.653332][ T3424] ? iter_file_splice_write+0x1a30/0x1a30
[ 158.653332][ T3424] do_splice+0x26d8/0x32f0
[ 158.653332][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[ 158.653332][ T3424] ? __se_sys_splice+0x292/0xba0
[ 158.653332][ T3424] ? __msan_metadata_ptr_for_load_8+0x24/0x40
[ 158.653332][ T3424] ? filter_irq_stacks+0xb9/0x230
[ 158.653332][ T3424] __se_sys_splice+0x81f/0xba0
[ 158.870673][ T3424] __x64_sys_splice+0x1a1/0x200
[ 158.870673][ T3424] do_syscall_64+0x41/0x90
[ 158.870673][ T3424] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 158.870673][ T3424] RIP: 0033:0x7f6bbd51ea3d
[ 158.895223][ T3424] Code: 5b 41 5c c3 66 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d c3 a3 0f 00 f7 d8 64 89 01 48
[ 158.895223][ T3424] RSP: 002b:00007f6bbd731e08 EFLAGS: 00000246 ORIG_RAX: 0000000000000113
[ 158.895223][ T3424] RAX: ffffffffffffffda RBX: 000055ccd9ea6080 RCX: 00007f6bbd51ea3d
[ 158.895223][ T3424] RDX: 0000000000000004 RSI: 0000000000000000 RDI: 0000000000000003
[ 158.895223][ T3424] RBP: 000055ccd9ea41f4 R08: 00080000fffffffc R09: 0000000000000000
[ 158.895223][ T3424] R10: 0000000000000000 R11: 0000000000000246 R12: 0100000000000000
[ 158.895223][ T3424] R13: e65b75b4ec4292eb R14: f2300cdb85a45425 R15: 000055ccd9ea6088
[ 159.041467][ T3424] </TASK>
[ 159.041467][ T3424] Kernel Offset: disabled
[ 159.041467][ T3424] Rebooting in 10 seconds..
----------------------------------------
>
> Could you explain why that bug contains ~50 reports that seem entirely
> unrelated? AIUI, this actual issue has not been reproduced since
> 2020??
Multiple different bugs are reported as the same problem.
Reproducer is available for only bpf_exec_tx_verdict() one, and the reproducer still works.
>
>
>> Config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=ee5f7a0b2e48ed66
>> Report: https://syzkaller.appspot.com/text?tag=CrashReport&x=1325260d900000
>> Syz repro: https://syzkaller.appspot.com/text?tag=ReproSyz&x=11af973e900000
>> C repro: https://syzkaller.appspot.com/text?tag=ReproC&x=163a1e45900000
>>
>> The bug is reproducible for me locally as well (and Tetsuo's patch
>> makes it disappear, although I have no opinion on its correctness).
>
> What I'd like to do is run a kernel plus initrd locally in OVMF and
> reproduce the issue - can I do that without all the syzkaller
> machinery?
I'm using Ubuntu 22.04 on Oracle VM VirtualBox.
I don't know if this can be reproduced with kernel plus initrd only. But
since the C reproducer is standalone, syzkaller machinery is not involved.
On Fri, Jun 30, 2023 at 1:11 PM Tetsuo Handa
<[email protected]> wrote:
>
> On 2023/06/30 19:18, Ard Biesheuvel wrote:
> > On Fri, 30 Jun 2023 at 12:11, Alexander Potapenko <[email protected]> wrote:
> >>
> >> On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
> >>>
> >>> On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
> >>> <[email protected]> wrote:
> >>>>
> >>>> On 2023/06/30 18:36, Ard Biesheuvel wrote:
> >>>>> Why are you sending this now?
> >>>>
> >>>> Just because this is currently top crasher and I can reproduce locally.
> >>>>
> >>>>> Do you have a reproducer for this issue?
> >>>>
> >>>> Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
> >>>>
> >>>
> >>> Could you please share your kernel config and the resulting kernel log
> >>> when running the reproducer? I'll try to reproduce locally as well,
> >>> and see if I can figure out what is going on in the crypto layer
> >>
> >> The config together with the repro is available at
> >> https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
> >> latest row of the "Crashes" table that contains a C repro.
>
> Kernel is commit e6bc8833d80f of https://github.com/google/kmsan/commits/master .
> Config is available in the dashboard page, but a smaller one is available at
> https://I-love.SAKURA.ne.jp/tmp/config-6.4.0-rc7-kmsan .
>
> I'm using a debug printk() patch shown below.
>
Please note that your patch is not correct, unless I am missing something.
sk_page_frag() will use a per-thread frag allocator
(current->task_frag), which might be fed with pages
allocated from other sockets (standard TCP ones), without __GFP_ZERO.
If we must (and I am not saying we should) take this route, we also
need to force
"sk->sk_use_task_frag = false" for TLS sockets.
On Fri, 30 Jun 2023 at 13:12, Tetsuo Handa
<[email protected]> wrote:
>
> On 2023/06/30 19:18, Ard Biesheuvel wrote:
> > On Fri, 30 Jun 2023 at 12:11, Alexander Potapenko <[email protected]> wrote:
> >>
> >> On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
> >>>
> >>> On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
> >>> <[email protected]> wrote:
> >>>>
> >>>> On 2023/06/30 18:36, Ard Biesheuvel wrote:
> >>>>> Why are you sending this now?
> >>>>
> >>>> Just because this is currently top crasher and I can reproduce locally.
> >>>>
> >>>>> Do you have a reproducer for this issue?
> >>>>
> >>>> Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
> >>>>
> >>>
> >>> Could you please share your kernel config and the resulting kernel log
> >>> when running the reproducer? I'll try to reproduce locally as well,
> >>> and see if I can figure out what is going on in the crypto layer
> >>
> >> The config together with the repro is available at
> >> https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
> >> latest row of the "Crashes" table that contains a C repro.
>
> Kernel is commit e6bc8833d80f of https://github.com/google/kmsan/commits/master .
That commit does not exist in that repo. Does it matter?
> Config is available in the dashboard page, but a smaller one is available at
> https://I-love.SAKURA.ne.jp/tmp/config-6.4.0-rc7-kmsan .
>
Thanks - I'll try to rebuild v6.4-rc7 with that.
> I'm using a debug printk() patch shown below.
>
> ----------------------------------------
> diff --git a/net/tls/tls_sw.c b/net/tls/tls_sw.c
> index 1a53c8f481e9..b32bb015995c 100644
> --- a/net/tls/tls_sw.c
> +++ b/net/tls/tls_sw.c
> @@ -1210,7 +1210,8 @@ static int tls_sw_do_sendpage(struct sock *sk, struct page *page,
> if (!sk_stream_memory_free(sk))
> goto wait_for_sndbuf;
> alloc_payload:
> - ret = tls_alloc_encrypted_msg(sk, required_size);
> + ret = tls_alloc_encrypted_msg(sk, required_size); /////
> + pr_info("required_size=%d ret=%d\n", required_size, ret);
> if (ret) {
> if (ret != -ENOSPC)
> goto wait_for_memory;
> @@ -1232,7 +1233,9 @@ static int tls_sw_do_sendpage(struct sock *sk, struct page *page,
>
> tls_ctx->pending_open_record_frags = true;
> if (full_record || eor || sk_msg_full(msg_pl)) {
> - ret = bpf_exec_tx_verdict(msg_pl, sk, full_record,
> + pr_info("full_record=%d eor=%d sk_msg_full(msg_pl)=%d copied=%d\n",
> + full_record, eor, sk_msg_full(msg_pl), copied);
> + ret = bpf_exec_tx_verdict(msg_pl, sk, full_record, /////
> record_type, &copied, flags);
> if (ret) {
> if (ret == -EINPROGRESS)
> ----------------------------------------
>
> Output (on Ubuntu 22.04 on Oracle VM VirtualBox) is shown below.
> Please check tendency of the sum of required_size= values up to the full_record= line.
> It seems that the value of required_size= might vary depending on the timings, but
> the sum of the values seems to have some rule.
>
> 4125+8221+12317+16413=41076 (the lower 4 bits are 0100)
> 2461+6557+10653+14749+16413=50833 (the lower 4 bits are 0001)
> 2461+6573+10669+14765+16413=50881 (the lower 4 bits are 0001)
>
> KMSAN reports this problem when the lower 4 bits became 0001 for the second time.
> Unless KMSAN's reporting is asynchronous, maybe the reason of "for the second time"
> part is that the previous state is relevant...
>
> ----------------------------------------
> [ 157.471712][ T3414] required_size=4125 ret=0
> [ 157.475879][ T3414] required_size=8221 ret=0
> [ 157.480471][ T3414] required_size=12317 ret=0
> [ 157.484604][ T3414] required_size=16413 ret=0
> [ 157.490499][ T3414] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=4096
> [ 157.513772][ T3414] required_size=4125 ret=0
> [ 157.523782][ T3414] required_size=8221 ret=0
> [ 157.533658][ T3414] required_size=12317 ret=0
> [ 157.539579][ T3414] required_size=16413 ret=0
> [ 157.543785][ T3414] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=4096
> [ 157.572869][ T3414] required_size=4125 ret=0
> [ 157.579350][ T3414] required_size=8221 ret=0
> [ 157.584699][ T3414] required_size=12317 ret=0
> [ 157.591756][ T3414] required_size=16413 ret=0
> [ 157.595891][ T3414] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=4096
> [ 157.790734][ T3424] required_size=2461 ret=0
> [ 157.800725][ T3424] required_size=6557 ret=0
> [ 157.804560][ T3424] required_size=10653 ret=0
> [ 157.808433][ T3424] required_size=14749 ret=0
> [ 157.810125][ T3424] required_size=16413 ret=0
> [ 157.829564][ T3424] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=1664
> [ 157.848397][ T3424] required_size=2461 ret=0
> [ 157.854875][ T3424] required_size=6573 ret=0
> [ 157.860883][ T3424] required_size=10669 ret=0
> [ 157.865463][ T3424] required_size=14765 ret=0
> [ 157.871794][ T3424] required_size=16413 ret=0
> [ 157.877333][ T3424] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=1648
> [ 157.885187][ T3424] =====================================================
> [ 157.887262][ T3424] BUG: KMSAN: uninit-value in aes_encrypt+0x1692/0x1fa0
> [ 157.887262][ T3424] aes_encrypt+0x1692/0x1fa0
> [ 157.887262][ T3424] aesti_encrypt+0xe1/0x160
> [ 157.887262][ T3424] crypto_cipher_encrypt_one+0x1d1/0x2e0
> [ 157.887262][ T3424] crypto_cbcmac_digest_update+0x3ff/0x5a0
> [ 157.887262][ T3424] shash_ahash_finup+0x79d/0xd00
> [ 157.887262][ T3424] shash_async_finup+0xbf/0x110
> [ 157.887262][ T3424] crypto_ahash_finup+0x244/0x500
> [ 157.887262][ T3424] crypto_ccm_auth+0x14df/0x15a0
> [ 157.887262][ T3424] crypto_ccm_encrypt+0x2ad/0x8b0
> [ 157.887262][ T3424] crypto_aead_encrypt+0x116/0x1a0
> [ 157.887262][ T3424] tls_push_record+0x2bbe/0x3bf0
> [ 157.887262][ T3424] bpf_exec_tx_verdict+0x5ba/0x2530
> [ 157.887262][ T3424] tls_sw_do_sendpage+0x1779/0x21f0
> [ 157.887262][ T3424] tls_sw_sendpage+0x247/0x2b0
> [ 157.887262][ T3424] inet_sendpage+0x1de/0x2f0
> [ 157.887262][ T3424] kernel_sendpage+0x4cc/0x940
> [ 158.004827][ T3424] sock_sendpage+0x162/0x220
> [ 158.004827][ T3424] pipe_to_sendpage+0x3df/0x4f0
> [ 158.004827][ T3424] __splice_from_pipe+0x5c7/0x1010
> [ 158.004827][ T3424] generic_splice_sendpage+0x1c6/0x2a0
> [ 158.004827][ T3424] do_splice+0x26d8/0x32f0
> [ 158.004827][ T3424] __se_sys_splice+0x81f/0xba0
> [ 158.004827][ T3424] __x64_sys_splice+0x1a1/0x200
> [ 158.004827][ T3424] do_syscall_64+0x41/0x90
> [ 158.004827][ T3424] entry_SYSCALL_64_after_hwframe+0x63/0xcd
> [ 158.004827][ T3424]
> [ 158.004827][ T3424] Uninit was stored to memory at:
> [ 158.004827][ T3424] __crypto_xor+0x285/0x1700
> [ 158.004827][ T3424] crypto_cbcmac_digest_update+0x2ba/0x5a0
> [ 158.004827][ T3424] shash_ahash_finup+0x79d/0xd00
> [ 158.004827][ T3424] shash_async_finup+0xbf/0x110
> [ 158.004827][ T3424] crypto_ahash_finup+0x244/0x500
> [ 158.004827][ T3424] crypto_ccm_auth+0x14df/0x15a0
> [ 158.004827][ T3424] crypto_ccm_encrypt+0x2ad/0x8b0
> [ 158.004827][ T3424] crypto_aead_encrypt+0x116/0x1a0
> [ 158.004827][ T3424] tls_push_record+0x2bbe/0x3bf0
> [ 158.004827][ T3424] bpf_exec_tx_verdict+0x5ba/0x2530
> [ 158.004827][ T3424] tls_sw_do_sendpage+0x1779/0x21f0
> [ 158.004827][ T3424] tls_sw_sendpage+0x247/0x2b0
> [ 158.004827][ T3424] inet_sendpage+0x1de/0x2f0
> [ 158.004827][ T3424] kernel_sendpage+0x4cc/0x940
> [ 158.004827][ T3424] sock_sendpage+0x162/0x220
> [ 158.004827][ T3424] pipe_to_sendpage+0x3df/0x4f0
> [ 158.004827][ T3424] __splice_from_pipe+0x5c7/0x1010
> [ 158.004827][ T3424] generic_splice_sendpage+0x1c6/0x2a0
> [ 158.004827][ T3424] do_splice+0x26d8/0x32f0
> [ 158.004827][ T3424] __se_sys_splice+0x81f/0xba0
> [ 158.004827][ T3424] __x64_sys_splice+0x1a1/0x200
> [ 158.004827][ T3424] do_syscall_64+0x41/0x90
> [ 158.004827][ T3424] entry_SYSCALL_64_after_hwframe+0x63/0xcd
> [ 158.004827][ T3424]
> [ 158.004827][ T3424] Uninit was created at:
> [ 158.004827][ T3424] __alloc_pages+0x925/0x1050
> [ 158.004827][ T3424] alloc_pages+0xe30/0x11b0
> [ 158.004827][ T3424] skb_page_frag_refill+0x362/0x910
> [ 158.004827][ T3424] sk_page_frag_refill+0xa2/0x1c0
> [ 158.004827][ T3424] sk_msg_alloc+0x278/0x1560
> [ 158.004827][ T3424] tls_sw_do_sendpage+0xbec/0x21f0
> [ 158.004827][ T3424] tls_sw_sendpage+0x247/0x2b0
> [ 158.004827][ T3424] inet_sendpage+0x1de/0x2f0
> [ 158.004827][ T3424] kernel_sendpage+0x4cc/0x940
> [ 158.004827][ T3424] sock_sendpage+0x162/0x220
> [ 158.004827][ T3424] pipe_to_sendpage+0x3df/0x4f0
> [ 158.004827][ T3424] __splice_from_pipe+0x5c7/0x1010
> [ 158.004827][ T3424] generic_splice_sendpage+0x1c6/0x2a0
> [ 158.260226][ T3424] do_splice+0x26d8/0x32f0
> [ 158.260226][ T3424] __se_sys_splice+0x81f/0xba0
> [ 158.260226][ T3424] __x64_sys_splice+0x1a1/0x200
> [ 158.260226][ T3424] do_syscall_64+0x41/0x90
> [ 158.260226][ T3424] entry_SYSCALL_64_after_hwframe+0x63/0xcd
> [ 158.260226][ T3424]
> [ 158.260226][ T3424] CPU: 7 PID: 3424 Comm: a.out Not tainted 6.4.0-rc7-ge6bc8833d80f-dirty #26
> [ 158.260226][ T3424] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [ 158.260226][ T3424] =====================================================
> [ 158.260226][ T3424] Disabling lock debugging due to kernel taint
> [ 158.260226][ T3424] Kernel panic - not syncing: kmsan.panic set ...
> [ 158.260226][ T3424] CPU: 7 PID: 3424 Comm: a.out Tainted: G B 6.4.0-rc7-ge6bc8833d80f-dirty #26
> [ 158.320898][ T3424] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [ 158.334186][ T3424] Call Trace:
> [ 158.334186][ T3424] <TASK>
> [ 158.334186][ T3424] dump_stack_lvl+0x1f6/0x280
> [ 158.334186][ T3424] dump_stack+0x29/0x30
> [ 158.334186][ T3424] panic+0x4e7/0xc60
> [ 158.334186][ T3424] ? add_taint+0x185/0x210
> [ 158.334186][ T3424] kmsan_report+0x2d1/0x2e0
> [ 158.334186][ T3424] ? __msan_warning+0x98/0x120
> [ 158.334186][ T3424] ? aes_encrypt+0x1692/0x1fa0
> [ 158.334186][ T3424] ? aesti_encrypt+0xe1/0x160
> [ 158.334186][ T3424] ? crypto_cipher_encrypt_one+0x1d1/0x2e0
> [ 158.334186][ T3424] ? crypto_cbcmac_digest_update+0x3ff/0x5a0
> [ 158.334186][ T3424] ? shash_ahash_finup+0x79d/0xd00
> [ 158.334186][ T3424] ? shash_async_finup+0xbf/0x110
> [ 158.334186][ T3424] ? crypto_ahash_finup+0x244/0x500
> [ 158.334186][ T3424] ? crypto_ccm_auth+0x14df/0x15a0
> [ 158.334186][ T3424] ? crypto_ccm_encrypt+0x2ad/0x8b0
> [ 158.334186][ T3424] ? crypto_aead_encrypt+0x116/0x1a0
> [ 158.334186][ T3424] ? tls_push_record+0x2bbe/0x3bf0
> [ 158.334186][ T3424] ? bpf_exec_tx_verdict+0x5ba/0x2530
> [ 158.334186][ T3424] ? tls_sw_do_sendpage+0x1779/0x21f0
> [ 158.334186][ T3424] ? tls_sw_sendpage+0x247/0x2b0
> [ 158.334186][ T3424] ? inet_sendpage+0x1de/0x2f0
> [ 158.334186][ T3424] ? kernel_sendpage+0x4cc/0x940
> [ 158.334186][ T3424] ? sock_sendpage+0x162/0x220
> [ 158.334186][ T3424] ? pipe_to_sendpage+0x3df/0x4f0
> [ 158.334186][ T3424] ? __splice_from_pipe+0x5c7/0x1010
> [ 158.334186][ T3424] ? generic_splice_sendpage+0x1c6/0x2a0
> [ 158.334186][ T3424] ? do_splice+0x26d8/0x32f0
> [ 158.334186][ T3424] ? __se_sys_splice+0x81f/0xba0
> [ 158.334186][ T3424] ? __x64_sys_splice+0x1a1/0x200
> [ 158.334186][ T3424] ? do_syscall_64+0x41/0x90
> [ 158.334186][ T3424] ? entry_SYSCALL_64_after_hwframe+0x63/0xcd
> [ 158.334186][ T3424] ? filter_irq_stacks+0xb9/0x230
> [ 158.334186][ T3424] ? __stack_depot_save+0x22/0x490
> [ 158.334186][ T3424] ? kmsan_internal_set_shadow_origin+0x66/0xe0
> [ 158.334186][ T3424] ? kmsan_internal_chain_origin+0x110/0x120
> [ 158.334186][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
> [ 158.334186][ T3424] __msan_warning+0x98/0x120
> [ 158.334186][ T3424] aes_encrypt+0x1692/0x1fa0
> [ 158.334186][ T3424] aesti_encrypt+0xe1/0x160
> [ 158.334186][ T3424] crypto_cipher_encrypt_one+0x1d1/0x2e0
> [ 158.334186][ T3424] ? aesti_set_key+0xb0/0xb0
> [ 158.334186][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
> [ 158.334186][ T3424] crypto_cbcmac_digest_update+0x3ff/0x5a0
> [ 158.334186][ T3424] ? crypto_cbcmac_digest_init+0x140/0x140
> [ 158.334186][ T3424] shash_ahash_finup+0x79d/0xd00
> [ 158.334186][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
> [ 158.334186][ T3424] shash_async_finup+0xbf/0x110
> [ 158.334186][ T3424] crypto_ahash_finup+0x244/0x500
> [ 158.334186][ T3424] ? shash_async_final+0x3d0/0x3d0
> [ 158.334186][ T3424] crypto_ccm_auth+0x14df/0x15a0
> [ 158.334186][ T3424] crypto_ccm_encrypt+0x2ad/0x8b0
> [ 158.334186][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
> [ 158.334186][ T3424] ? crypto_ccm_setauthsize+0x100/0x100
> [ 158.334186][ T3424] crypto_aead_encrypt+0x116/0x1a0
> [ 158.653332][ T3424] tls_push_record+0x2bbe/0x3bf0
> [ 158.653332][ T3424] bpf_exec_tx_verdict+0x5ba/0x2530
> [ 158.653332][ T3424] ? _printk+0x181/0x1b0
> [ 158.653332][ T3424] ? tls_sw_do_sendpage+0xc81/0x21f0
> [ 158.653332][ T3424] tls_sw_do_sendpage+0x1779/0x21f0
> [ 158.653332][ T3424] tls_sw_sendpage+0x247/0x2b0
> [ 158.653332][ T3424] ? tls_sw_do_sendpage+0x21f0/0x21f0
> [ 158.653332][ T3424] inet_sendpage+0x1de/0x2f0
> [ 158.653332][ T3424] ? inet_sendmsg+0x1d0/0x1d0
> [ 158.653332][ T3424] kernel_sendpage+0x4cc/0x940
> [ 158.653332][ T3424] sock_sendpage+0x162/0x220
> [ 158.653332][ T3424] pipe_to_sendpage+0x3df/0x4f0
> [ 158.653332][ T3424] ? sock_fasync+0x240/0x240
> [ 158.653332][ T3424] __splice_from_pipe+0x5c7/0x1010
> [ 158.653332][ T3424] ? generic_splice_sendpage+0x2a0/0x2a0
> [ 158.653332][ T3424] generic_splice_sendpage+0x1c6/0x2a0
> [ 158.653332][ T3424] ? iter_file_splice_write+0x1a30/0x1a30
> [ 158.653332][ T3424] do_splice+0x26d8/0x32f0
> [ 158.653332][ T3424] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
> [ 158.653332][ T3424] ? __se_sys_splice+0x292/0xba0
> [ 158.653332][ T3424] ? __msan_metadata_ptr_for_load_8+0x24/0x40
> [ 158.653332][ T3424] ? filter_irq_stacks+0xb9/0x230
> [ 158.653332][ T3424] __se_sys_splice+0x81f/0xba0
> [ 158.870673][ T3424] __x64_sys_splice+0x1a1/0x200
> [ 158.870673][ T3424] do_syscall_64+0x41/0x90
> [ 158.870673][ T3424] entry_SYSCALL_64_after_hwframe+0x63/0xcd
> [ 158.870673][ T3424] RIP: 0033:0x7f6bbd51ea3d
> [ 158.895223][ T3424] Code: 5b 41 5c c3 66 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d c3 a3 0f 00 f7 d8 64 89 01 48
> [ 158.895223][ T3424] RSP: 002b:00007f6bbd731e08 EFLAGS: 00000246 ORIG_RAX: 0000000000000113
> [ 158.895223][ T3424] RAX: ffffffffffffffda RBX: 000055ccd9ea6080 RCX: 00007f6bbd51ea3d
> [ 158.895223][ T3424] RDX: 0000000000000004 RSI: 0000000000000000 RDI: 0000000000000003
> [ 158.895223][ T3424] RBP: 000055ccd9ea41f4 R08: 00080000fffffffc R09: 0000000000000000
> [ 158.895223][ T3424] R10: 0000000000000000 R11: 0000000000000246 R12: 0100000000000000
> [ 158.895223][ T3424] R13: e65b75b4ec4292eb R14: f2300cdb85a45425 R15: 000055ccd9ea6088
> [ 159.041467][ T3424] </TASK>
> [ 159.041467][ T3424] Kernel Offset: disabled
> [ 159.041467][ T3424] Rebooting in 10 seconds..
> ----------------------------------------
>
> >
> > Could you explain why that bug contains ~50 reports that seem entirely
> > unrelated? AIUI, this actual issue has not been reproduced since
> > 2020??
>
> Multiple different bugs are reported as the same problem.
> Reproducer is available for only bpf_exec_tx_verdict() one, and the reproducer still works.
>
> >
> >
> >> Config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=ee5f7a0b2e48ed66
> >> Report: https://syzkaller.appspot.com/text?tag=CrashReport&x=1325260d900000
> >> Syz repro: https://syzkaller.appspot.com/text?tag=ReproSyz&x=11af973e900000
> >> C repro: https://syzkaller.appspot.com/text?tag=ReproC&x=163a1e45900000
> >>
> >> The bug is reproducible for me locally as well (and Tetsuo's patch
> >> makes it disappear, although I have no opinion on its correctness).
> >
> > What I'd like to do is run a kernel plus initrd locally in OVMF and
> > reproduce the issue - can I do that without all the syzkaller
> > machinery?
>
> I'm using Ubuntu 22.04 on Oracle VM VirtualBox.
> I don't know if this can be reproduced with kernel plus initrd only. But
> since the C reproducer is standalone, syzkaller machinery is not involved.
>
> > >>>
> > >>> Could you please share your kernel config and the resulting kernel log
> > >>> when running the reproducer? I'll try to reproduce locally as well,
> > >>> and see if I can figure out what is going on in the crypto layer
> > >>
> > >> The config together with the repro is available at
> > >> https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
> > >> latest row of the "Crashes" table that contains a C repro.
> >
> > Kernel is commit e6bc8833d80f of https://github.com/google/kmsan/commits/master .
>
> That commit does not exist in that repo. Does it matter?
Apologies for this mess.
https://github.com/google/kmsan/commits/master is force-updated once a
week to point to the latest release candidate with KMSAN-specific
patches.
Older releases are called e.g. kmsan-v6.4-rc7.
Right now there's only one patch required to run torvalds/master with
KMSAN (https://github.com/google/kmsan/commit/e6bc8833d80f).
That patch will hit upstream in v6.5-rc1, after which I am going to
switch syzbot to test upstream.
For such a long-standing bug the exact version of KMSAN shouldn't matter.
On Fri, Jun 30, 2023 at 12:18 PM Ard Biesheuvel <[email protected]> wrote:
>
> On Fri, 30 Jun 2023 at 12:11, Alexander Potapenko <[email protected]> wrote:
> >
> > On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
> > >
> > > On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
> > > <[email protected]> wrote:
> > > >
> > > > On 2023/06/30 18:36, Ard Biesheuvel wrote:
> > > > > Why are you sending this now?
> > > >
> > > > Just because this is currently top crasher and I can reproduce locally.
> > > >
> > > > > Do you have a reproducer for this issue?
> > > >
> > > > Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
> > > >
> > >
> > > Could you please share your kernel config and the resulting kernel log
> > > when running the reproducer? I'll try to reproduce locally as well,
> > > and see if I can figure out what is going on in the crypto layer
> >
> > The config together with the repro is available at
> > https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
> > latest row of the "Crashes" table that contains a C repro.
>
> Could you explain why that bug contains ~50 reports that seem entirely
> unrelated?
These are some unfortunate effects of syzbot trying to deduplicate
bugs. There's a tradeoff between reporting every single crash
separately and grouping together those that have e.g. the same origin.
Applying this algorithm transitively results in bigger clusters
containing unwanted reports.
We'll look closer.
> AIUI, this actual issue has not been reproduced since
> 2020??
Oh, sorry, I misread the table and misinformed you. The topmost row of
the table is indeed the _oldest_ one.
Another manifestation of the bug was on 2023/05/23
(https://syzkaller.appspot.com/text?tag=CrashReport&x=146f66b1280000)
>
> > Config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=ee5f7a0b2e48ed66
> > Report: https://syzkaller.appspot.com/text?tag=CrashReport&x=1325260d900000
> > Syz repro: https://syzkaller.appspot.com/text?tag=ReproSyz&x=11af973e900000
> > C repro: https://syzkaller.appspot.com/text?tag=ReproC&x=163a1e45900000
> >
> > The bug is reproducible for me locally as well (and Tetsuo's patch
> > makes it disappear, although I have no opinion on its correctness).
>
> What I'd like to do is run a kernel plus initrd locally in OVMF and
> reproduce the issue - can I do that without all the syzkaller
> machinery?
You can build the kernel from the config linked above, that's what I
did to reproduce it locally.
As for initrd, there are disk images attached to the reports, will that help?
E.g.
$ wget https://storage.googleapis.com/syzbot-assets/79bb4ff7cc58/disk-f93f2fed.raw.xz
$ unxz disk-f93f2fed.raw.xz
$ qemu-system-x86_64 -smp 2,sockets=2,cores=1 -m 4G -drive
file=disk-f93f2fed.raw -snapshot -nographic -enable-kvm
lets me boot syzkaller with the disk/kernel from that report of 2023/05/23.
Adding "-net user,hostfwd=tcp::10022-:22 -net nic,model=e1000" I am
also able to SSH into the machine (there's no password):
$ ssh -o "StrictHostKeyChecking no" -p 10022 root@localhost
Then the repro can be downloaded and executed:
$ wget "https://syzkaller.appspot.com/text?tag=ReproC&x=163a1e45900000" -O t.c
$ gcc t.c -static -o t
$ scp -o "StrictHostKeyChecking no" -P 10022 t root@localhost:
$ ssh -o "StrictHostKeyChecking no" -p 10022 root@localhost ./t
Within a couple minutes the kernel crashes with the report:
[ 151.522472][ T5865] =====================================================
[ 151.523843][ T5865] BUG: KMSAN: uninit-value in aes_encrypt+0x15cc/0x1db0
[ 151.525120][ T5865] aes_encrypt+0x15cc/0x1db0
[ 151.526113][ T5865] aesti_encrypt+0x7d/0xf0
[ 151.527057][ T5865] crypto_cipher_encrypt_one+0x112/0x200
[ 151.528224][ T5865] crypto_cbcmac_digest_update+0x301/0x4b0
The vmlinux binary (also available at the syzbot page) can be used to
symbolize this report, but perhaps at this point you'd love to switch
to your own kernel.
--
Alexander Potapenko
Software Engineer
Google Germany GmbH
Erika-Mann-Straße, 33
80636 München
Geschäftsführer: Paul Manicle, Liana Sebastian
Registergericht und -nummer: Hamburg, HRB 86891
Sitz der Gesellschaft: Hamburg
On Fri, 30 Jun 2023 at 13:38, Alexander Potapenko <[email protected]> wrote:
>
> On Fri, Jun 30, 2023 at 12:18 PM Ard Biesheuvel <[email protected]> wrote:
> >
> > On Fri, 30 Jun 2023 at 12:11, Alexander Potapenko <[email protected]> wrote:
> > >
> > > On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
> > > >
> > > > On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
> > > > <[email protected]> wrote:
> > > > >
> > > > > On 2023/06/30 18:36, Ard Biesheuvel wrote:
> > > > > > Why are you sending this now?
> > > > >
> > > > > Just because this is currently top crasher and I can reproduce locally.
> > > > >
> > > > > > Do you have a reproducer for this issue?
> > > > >
> > > > > Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
> > > > >
> > > >
> > > > Could you please share your kernel config and the resulting kernel log
> > > > when running the reproducer? I'll try to reproduce locally as well,
> > > > and see if I can figure out what is going on in the crypto layer
> > >
> > > The config together with the repro is available at
> > > https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
> > > latest row of the "Crashes" table that contains a C repro.
> >
> > Could you explain why that bug contains ~50 reports that seem entirely
> > unrelated?
>
> These are some unfortunate effects of syzbot trying to deduplicate
> bugs. There's a tradeoff between reporting every single crash
> separately and grouping together those that have e.g. the same origin.
> Applying this algorithm transitively results in bigger clusters
> containing unwanted reports.
> We'll look closer.
>
> > AIUI, this actual issue has not been reproduced since
> > 2020??
>
> Oh, sorry, I misread the table and misinformed you. The topmost row of
> the table is indeed the _oldest_ one.
> Another manifestation of the bug was on 2023/05/23
> (https://syzkaller.appspot.com/text?tag=CrashReport&x=146f66b1280000)
>
That one has nothing to do with networking, so I don't see how this
patch would affect it.
>
> >
> > > Config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=ee5f7a0b2e48ed66
> > > Report: https://syzkaller.appspot.com/text?tag=CrashReport&x=1325260d900000
> > > Syz repro: https://syzkaller.appspot.com/text?tag=ReproSyz&x=11af973e900000
> > > C repro: https://syzkaller.appspot.com/text?tag=ReproC&x=163a1e45900000
> > >
> > > The bug is reproducible for me locally as well (and Tetsuo's patch
> > > makes it disappear, although I have no opinion on its correctness).
> >
> > What I'd like to do is run a kernel plus initrd locally in OVMF and
> > reproduce the issue - can I do that without all the syzkaller
> > machinery?
>
> You can build the kernel from the config linked above, that's what I
> did to reproduce it locally.
> As for initrd, there are disk images attached to the reports, will that help?
>
> E.g.
> $ wget https://storage.googleapis.com/syzbot-assets/79bb4ff7cc58/disk-f93f2fed.raw.xz
> $ unxz disk-f93f2fed.raw.xz
> $ qemu-system-x86_64 -smp 2,sockets=2,cores=1 -m 4G -drive
> file=disk-f93f2fed.raw -snapshot -nographic -enable-kvm
>
> lets me boot syzkaller with the disk/kernel from that report of 2023/05/23.
> Adding "-net user,hostfwd=tcp::10022-:22 -net nic,model=e1000" I am
> also able to SSH into the machine (there's no password):
>
> $ ssh -o "StrictHostKeyChecking no" -p 10022 root@localhost
>
> Then the repro can be downloaded and executed:
>
> $ wget "https://syzkaller.appspot.com/text?tag=ReproC&x=163a1e45900000" -O t.c
> $ gcc t.c -static -o t
> $ scp -o "StrictHostKeyChecking no" -P 10022 t root@localhost:
> $ ssh -o "StrictHostKeyChecking no" -p 10022 root@localhost ./t
>
> Within a couple minutes the kernel crashes with the report:
>
> [ 151.522472][ T5865] =====================================================
> [ 151.523843][ T5865] BUG: KMSAN: uninit-value in aes_encrypt+0x15cc/0x1db0
> [ 151.525120][ T5865] aes_encrypt+0x15cc/0x1db0
> [ 151.526113][ T5865] aesti_encrypt+0x7d/0xf0
> [ 151.527057][ T5865] crypto_cipher_encrypt_one+0x112/0x200
> [ 151.528224][ T5865] crypto_cbcmac_digest_update+0x301/0x4b0
>
OK, thanks for the instructions.
Out of curiosity - does the stack trace you cut off here include the
BPF routine mentioned in the report?
On Fri, Jun 30, 2023 at 1:49 PM Ard Biesheuvel <[email protected]> wrote:
>
> On Fri, 30 Jun 2023 at 13:38, Alexander Potapenko <[email protected]> wrote:
> >
> > On Fri, Jun 30, 2023 at 12:18 PM Ard Biesheuvel <[email protected]> wrote:
> > >
> > > On Fri, 30 Jun 2023 at 12:11, Alexander Potapenko <[email protected]> wrote:
> > > >
> > > > On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
> > > > >
> > > > > On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
> > > > > <[email protected]> wrote:
> > > > > >
> > > > > > On 2023/06/30 18:36, Ard Biesheuvel wrote:
> > > > > > > Why are you sending this now?
> > > > > >
> > > > > > Just because this is currently top crasher and I can reproduce locally.
> > > > > >
> > > > > > > Do you have a reproducer for this issue?
> > > > > >
> > > > > > Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
> > > > > >
> > > > >
> > > > > Could you please share your kernel config and the resulting kernel log
> > > > > when running the reproducer? I'll try to reproduce locally as well,
> > > > > and see if I can figure out what is going on in the crypto layer
> > > >
> > > > The config together with the repro is available at
> > > > https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
> > > > latest row of the "Crashes" table that contains a C repro.
> > >
> > > Could you explain why that bug contains ~50 reports that seem entirely
> > > unrelated?
> >
> > These are some unfortunate effects of syzbot trying to deduplicate
> > bugs. There's a tradeoff between reporting every single crash
> > separately and grouping together those that have e.g. the same origin.
> > Applying this algorithm transitively results in bigger clusters
> > containing unwanted reports.
> > We'll look closer.
> >
> > > AIUI, this actual issue has not been reproduced since
> > > 2020??
> >
> > Oh, sorry, I misread the table and misinformed you. The topmost row of
> > the table is indeed the _oldest_ one.
> > Another manifestation of the bug was on 2023/05/23
> > (https://syzkaller.appspot.com/text?tag=CrashReport&x=146f66b1280000)
> >
>
> That one has nothing to do with networking, so I don't see how this
> patch would affect it.
I definitely have to be more attentive.
You are right that this bug report is also unrelated. Yet it is still
fine to use the build artifacts corresponding to it (which is what I
did).
I'll investigate why so many reports got clustered into this one.
> OK, thanks for the instructions.
>
> Out of curiosity - does the stack trace you cut off here include the
> BPF routine mentioned in the report?
It does:
[ 151.522472][ T5865] =====================================================
[ 151.523843][ T5865] BUG: KMSAN: uninit-value in aes_encrypt+0x15cc/0x1db0
[ 151.525120][ T5865] aes_encrypt+0x15cc/0x1db0
[ 151.526113][ T5865] aesti_encrypt+0x7d/0xf0
[ 151.527057][ T5865] crypto_cipher_encrypt_one+0x112/0x200
[ 151.528224][ T5865] crypto_cbcmac_digest_update+0x301/0x4b0
[ 151.529459][ T5865] shash_ahash_finup+0x66e/0xc00
[ 151.530541][ T5865] shash_async_finup+0x7f/0xc0
[ 151.531542][ T5865] crypto_ahash_finup+0x1b8/0x3e0
[ 151.532583][ T5865] crypto_ccm_auth+0x1269/0x1350
[ 151.533606][ T5865] crypto_ccm_encrypt+0x1c9/0x7a0
[ 151.534650][ T5865] crypto_aead_encrypt+0xe0/0x150
[ 151.535695][ T5865] tls_push_record+0x3bf3/0x4ec0
[ 151.539491][ T5865] bpf_exec_tx_verdict+0x46e/0x21d0
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[ 151.540597][ T5865] tls_sw_do_sendpage+0x1150/0x1ad0
[ 151.541594][ T5865] tls_sw_sendpage+0x15b/0x1b0
[ 151.542500][ T5865] inet_sendpage+0x138/0x210
[ 151.543365][ T5865] kernel_sendpage+0x34c/0x6d0
[ 151.544269][ T5865] sock_sendpage+0xb0/0x160
[ 151.545117][ T5865] pipe_to_sendpage+0x304/0x3f0
[ 151.546051][ T5865] __splice_from_pipe+0x438/0xc20
[ 151.547013][ T5865] generic_splice_sendpage+0x100/0x160
[ 151.548068][ T5865] do_splice+0x213b/0x2d10
[ 151.548933][ T5865] __se_sys_splice+0x5ad/0x8f0
[ 151.549851][ T5865] __x64_sys_splice+0x11b/0x1a0
[ 151.550790][ T5865] do_syscall_64+0x41/0xc0
[ 151.551646][ T5865] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 151.552773][ T5865]
[ 151.553220][ T5865] Uninit was stored to memory at:
[ 151.554212][ T5865] __crypto_xor+0x171/0x1310
[ 151.555062][ T5865] crypto_cbcmac_digest_update+0x208/0x4b0
[ 151.556132][ T5865] shash_ahash_finup+0x66e/0xc00
[ 151.557084][ T5865] shash_async_finup+0x7f/0xc0
[ 151.557989][ T5865] crypto_ahash_finup+0x1b8/0x3e0
[ 151.558941][ T5865] crypto_ccm_auth+0x1269/0x1350
[ 151.559874][ T5865] crypto_ccm_encrypt+0x1c9/0x7a0
[ 151.560812][ T5865] crypto_aead_encrypt+0xe0/0x150
[ 151.561749][ T5865] tls_push_record+0x3bf3/0x4ec0
[ 151.562835][ T5865] bpf_exec_tx_verdict+0x46e/0x21d0
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[ 151.563967][ T5865] tls_sw_do_sendpage+0x1150/0x1ad0
[ 151.565075][ T5865] tls_sw_sendpage+0x15b/0x1b0
[ 151.566107][ T5865] inet_sendpage+0x138/0x210
[ 151.567078][ T5865] kernel_sendpage+0x34c/0x6d0
[ 151.568087][ T5865] sock_sendpage+0xb0/0x160
[ 151.568960][ T5865] pipe_to_sendpage+0x304/0x3f0
[ 151.569909][ T5865] __splice_from_pipe+0x438/0xc20
[ 151.570886][ T5865] generic_splice_sendpage+0x100/0x160
[ 151.571946][ T5865] do_splice+0x213b/0x2d10
[ 151.572810][ T5865] __se_sys_splice+0x5ad/0x8f0
[ 151.573732][ T5865] __x64_sys_splice+0x11b/0x1a0
[ 151.574664][ T5865] do_syscall_64+0x41/0xc0
[ 151.575513][ T5865] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 151.576640][ T5865]
[ 151.577084][ T5865] Uninit was created at:
[ 151.577949][ T5865] __alloc_pages+0x9a4/0xe00
[ 151.578849][ T5865] alloc_pages+0xd01/0x1040
[ 151.579729][ T5865] skb_page_frag_refill+0x2bf/0x7c0
[ 151.580752][ T5865] sk_page_frag_refill+0x59/0x130
[ 151.581720][ T5865] sk_msg_alloc+0x198/0x10d0
[ 151.582611][ T5865] tls_sw_do_sendpage+0x98a/0x1ad0
[ 151.583599][ T5865] tls_sw_sendpage+0x15b/0x1b0
[ 151.584535][ T5865] inet_sendpage+0x138/0x210
[ 151.585404][ T5865] kernel_sendpage+0x34c/0x6d0
[ 151.586275][ T5865] sock_sendpage+0xb0/0x160
[ 151.587099][ T5865] pipe_to_sendpage+0x304/0x3f0
[ 151.588023][ T5865] __splice_from_pipe+0x438/0xc20
[ 151.588981][ T5865] generic_splice_sendpage+0x100/0x160
[ 151.590032][ T5865] do_splice+0x213b/0x2d10
[ 151.590910][ T5865] __se_sys_splice+0x5ad/0x8f0
[ 151.591840][ T5865] __x64_sys_splice+0x11b/0x1a0
[ 151.592780][ T5865] do_syscall_64+0x41/0xc0
[ 151.593748][ T5865] entry_SYSCALL_64_after_hwframe+0x63/0xcd
--
Alexander Potapenko
Software Engineer
Google Germany GmbH
Erika-Mann-Straße, 33
80636 München
Geschäftsführer: Paul Manicle, Liana Sebastian
Registergericht und -nummer: Hamburg, HRB 86891
Sitz der Gesellschaft: Hamburg
On Fri, 30 Jun 2023 at 13:55, Alexander Potapenko <[email protected]> wrote:
>
> On Fri, Jun 30, 2023 at 1:49 PM Ard Biesheuvel <[email protected]> wrote:
> >
> > On Fri, 30 Jun 2023 at 13:38, Alexander Potapenko <[email protected]> wrote:
> > >
> > > On Fri, Jun 30, 2023 at 12:18 PM Ard Biesheuvel <[email protected]> wrote:
> > > >
> > > > On Fri, 30 Jun 2023 at 12:11, Alexander Potapenko <[email protected]> wrote:
> > > > >
> > > > > On Fri, Jun 30, 2023 at 12:02 PM Ard Biesheuvel <[email protected]> wrote:
> > > > > >
> > > > > > On Fri, 30 Jun 2023 at 11:53, Tetsuo Handa
> > > > > > <[email protected]> wrote:
> > > > > > >
> > > > > > > On 2023/06/30 18:36, Ard Biesheuvel wrote:
> > > > > > > > Why are you sending this now?
> > > > > > >
> > > > > > > Just because this is currently top crasher and I can reproduce locally.
> > > > > > >
> > > > > > > > Do you have a reproducer for this issue?
> > > > > > >
> > > > > > > Yes. https://syzkaller.appspot.com/text?tag=ReproC&x=12931621900000 works.
> > > > > > >
> > > > > >
> > > > > > Could you please share your kernel config and the resulting kernel log
> > > > > > when running the reproducer? I'll try to reproduce locally as well,
> > > > > > and see if I can figure out what is going on in the crypto layer
> > > > >
> > > > > The config together with the repro is available at
> > > > > https://syzkaller.appspot.com/bug?extid=828dfc12440b4f6f305d, see the
> > > > > latest row of the "Crashes" table that contains a C repro.
> > > >
> > > > Could you explain why that bug contains ~50 reports that seem entirely
> > > > unrelated?
> > >
> > > These are some unfortunate effects of syzbot trying to deduplicate
> > > bugs. There's a tradeoff between reporting every single crash
> > > separately and grouping together those that have e.g. the same origin.
> > > Applying this algorithm transitively results in bigger clusters
> > > containing unwanted reports.
> > > We'll look closer.
> > >
> > > > AIUI, this actual issue has not been reproduced since
> > > > 2020??
> > >
> > > Oh, sorry, I misread the table and misinformed you. The topmost row of
> > > the table is indeed the _oldest_ one.
> > > Another manifestation of the bug was on 2023/05/23
> > > (https://syzkaller.appspot.com/text?tag=CrashReport&x=146f66b1280000)
> > >
> >
> > That one has nothing to do with networking, so I don't see how this
> > patch would affect it.
>
> I definitely have to be more attentive.
> You are right that this bug report is also unrelated. Yet it is still
> fine to use the build artifacts corresponding to it (which is what I
> did).
> I'll investigate why so many reports got clustered into this one.
>
>
>
> > OK, thanks for the instructions.
> >
> > Out of curiosity - does the stack trace you cut off here include the
> > BPF routine mentioned in the report?
>
> It does:
>
> [ 151.522472][ T5865] =====================================================
> [ 151.523843][ T5865] BUG: KMSAN: uninit-value in aes_encrypt+0x15cc/0x1db0
> [ 151.525120][ T5865] aes_encrypt+0x15cc/0x1db0
> [ 151.526113][ T5865] aesti_encrypt+0x7d/0xf0
> [ 151.527057][ T5865] crypto_cipher_encrypt_one+0x112/0x200
> [ 151.528224][ T5865] crypto_cbcmac_digest_update+0x301/0x4b0
> [ 151.529459][ T5865] shash_ahash_finup+0x66e/0xc00
> [ 151.530541][ T5865] shash_async_finup+0x7f/0xc0
> [ 151.531542][ T5865] crypto_ahash_finup+0x1b8/0x3e0
> [ 151.532583][ T5865] crypto_ccm_auth+0x1269/0x1350
> [ 151.533606][ T5865] crypto_ccm_encrypt+0x1c9/0x7a0
> [ 151.534650][ T5865] crypto_aead_encrypt+0xe0/0x150
> [ 151.535695][ T5865] tls_push_record+0x3bf3/0x4ec0
> [ 151.539491][ T5865] bpf_exec_tx_verdict+0x46e/0x21d0
> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> [ 151.540597][ T5865] tls_sw_do_sendpage+0x1150/0x1ad0
OK, so after poking around a little bit, I have managed to confirm
that the problem is in the TLS layer, and I am a bit out of my depth
debugging that.
With the debugging code below applied, KMSAN triggers on an
uninit-memory in the input scatterlist provided by the TLS layer into
the CCM code.
[ 148.375852][ T2424] =====================================================
[ 148.377269][ T2424] BUG: KMSAN: uninit-value in tls_push_record+0x2d9f/0x3eb0
[ 148.378623][ T2424] tls_push_record+0x2d9f/0x3eb0
[ 148.379559][ T2424] bpf_exec_tx_verdict+0x5ba/0x2530
[ 148.380534][ T2424] tls_sw_do_sendpage+0x169c/0x1f80
[ 148.381519][ T2424] tls_sw_sendpage+0x247/0x2b0
...
[ 148.411559][ T2424]
[ 148.412108][ T2424] Bytes 0-15 of 16 are uninitialized
[ 148.413379][ T2424] Memory access of size 16 starts at ffff8880157889c7
Note that this is the *input* scatterlist containing the AAD
(additional authenticated data) and the crypto input, and so there is
definitely a bug here that shouldn't be papered over by zero'ing the
allocation.
--- a/net/tls/tls_sw.c
+++ b/net/tls/tls_sw.c
@@ -543,6 +543,21 @@ static int tls_do_encryption(struct sock *sk,
list_add_tail((struct list_head *)&rec->list, &ctx->tx_list);
atomic_inc(&ctx->encrypt_pending);
+ {
+ int len = aead_req->assoclen + aead_req->cryptlen;
+ struct sg_mapping_iter miter;
+
+ sg_miter_start(&miter, rec->sg_aead_in,
+ sg_nents(rec->sg_aead_in),
+ SG_MITER_TO_SG | SG_MITER_ATOMIC);
+
+ while (len > 0 && sg_miter_next(&miter)) {
+ kmsan_check_memory(miter.addr, min(len,
(int)miter.length));
+ len -= miter.length;
+ }
+ sg_miter_stop(&miter);
+ }
+
The reason that this cascades all the way down to the AES cipher code
appears to be that sbox substitution involves array indexing, which is
one of the actions KMSAN qualifies as 'use' of uninit data.
On Fri, 30 Jun 2023 17:16:06 +0200 Ard Biesheuvel wrote:
> Note that this is the *input* scatterlist containing the AAD
> (additional authenticated data) and the crypto input, and so there is
> definitely a bug here that shouldn't be papered over by zero'ing the
> allocation.
Noob question, it's not the tag / AAD, right? We definitely don't init
that..
On Fri, 30 Jun 2023 at 17:27, Jakub Kicinski <[email protected]> wrote:
>
> On Fri, 30 Jun 2023 17:16:06 +0200 Ard Biesheuvel wrote:
> > Note that this is the *input* scatterlist containing the AAD
> > (additional authenticated data) and the crypto input, and so there is
> > definitely a bug here that shouldn't be papered over by zero'ing the
> > allocation.
>
> Noob question, it's not the tag / AAD, right? We definitely don't init
> that..
assoclen + cryptlen does not cover the tag on encryption, so it would
be omitted here regardless of whether it was covered in the input
scatterlist or not.
I'm trying to write a simplified reproducer that reproduces
----------------------------------------
[ 162.905919][ T3399] required_size=2461 ret=0
[ 162.916796][ T3399] required_size=6557 ret=0
[ 162.919587][ T3399] required_size=10653 ret=0
[ 162.923090][ T3399] required_size=14749 ret=0
[ 162.928686][ T3399] required_size=16413 ret=0
[ 162.936894][ T3399] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=1664
[ 162.962097][ T3399] required_size=2461 ret=0
[ 162.967270][ T3399] required_size=6557 ret=0
[ 162.992866][ T3399] required_size=10653 ret=0
[ 162.999962][ T3399] required_size=14765 ret=0
[ 163.006420][ T3399] required_size=16413 ret=0
[ 163.012163][ T3399] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=1648
----------------------------------------
part, and came to wonder if serialization between splice() and sendmsg() is correct.
A program where splice() and sendmsg() cannot run in parallel due to single-threaded
is shown below.
----------------------------------------
#define _GNU_SOURCE
#include <sys/types.h>
#include <fcntl.h>
#include <unistd.h>
#include <sys/socket.h>
#include <arpa/inet.h>
#define SOL_TCP 6
#define TCP_REPAIR 19
#define TCP_ULP 31
#define TLS_TX 1
int main(int argc, char *argv[])
{
struct iovec iov = {
.iov_base = "@@@@@@@@@@@@@@@@",
.iov_len = 16
};
struct msghdr hdr = {
.msg_iov = &iov,
.msg_iovlen = 1,
.msg_flags = MSG_FASTOPEN
};
const struct sockaddr_in6 addr = { .sin6_family = AF_INET6, .sin6_addr = in6addr_loopback };
const int one = 1;
int ret_ignored = 0;
const int fd = socket(PF_INET6, SOCK_STREAM, IPPROTO_IP);
int pipe_fds[2] = { -1, -1 };
static char buf[32768] = { };
ret_ignored += pipe(pipe_fds);
setsockopt(fd, SOL_TCP, TCP_REPAIR, &one, sizeof(one));
connect(fd, (struct sockaddr *) &addr, sizeof(addr));
setsockopt(fd, SOL_TCP, TCP_ULP, "tls", 4);
setsockopt(fd, SOL_TLS, TLS_TX,"\3\0035\0%T\244\205\333\f0\362B\221\243\234\206\216\220\243u\347\342P|1\24}Q@\377\227\353\222B\354\264u[\346", 40);
ret_ignored += write(pipe_fds[1], buf, 2432);
ret_ignored += write(pipe_fds[1], buf, 10676);
ret_ignored += write(pipe_fds[1], buf, 17996);
if (argc == 1) {
ret_ignored += splice(pipe_fds[0], NULL, fd, NULL, 1048576, 0);
ret_ignored += sendmsg(fd, &hdr, MSG_DONTWAIT | MSG_MORE);
} else {
ret_ignored += sendmsg(fd, &hdr, MSG_DONTWAIT | MSG_MORE);
ret_ignored += splice(pipe_fds[0], NULL, fd, NULL, 1048576, 0);
}
return ret_ignored * 0;
}
----------------------------------------
If you run this program with argc == 1, you will get below output.
----------------------------------------
[ 4030.292376] [ T3896] required_size=2461 ret=0
[ 4030.292376] [ T3896] required_size=6557 ret=0
[ 4030.292376] [ T3896] required_size=10653 ret=0
[ 4030.292376] [ T3896] required_size=14749 ret=0
[ 4030.292376] [ T3896] required_size=16413 ret=0
[ 4030.292376] [ T3896] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=1664
[ 4030.330185] [ T3896] required_size=2461 ret=0
[ 4030.330185] [ T3896] required_size=6557 ret=0
[ 4030.330185] [ T3896] required_size=10653 ret=0
[ 4030.335443] [ T3896] required_size=14749 ret=0
[ 4030.335443] [ T3896] full_record=0 eor=1 sk_msg_full(msg_pl)=0 copied=4096
----------------------------------------
If you run this program with argc != 1, you will get below output.
----------------------------------------
[ 4044.312696] [ T3898] required_size=2477 ret=0
[ 4044.312696] [ T3898] required_size=6573 ret=0
[ 4044.312696] [ T3898] required_size=10669 ret=0
[ 4044.312696] [ T3898] required_size=14765 ret=0
[ 4044.312696] [ T3898] required_size=16413 ret=0
[ 4044.312696] [ T3898] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=1648
[ 4044.340425] [ T3898] required_size=2477 ret=0
[ 4044.350515] [ T3898] required_size=6573 ret=0
[ 4044.350515] [ T3898] required_size=10669 ret=0
[ 4044.350515] [ T3898] required_size=14765 ret=0
[ 4044.350515] [ T3898] full_record=0 eor=1 sk_msg_full(msg_pl)=0 copied=4096
----------------------------------------
The difference is that the required_size= value differs by "struct iovec"->iov_len
bytes which is the value passed to sendmsg().
If splice() happens before sendmsg() happens, the output does not include
bytes passed to sendmsg(). If sendmsg() happens before splice() happens,
the output includes bytes passed to sendmsg().
Then, where does the difference between
----------------------------------------
[ 162.919587][ T3399] required_size=10653 ret=0
[ 162.923090][ T3399] required_size=14749 ret=0
[ 162.928686][ T3399] required_size=16413 ret=0
----------------------------------------
and
----------------------------------------
[ 162.992866][ T3399] required_size=10653 ret=0
[ 162.999962][ T3399] required_size=14765 ret=0
[ 163.006420][ T3399] required_size=16413 ret=0
----------------------------------------
come from? Both output had the same values until 10653, but
the next value differs by 16. This might suggest that a race between
splice() and sendmsg() caused unexpected required_size= value...
This could explain "for the second time" part below.
> 4125+8221+12317+16413=41076 (the lower 4 bits are 0100)
> 2461+6557+10653+14749+16413=50833 (the lower 4 bits are 0001)
> 2461+6573+10669+14765+16413=50881 (the lower 4 bits are 0001)
>
> KMSAN reports this problem when the lower 4 bits became 0001 for the second time.
> Unless KMSAN's reporting is asynchronous, maybe the reason of "for the second time"
> part is that the previous state is relevant...
On 2023/07/01 13:12, Tetsuo Handa wrote:
> Then, where does the difference between
>
> ----------------------------------------
> [ 162.919587][ T3399] required_size=10653 ret=0
> [ 162.923090][ T3399] required_size=14749 ret=0
> [ 162.928686][ T3399] required_size=16413 ret=0
> ----------------------------------------
>
> and
>
> ----------------------------------------
> [ 162.992866][ T3399] required_size=10653 ret=0
> [ 162.999962][ T3399] required_size=14765 ret=0
> [ 163.006420][ T3399] required_size=16413 ret=0
> ----------------------------------------
>
> come from? Both output had the same values until 10653, but
> the next value differs by 16. This might suggest that a race between
> splice() and sendmsg() caused unexpected required_size= value...
>
I found a simplified reproducer.
This problem happens when splice() and sendmsg() run in parallel.
----------------------------------------
#define _GNU_SOURCE
#include <sys/types.h>
#include <fcntl.h>
#include <unistd.h>
#include <sys/socket.h>
#include <arpa/inet.h>
#include <sys/poll.h>
#define SOL_TCP 6
#define TCP_REPAIR 19
#define TCP_ULP 31
#define TLS_TX 1
int main(int argc, char *argv[])
{
struct iovec iov = {
.iov_base = "@@@@@@@@@@@@@@@@",
.iov_len = 16
};
struct msghdr hdr = {
.msg_iov = &iov,
.msg_iovlen = 1,
.msg_flags = MSG_FASTOPEN
};
const struct sockaddr_in6 addr = { .sin6_family = AF_INET6, .sin6_addr = in6addr_loopback };
const int one = 1;
int ret_ignored = 0;
const int fd = socket(PF_INET6, SOCK_STREAM, IPPROTO_IP);
int pipe_fds[2] = { -1, -1 };
static char buf[32768] = { };
ret_ignored += pipe(pipe_fds);
setsockopt(fd, SOL_TCP, TCP_REPAIR, &one, sizeof(one));
connect(fd, (struct sockaddr *) &addr, sizeof(addr));
setsockopt(fd, SOL_TCP, TCP_ULP, "tls", 4);
setsockopt(fd, SOL_TLS, TLS_TX,"\3\0035\0%T\244\205\333\f0\362B\221\243\234\206\216\220\243u\347\342P|1\24}Q@\377\227\353\222B\354\264u[\346", 40);
if (fork() == 0) {
ret_ignored += splice(pipe_fds[0], NULL, fd, NULL, 1048576, SPLICE_F_MORE);
_exit(0);
}
close(pipe_fds[0]);
ret_ignored += write(pipe_fds[1], buf, sizeof(buf));
poll(NULL, 0, 1);
ret_ignored += sendmsg(fd, &hdr, MSG_DONTWAIT | MSG_MORE);
return ret_ignored * 0;
}
----------------------------------------
Debug printk() patch and output are shown below.
----------------------------------------
diff --git a/net/core/sock.c b/net/core/sock.c
index 24f2761bdb1d..879c1d54deed 100644
--- a/net/core/sock.c
+++ b/net/core/sock.c
@@ -2825,6 +2825,14 @@ static void sk_leave_memory_pressure(struct sock *sk)
DEFINE_STATIC_KEY_FALSE(net_high_order_alloc_disable_key);
+static inline char *kaddr(struct page *page)
+{
+ char *kaddr = kmap_atomic(page);
+
+ kunmap_atomic(kaddr);
+ return kaddr;
+}
+
/**
* skb_page_frag_refill - check that a page_frag contains enough room
* @sz: minimum size of the fragment we want to get
@@ -2840,10 +2848,17 @@ bool skb_page_frag_refill(unsigned int sz, struct page_frag *pfrag, gfp_t gfp)
if (pfrag->page) {
if (page_ref_count(pfrag->page) == 1) {
pfrag->offset = 0;
+ if (current->comm[0] && !strcmp(current->comm + 1, ".out")) {
+ pr_info("assigned %px\n", kaddr(pfrag->page));
+ }
return true;
}
- if (pfrag->offset + sz <= pfrag->size)
+ if (pfrag->offset + sz <= pfrag->size) {
+ if (current->comm[0] && !strcmp(current->comm + 1, ".out")) {
+ pr_info("assigned %d from %px\n", sz, kaddr(pfrag->page) + pfrag->offset);
+ }
return true;
+ }
put_page(pfrag->page);
}
@@ -2856,12 +2871,18 @@ bool skb_page_frag_refill(unsigned int sz, struct page_frag *pfrag, gfp_t gfp)
__GFP_NORETRY,
SKB_FRAG_PAGE_ORDER);
if (likely(pfrag->page)) {
+ if (current->comm[0] && !strcmp(current->comm + 1, ".out")) {
+ pr_info("allocated %px\n", kaddr(pfrag->page));
+ }
pfrag->size = PAGE_SIZE << SKB_FRAG_PAGE_ORDER;
return true;
}
}
pfrag->page = alloc_page(gfp);
if (likely(pfrag->page)) {
+ if (current->comm[0] && !strcmp(current->comm + 1, ".out")) {
+ pr_info("allocated %px\n", kaddr(pfrag->page));
+ }
pfrag->size = PAGE_SIZE;
return true;
}
diff --git a/net/tls/tls_sw.c b/net/tls/tls_sw.c
index 1a53c8f481e9..dcf00d1f239f 100644
--- a/net/tls/tls_sw.c
+++ b/net/tls/tls_sw.c
@@ -543,6 +543,22 @@ static int tls_do_encryption(struct sock *sk,
list_add_tail((struct list_head *)&rec->list, &ctx->tx_list);
atomic_inc(&ctx->encrypt_pending);
+ {
+ int len = aead_req->assoclen + aead_req->cryptlen;
+ struct sg_mapping_iter miter;
+
+ sg_miter_start(&miter, rec->sg_aead_in,
+ sg_nents(rec->sg_aead_in),
+ SG_MITER_TO_SG | SG_MITER_ATOMIC);
+
+ while (len > 0 && sg_miter_next(&miter)) {
+ pr_info("addr=%px len=%d\n", miter.addr, min(len, (int)miter.length));
+ kmsan_check_memory(miter.addr, min(len, (int)miter.length));
+ len -= miter.length;
+ }
+ sg_miter_stop(&miter);
+ }
+
rc = crypto_aead_encrypt(aead_req);
if (!rc || rc != -EINPROGRESS) {
atomic_dec(&ctx->encrypt_pending);
@@ -1211,6 +1227,7 @@ static int tls_sw_do_sendpage(struct sock *sk, struct page *page,
goto wait_for_sndbuf;
alloc_payload:
ret = tls_alloc_encrypted_msg(sk, required_size);
+ pr_info("required_size=%d ret=%d\n", required_size, ret);
if (ret) {
if (ret != -ENOSPC)
goto wait_for_memory;
@@ -1232,6 +1249,8 @@ static int tls_sw_do_sendpage(struct sock *sk, struct page *page,
tls_ctx->pending_open_record_frags = true;
if (full_record || eor || sk_msg_full(msg_pl)) {
+ pr_info("full_record=%d eor=%d sk_msg_full(msg_pl)=%d copied=%d\n",
+ full_record, eor, sk_msg_full(msg_pl), copied);
ret = bpf_exec_tx_verdict(msg_pl, sk, full_record,
record_type, &copied, flags);
if (ret) {
----------------------------------------
skb_page_frag_refill() assigned 32 bytes from ffff88810d40901d
but tls_do_encryption() accesses 16 bytes from ffff88810d40900d !?
----------------------------------------
[ 159.777428][ T3405] sock: allocated ffff88810d408000
[ 159.792685][ T3405] required_size=4125 ret=0
[ 159.802047][ T3395] sock: allocated ffff88810b000000
[ 159.799656][ T3405] sock: assigned 32 from ffff88810d40901d
[ 159.828229][ T3405] required_size=8237 ret=0
[ 159.848161][ T3405] sock: assigned 32 from ffff88810d40a01d
[ 159.849298][ T3405] required_size=12333 ret=0
[ 159.849382][ T3405] sock: assigned 32 from ffff88810d40b01d
[ 159.849416][ T3405] required_size=16413 ret=0
[ 159.849434][ T3405] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=4080
[ 159.849472][ T3405] addr=ffff888115aa4658 len=13
[ 159.849492][ T3405] addr=ffff88811da48000 len=4096
[ 159.849513][ T3405] addr=ffff88810d40900d len=16
[ 159.849530][ T3405] =====================================================
[ 159.849618][ T3405] BUG: KMSAN: uninit-value in tls_push_record+0x2cff/0x4040
[ 159.849654][ T3405] tls_push_record+0x2cff/0x4040
[ 159.849686][ T3405] bpf_exec_tx_verdict+0x5ba/0x2530
[ 159.849715][ T3405] tls_sw_do_sendpage+0x1779/0x21f0
[ 159.849744][ T3405] tls_sw_sendpage+0x247/0x2b0
[ 159.849772][ T3405] inet_sendpage+0x1de/0x2f0
[ 159.849807][ T3405] kernel_sendpage+0x4cc/0x940
[ 159.849837][ T3405] sock_sendpage+0x162/0x220
[ 159.849864][ T3405] pipe_to_sendpage+0x3df/0x4f0
[ 159.849891][ T3405] __splice_from_pipe+0x5c7/0x1010
[ 159.849916][ T3405] generic_splice_sendpage+0x1c6/0x2a0
[ 159.849943][ T3405] do_splice+0x26d8/0x32f0
[ 159.849966][ T3405] __se_sys_splice+0x81f/0xba0
[ 159.849991][ T3405] __x64_sys_splice+0x1a1/0x200
[ 159.850016][ T3405] do_syscall_64+0x41/0x90
[ 159.850044][ T3405] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 159.850082][ T3405]
[ 159.850088][ T3405] Uninit was created at:
[ 159.850136][ T3405] __alloc_pages+0x925/0x1050
[ 159.850171][ T3405] alloc_pages+0xe30/0x11b0
[ 159.850204][ T3405] skb_page_frag_refill+0x539/0x1030
[ 159.850238][ T3405] sk_page_frag_refill+0xa2/0x1c0
[ 159.850271][ T3405] sk_msg_alloc+0x278/0x1560
[ 159.850307][ T3405] tls_sw_do_sendpage+0xbec/0x21f0
[ 159.850336][ T3405] tls_sw_sendpage+0x247/0x2b0
[ 159.850363][ T3405] inet_sendpage+0x1de/0x2f0
[ 159.850392][ T3405] kernel_sendpage+0x4cc/0x940
[ 159.850418][ T3405] sock_sendpage+0x162/0x220
[ 159.850446][ T3405] pipe_to_sendpage+0x3df/0x4f0
[ 159.850470][ T3405] __splice_from_pipe+0x5c7/0x1010
[ 159.850495][ T3405] generic_splice_sendpage+0x1c6/0x2a0
[ 159.850522][ T3405] do_splice+0x26d8/0x32f0
[ 159.850545][ T3405] __se_sys_splice+0x81f/0xba0
[ 159.850570][ T3405] __x64_sys_splice+0x1a1/0x200
[ 159.850595][ T3405] do_syscall_64+0x41/0x90
[ 159.850619][ T3405] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 159.850654][ T3405]
[ 159.850659][ T3405] Bytes 0-15 of 16 are uninitialized
[ 159.850672][ T3405] Memory access of size 16 starts at ffff88810d40900d
[ 159.850685][ T3405]
[ 159.850694][ T3405] CPU: 2 PID: 3405 Comm: a.out Not tainted 6.4.0-rc7-ge6bc8833d80f-dirty #32
[ 159.850725][ T3405] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[ 159.850741][ T3405] =====================================================
[ 159.850749][ T3405] Disabling lock debugging due to kernel taint
[ 159.850761][ T3405] Kernel panic - not syncing: kmsan.panic set ...
[ 159.850774][ T3405] CPU: 2 PID: 3405 Comm: a.out Tainted: G B 6.4.0-rc7-ge6bc8833d80f-dirty #32
[ 159.850801][ T3405] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[ 159.850814][ T3405] Call Trace:
[ 159.850824][ T3405] <TASK>
[ 159.850833][ T3405] dump_stack_lvl+0x1f6/0x280
[ 159.850863][ T3405] dump_stack+0x29/0x30
[ 159.850888][ T3405] panic+0x4e7/0xc60
[ 159.850928][ T3405] ? add_taint+0x185/0x210
[ 159.850969][ T3405] kmsan_report+0x2d1/0x2e0
[ 159.851008][ T3405] ? kmsan_internal_unpoison_memory+0x14/0x20
[ 159.851048][ T3405] ? __msan_metadata_ptr_for_load_4+0x24/0x40
[ 159.851089][ T3405] ? kmsan_internal_check_memory+0x47d/0x540
[ 159.851128][ T3405] ? kmsan_check_memory+0x1a/0x20
[ 159.851166][ T3405] ? tls_push_record+0x2cff/0x4040
[ 159.851197][ T3405] ? bpf_exec_tx_verdict+0x5ba/0x2530
[ 159.851228][ T3405] ? tls_sw_do_sendpage+0x1779/0x21f0
[ 159.851258][ T3405] ? tls_sw_sendpage+0x247/0x2b0
[ 159.851288][ T3405] ? inet_sendpage+0x1de/0x2f0
[ 159.851318][ T3405] ? kernel_sendpage+0x4cc/0x940
[ 159.851346][ T3405] ? sock_sendpage+0x162/0x220
[ 159.851374][ T3405] ? pipe_to_sendpage+0x3df/0x4f0
[ 159.851399][ T3405] ? __splice_from_pipe+0x5c7/0x1010
[ 159.851427][ T3405] ? generic_splice_sendpage+0x1c6/0x2a0
[ 159.851455][ T3405] ? do_splice+0x26d8/0x32f0
[ 159.851479][ T3405] ? __se_sys_splice+0x81f/0xba0
[ 159.851506][ T3405] ? __x64_sys_splice+0x1a1/0x200
[ 159.851532][ T3405] ? do_syscall_64+0x41/0x90
[ 159.851557][ T3405] ? entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 159.851598][ T3405] ? vprintk_default+0x8a/0xa0
[ 159.851634][ T3405] ? vprintk+0x163/0x180
[ 159.851669][ T3405] ? _printk+0x181/0x1b0
[ 159.851706][ T3405] kmsan_internal_check_memory+0x47d/0x540
[ 159.851748][ T3405] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[ 159.851790][ T3405] kmsan_check_memory+0x1a/0x20
[ 159.851828][ T3405] tls_push_record+0x2cff/0x4040
[ 159.851873][ T3405] bpf_exec_tx_verdict+0x5ba/0x2530
[ 159.851926][ T3405] ? _printk+0x181/0x1b0
[ 159.851965][ T3405] ? tls_sw_do_sendpage+0xbd1/0x21f0
[ 159.851998][ T3405] tls_sw_do_sendpage+0x1779/0x21f0
[ 159.852045][ T3405] tls_sw_sendpage+0x247/0x2b0
[ 159.852078][ T3405] ? tls_sw_do_sendpage+0x21f0/0x21f0
[ 159.852110][ T3405] inet_sendpage+0x1de/0x2f0
[ 159.852143][ T3405] ? inet_sendmsg+0x1d0/0x1d0
[ 159.852173][ T3405] kernel_sendpage+0x4cc/0x940
[ 159.852206][ T3405] sock_sendpage+0x162/0x220
[ 159.852238][ T3405] pipe_to_sendpage+0x3df/0x4f0
[ 159.852264][ T3405] ? sock_fasync+0x240/0x240
[ 159.852296][ T3405] __splice_from_pipe+0x5c7/0x1010
[ 159.852324][ T3405] ? generic_splice_sendpage+0x2a0/0x2a0
[ 159.852360][ T3405] generic_splice_sendpage+0x1c6/0x2a0
[ 159.852393][ T3405] ? iter_file_splice_write+0x1a30/0x1a30
[ 159.852421][ T3405] do_splice+0x26d8/0x32f0
[ 159.852446][ T3405] ? kmsan_internal_set_shadow_origin+0x66/0xe0
[ 159.852487][ T3405] ? _raw_spin_lock_irqsave+0x91/0x110
[ 159.852527][ T3405] ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[ 159.852567][ T3405] ? _raw_spin_lock_irqsave+0x91/0x110
[ 159.852606][ T3405] ? _raw_spin_unlock_irqrestore+0x76/0xb0
[ 159.852652][ T3405] __se_sys_splice+0x81f/0xba0
[ 159.852696][ T3405] __x64_sys_splice+0x1a1/0x200
[ 159.852735][ T3405] do_syscall_64+0x41/0x90
[ 159.852767][ T3405] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[ 159.852813][ T3405] RIP: 0033:0x7f5a347261aa
[ 159.852840][ T3405] Code: d8 64 89 02 48 c7 c0 ff ff ff ff eb b9 0f 1f 00 f3 0f 1e fa 49 89 ca 64 8b 04 25 18 00 00 00 85 c0 75 15 b8 13 01 00 00 0f 05 <48> 3d 00 f0 ff ff 77 7e c3 0f 1f 44 00 00 41 54 48 83 ec 30 44 89
[ 159.852873][ T3405] RSP: 002b:00007ffe1b674588 EFLAGS: 00000246 ORIG_RAX: 0000000000000113
[ 159.852905][ T3405] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f5a347261aa
[ 159.852926][ T3405] RDX: 0000000000000003 RSI: 0000000000000000 RDI: 0000000000000004
[ 159.852942][ T3405] RBP: 0000000000000001 R08: 0000000000100000 R09: 0000000000000004
[ 159.852959][ T3405] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
[ 159.852975][ T3405] R13: 000055675f9631c0 R14: 000055675f965d58 R15: 00007f5a348e8040
[ 159.853001][ T3405] </TASK>
[ 159.858725][ T3405] Kernel Offset: disabled
[ 159.858725][ T3405] Rebooting in 10 seconds..
----------------------------------------
On Tue, 4 Jul 2023 22:32:00 +0900 Tetsuo Handa wrote:
> I found a simplified reproducer.
> This problem happens when splice() and sendmsg() run in parallel.
Could you retry with the upstream (tip of Linus's tree) and see if it
still repros? I tried to get a KMSAN kernel to boot on QEMU but it
the kernel doesn't want to start, no idea what's going on :(
On 2023/07/07 5:53, Jakub Kicinski wrote:
> On Tue, 4 Jul 2023 22:32:00 +0900 Tetsuo Handa wrote:
>> I found a simplified reproducer.
>> This problem happens when splice() and sendmsg() run in parallel.
>
> Could you retry with the upstream (tip of Linus's tree) and see if it
> still repros? I tried to get a KMSAN kernel to boot on QEMU but it
> the kernel doesn't want to start, no idea what's going on :(
I can't reproduce this problem as of commit a452483508d7 of linux.git tree, for
the simplified reproducer is failing with EBADMSG error. Unless what the simplified
reproducer is doing has become illegal, I need to bisect between
commit 219d92056ba3 ("splice, net: Fix SPLICE_F_MORE signalling in splice_direct_to_actor()")
which fails with EBADMSG error and
commit 8a0d57df8938 ("tls: improve lockless access safety of tls_err_abort()")
which shows this problem, with
commit e6bc8833d80f ("string: use __builtin_memcpy() in strlcpy/strlcat")
backported...
----------------------------------------
root@fuzz:~# strace -f ./a.out
execve("./a.out", ["./a.out"], 0x7ffedb58a368 /* 26 vars */) = 0
brk(NULL) = 0x564cb3f30000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffd9c8980a0) = -1 EINVAL (Invalid argument)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f463d4e6000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=37735, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 37735, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f463d4dc000
close(3) = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\237\2\0\0\0\0\0"..., 832) = 832
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
pread64(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0"..., 48, 848) = 48
pread64(3, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0i8\235HZ\227\223\333\350s\360\352,\223\340."..., 68, 896) = 68
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=2216304, ...}, AT_EMPTY_PATH) = 0
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
mmap(NULL, 2260560, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f463d200000
mmap(0x7f463d228000, 1658880, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7f463d228000
mmap(0x7f463d3bd000, 360448, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1bd000) = 0x7f463d3bd000
mmap(0x7f463d415000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x214000) = 0x7f463d415000
mmap(0x7f463d41b000, 52816, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f463d41b000
close(3) = 0
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f463d4d9000
arch_prctl(ARCH_SET_FS, 0x7f463d4d9740) = 0
set_tid_address(0x7f463d4d9a10) = 3444
set_robust_list(0x7f463d4d9a20, 24) = 0
rseq(0x7f463d4da0e0, 0x20, 0, 0x53053053) = 0
mprotect(0x7f463d415000, 16384, PROT_READ) = 0
mprotect(0x564cb38ac000, 4096, PROT_READ) = 0
mprotect(0x7f463d520000, 8192, PROT_READ) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
munmap(0x7f463d4dc000, 37735) = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 3
pipe2([4, 5], 0) = 0
setsockopt(3, SOL_TCP, TCP_REPAIR, [1], 4) = 0
connect(3, {sa_family=AF_INET6, sin6_port=htons(0), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_scope_id=0}, 28) = 0
setsockopt(3, SOL_TCP, TCP_ULP, [7564404], 4) = 0
setsockopt(3, SOL_TLS, TLS_TX, "\3\0035\0%T\244\205\333\f0\362B\221\243\234\206\216\220\243u\347\342P|1\24}Q@\377\227"..., 40) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLDstrace: Process 3445 attached
, child_tidptr=0x7f463d4d9a10) = 3445
[pid 3444] close(4 <unfinished ...>
[pid 3445] set_robust_list(0x7f463d4d9a20, 24 <unfinished ...>
[pid 3444] <... close resumed>) = 0
[pid 3445] <... set_robust_list resumed>) = 0
[pid 3444] write(5, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 32768 <unfinished ...>
[pid 3445] splice(4, NULL, 3, NULL, 1048576, SPLICE_F_MORE <unfinished ...>
[pid 3444] <... write resumed>) = 32768
[pid 3444] poll(NULL, 0, 1) = 0 (Timeout)
[pid 3444] sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="@@@@@@@@@@@@@@@@", iov_len=16}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_FASTOPEN}, MSG_DONTWAIT|MSG_MORE) = -1 EBADMSG (Bad message)
[pid 3445] <... splice resumed>) = -1 EBADMSG (Bad message)
[pid 3444] exit_group(0 <unfinished ...>
[pid 3445] exit_group(0 <unfinished ...>
[pid 3444] <... exit_group resumed>) = ?
[pid 3445] <... exit_group resumed>) = ?
[pid 3444] +++ exited with 0 +++
+++ exited with 0 +++
----------------------------------------
On 2023/07/07 18:41, Tetsuo Handa wrote:
> On 2023/07/07 5:53, Jakub Kicinski wrote:
>> On Tue, 4 Jul 2023 22:32:00 +0900 Tetsuo Handa wrote:
>>> I found a simplified reproducer.
>>> This problem happens when splice() and sendmsg() run in parallel.
>>
>> Could you retry with the upstream (tip of Linus's tree) and see if it
>> still repros? I tried to get a KMSAN kernel to boot on QEMU but it
>> the kernel doesn't want to start, no idea what's going on :(
(Returned from https://lkml.kernel.org/r/[email protected] .)
It seems that a series of changes that was merged in this merge window
made this problem no longer reproducible. ;-)
Which commit should we mark as a fix for this problem?