Re: INFO: task hung in aead_recvmsg

Re: INFO: task hung in aead_recvmsg

[Dmitry Vyukov]

On Sun, Dec 10, 2017 at 2:34 PM, syzbot
<bot+56c7151cad94eec37c521f0e47d2eee53f9361c4@syzkaller.appspotmail.com>
wrote:
> Hello,
>
> syzkaller hit the following crash on
> ad4dac17f9d563b9e34aab78a34293b10993e9b5
> git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/master
> compiler: gcc (GCC) 7.1.1 20170620
> .config is attached
> Raw console output is attached.
>
> Unfortunately, I don't have any reproducer for this bug yet.
>
>
> Use struct sctp_assoc_value instead
> INFO: task syz-executor6:7377 blocked for more than 120 seconds.
>       Not tainted 4.15.0-rc2-next-20171208+ #63
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> syz-executor6   D24416  7377   3393 0x00000004
> Call Trace:
>  context_switch kernel/sched/core.c:2800 [inline]
>  __schedule+0x8eb/0x2060 kernel/sched/core.c:3376
>  schedule+0xf5/0x430 kernel/sched/core.c:3435
>  schedule_timeout+0x43a/0x560 kernel/time/timer.c:1776
>  do_wait_for_common kernel/sched/completion.c:91 [inline]
>  __wait_for_common kernel/sched/completion.c:112 [inline]
>  wait_for_common kernel/sched/completion.c:123 [inline]
>  wait_for_completion+0x44b/0x7b0 kernel/sched/completion.c:144
>  crypto_wait_req include/linux/crypto.h:496 [inline]
>  _aead_recvmsg crypto/algif_aead.c:308 [inline]
>  aead_recvmsg+0x1396/0x1bc0 crypto/algif_aead.c:329
>  aead_recvmsg_nokey+0x60/0x80 crypto/algif_aead.c:447
>  sock_recvmsg_nosec net/socket.c:809 [inline]
>  sock_recvmsg+0xc9/0x110 net/socket.c:816
>  ___sys_recvmsg+0x29b/0x630 net/socket.c:2185
>  __sys_recvmsg+0xe2/0x210 net/socket.c:2230
>  SYSC_recvmsg net/socket.c:2242 [inline]
>  SyS_recvmsg+0x2d/0x50 net/socket.c:2237
>  entry_SYSCALL_64_fastpath+0x1f/0x96
> RIP: 0033:0x452a39
> RSP: 002b:00007f9dc7c93c58 EFLAGS: 00000212 ORIG_RAX: 000000000000002f
> RAX: ffffffffffffffda RBX: 00007f9dc7c94700 RCX: 0000000000452a39
> RDX: 0000000000000000 RSI: 0000000020539fc8 RDI: 0000000000000025
> RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000212 R12: 0000000000000000
> R13: 0000000000a6f7ff R14: 00007f9dc7c949c0 R15: 0000000000000000
>
> Showing all locks held in the system:
> 2 locks held by khungtaskd/671:
>  #0:  (rcu_read_lock){....}, at: [<00000000d256784e>]
> check_hung_uninterruptible_tasks kernel/hung_task.c:175 [inline]
>  #0:  (rcu_read_lock){....}, at: [<00000000d256784e>] watchdog+0x1c5/0xd60
> kernel/hung_task.c:249
>  #1:  (tasklist_lock){.+.+}, at: [<00000000d84da0f3>]
> debug_show_all_locks+0xd3/0x400 kernel/locking/lockdep.c:4554
> 1 lock held by rsyslogd/2995:
>  #0:  (&f->f_pos_lock){+.+.}, at: [<0000000034bb33fc>]
> __fdget_pos+0x131/0x1a0 fs/file.c:765
> 2 locks held by getty/3116:
>  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> 2 locks held by getty/3117:
>  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> 2 locks held by getty/3118:
>  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> 2 locks held by getty/3119:
>  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> 2 locks held by getty/3120:
>  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> 2 locks held by getty/3121:
>  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> 2 locks held by getty/3122:
>  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> 1 lock held by syz-executor6/7377:
>  #0:  (sk_lock-AF_ALG){+.+.}, at: [<0000000096d0e030>] lock_sock
> include/net/sock.h:1463 [inline]
>  #0:  (sk_lock-AF_ALG){+.+.}, at: [<0000000096d0e030>]
> aead_recvmsg+0xb3/0x1bc0 crypto/algif_aead.c:327
> 1 lock held by syz-executor6/7391:
>  #0:  (sk_lock-AF_ALG){+.+.}, at: [<0000000096d0e030>] lock_sock
> include/net/sock.h:1463 [inline]
>  #0:  (sk_lock-AF_ALG){+.+.}, at: [<0000000096d0e030>]
> aead_recvmsg+0xb3/0x1bc0 crypto/algif_aead.c:327
>
> =============================================
>
> NMI backtrace for cpu 0
> CPU: 0 PID: 671 Comm: khungtaskd Not tainted 4.15.0-rc2-next-20171208+ #63
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
> Google 01/01/2011
> Call Trace:
>  __dump_stack lib/dump_stack.c:17 [inline]
>  dump_stack+0x194/0x257 lib/dump_stack.c:53
>  nmi_cpu_backtrace+0x1d2/0x210 lib/nmi_backtrace.c:103
>  nmi_trigger_cpumask_backtrace+0x122/0x180 lib/nmi_backtrace.c:62
>  arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
>  trigger_all_cpu_backtrace include/linux/nmi.h:138 [inline]
>  check_hung_task kernel/hung_task.c:132 [inline]
>  check_hung_uninterruptible_tasks kernel/hung_task.c:190 [inline]
>  watchdog+0x90c/0xd60 kernel/hung_task.c:249
>  kthread+0x37a/0x440 kernel/kthread.c:238
>  ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:524
> Sending NMI from CPU 0 to CPUs 1:
> NMI backtrace for cpu 1
> CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.15.0-rc2-next-20171208+ #63
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
> Google 01/01/2011
> RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:777
> [inline]
> RIP: 0010:lock_pin_lock+0x2b7/0x370 kernel/locking/lockdep.c:4064
> RSP: 0018:ffff8801db307470 EFLAGS: 00000086
> RAX: dffffc0000000000 RBX: ffff8801d9f88300 RCX: ffffffff82501583
> RDX: 1ffffffff0c59759 RSI: ffff8801db32c918 RDI: 0000000000000082
> RBP: ffff8801db3074b8 R08: ffff8801db306f88 R09: ffff8801d9f88300
> R10: 000000000000000b R11: ffffed003b660df3 R12: ffff8801d9f88300
> R13: ffffed003b3f1170 R14: ffff8801db32c918 R15: 0000000000000000
> FS:  0000000000000000(0000) GS:ffff8801db300000(0000) knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 000000c446de3010 CR3: 00000001cc38e000 CR4: 00000000001406e0
> DR0: 0000000020000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
> Call Trace:
>  <IRQ>
>  rq_pin_lock kernel/sched/sched.h:932 [inline]
>  rq_lock_irqsave kernel/sched/sched.h:1751 [inline]
>  update_blocked_averages+0x195/0x1b60 kernel/sched/fair.c:7353
>  rebalance_domains+0x145/0xcc0 kernel/sched/fair.c:9122
>  run_rebalance_domains+0x381/0x780 kernel/sched/fair.c:9383
>  __do_softirq+0x29d/0xbb2 kernel/softirq.c:285
>  invoke_softirq kernel/softirq.c:365 [inline]
>  irq_exit+0x1d3/0x210 kernel/softirq.c:405
>  scheduler_ipi+0x32a/0x830 kernel/sched/core.c:1804
>  smp_reschedule_interrupt+0xe6/0x670 arch/x86/kernel/smp.c:277
>  reschedule_interrupt+0xa9/0xb0 arch/x86/entry/entry_64.S:944
>  </IRQ>
> RIP: 0010:native_safe_halt+0x6/0x10 arch/x86/include/asm/irqflags.h:54
> RSP: 0018:ffff8801d9f97da8 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff02
> RAX: dffffc0000000000 RBX: 1ffff1003b3f2fb8 RCX: 0000000000000000
> RDX: 1ffffffff0c5975c RSI: 0000000000000001 RDI: ffffffff862cbae0
> RBP: ffff8801d9f97da8 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
> R13: ffff8801d9f97e60 R14: ffffffff869efaa0 R15: 0000000000000000
>  arch_safe_halt arch/x86/include/asm/paravirt.h:93 [inline]
>  default_idle+0xbf/0x430 arch/x86/kernel/process.c:355
>  arch_cpu_idle+0xa/0x10 arch/x86/kernel/process.c:346
>  default_idle_call+0x36/0x90 kernel/sched/idle.c:98
>  cpuidle_idle_call kernel/sched/idle.c:156 [inline]
>  do_idle+0x24a/0x3b0 kernel/sched/idle.c:246
>  cpu_startup_entry+0x18/0x20 kernel/sched/idle.c:351
>  start_secondary+0x330/0x460 arch/x86/kernel/smpboot.c:277
>  secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:237
> Code: ff df c7 83 84 08 00 00 00 00 00 00 48 89 fa 48 c1 ea 03 80 3c 02 00
> 0f 85 91 00 00 00 48 83 3d 37 78 d7 04 00 74 45 48 8b 7d c0 <57> 9d 0f 1f 44
> 00 00 8b 45 cc 48 83 c4 20 5b 41 5c 41 5d 41 5e

+crypto maintainers
this is crypto, not sched


> ---
> This bug is generated by a dumb bot. It may contain errors.
> See https://goo.gl/tpsmEJ for details.
> Direct all questions to syzkaller@googlegroups.com.
> Please credit me with: Reported-by: syzbot <syzkaller@googlegroups.com>
>
> syzbot will keep track of this bug report.
> Once a fix for this bug is merged into any tree, reply to this email with:
> #syz fix: exact-commit-title
> To mark this as a duplicate of another syzbot report, please reply with:
> #syz dup: exact-subject-of-another-report
> If it's a one-off invalid bug report, please reply with:
> #syz invalid
> Note: if the crash happens again, it will cause creation of a new bug
> report.
> Note: all commands must start from beginning of the line in the email body.
>
> --
> You received this message because you are subscribed to the Google Groups
> "syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to syzkaller-bugs+unsubscribe@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/syzkaller-bugs/001a1140b8307b0439055ffc7872%40google.com.
> For more options, visit https://groups.google.com/d/optout.

Re: INFO: task hung in aead_recvmsg

[Eric Biggers]

[+Cc Steffen Klassert <steffen.klassert@secunet.com>]

On Tue, Dec 12, 2017 at 05:46:46PM +0100, 'Dmitry Vyukov' via syzkaller-bugs wrote:
> On Sun, Dec 10, 2017 at 2:34 PM, syzbot
> <bot+56c7151cad94eec37c521f0e47d2eee53f9361c4@syzkaller.appspotmail.com>
> wrote:
> > Hello,
> >
> > syzkaller hit the following crash on
> > ad4dac17f9d563b9e34aab78a34293b10993e9b5
> > git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/master
> > compiler: gcc (GCC) 7.1.1 20170620
> > .config is attached
> > Raw console output is attached.
> >
> > Unfortunately, I don't have any reproducer for this bug yet.
> >
> >
> > Use struct sctp_assoc_value instead
> > INFO: task syz-executor6:7377 blocked for more than 120 seconds.
> >       Not tainted 4.15.0-rc2-next-20171208+ #63
> > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > syz-executor6   D24416  7377   3393 0x00000004
> > Call Trace:
> >  context_switch kernel/sched/core.c:2800 [inline]
> >  __schedule+0x8eb/0x2060 kernel/sched/core.c:3376
> >  schedule+0xf5/0x430 kernel/sched/core.c:3435
> >  schedule_timeout+0x43a/0x560 kernel/time/timer.c:1776
> >  do_wait_for_common kernel/sched/completion.c:91 [inline]
> >  __wait_for_common kernel/sched/completion.c:112 [inline]
> >  wait_for_common kernel/sched/completion.c:123 [inline]
> >  wait_for_completion+0x44b/0x7b0 kernel/sched/completion.c:144
> >  crypto_wait_req include/linux/crypto.h:496 [inline]
> >  _aead_recvmsg crypto/algif_aead.c:308 [inline]
> >  aead_recvmsg+0x1396/0x1bc0 crypto/algif_aead.c:329
> >  aead_recvmsg_nokey+0x60/0x80 crypto/algif_aead.c:447
> >  sock_recvmsg_nosec net/socket.c:809 [inline]
> >  sock_recvmsg+0xc9/0x110 net/socket.c:816
> >  ___sys_recvmsg+0x29b/0x630 net/socket.c:2185
> >  __sys_recvmsg+0xe2/0x210 net/socket.c:2230
> >  SYSC_recvmsg net/socket.c:2242 [inline]
> >  SyS_recvmsg+0x2d/0x50 net/socket.c:2237
> >  entry_SYSCALL_64_fastpath+0x1f/0x96
> > RIP: 0033:0x452a39
> > RSP: 002b:00007f9dc7c93c58 EFLAGS: 00000212 ORIG_RAX: 000000000000002f
> > RAX: ffffffffffffffda RBX: 00007f9dc7c94700 RCX: 0000000000452a39
> > RDX: 0000000000000000 RSI: 0000000020539fc8 RDI: 0000000000000025
> > RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
> > R10: 0000000000000000 R11: 0000000000000212 R12: 0000000000000000
> > R13: 0000000000a6f7ff R14: 00007f9dc7c949c0 R15: 0000000000000000
> >
> > Showing all locks held in the system:
> > 2 locks held by khungtaskd/671:
> >  #0:  (rcu_read_lock){....}, at: [<00000000d256784e>]
> > check_hung_uninterruptible_tasks kernel/hung_task.c:175 [inline]
> >  #0:  (rcu_read_lock){....}, at: [<00000000d256784e>] watchdog+0x1c5/0xd60
> > kernel/hung_task.c:249
> >  #1:  (tasklist_lock){.+.+}, at: [<00000000d84da0f3>]
> > debug_show_all_locks+0xd3/0x400 kernel/locking/lockdep.c:4554
> > 1 lock held by rsyslogd/2995:
> >  #0:  (&f->f_pos_lock){+.+.}, at: [<0000000034bb33fc>]
> > __fdget_pos+0x131/0x1a0 fs/file.c:765
> > 2 locks held by getty/3116:
> >  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> > ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
> >  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> > n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> > 2 locks held by getty/3117:
> >  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> > ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
> >  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> > n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> > 2 locks held by getty/3118:
> >  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> > ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
> >  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> > n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> > 2 locks held by getty/3119:
> >  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> > ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
> >  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> > n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> > 2 locks held by getty/3120:
> >  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> > ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
> >  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> > n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> > 2 locks held by getty/3121:
> >  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> > ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
> >  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> > n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> > 2 locks held by getty/3122:
> >  #0:  (&tty->ldisc_sem){++++}, at: [<000000008df66e53>]
> > ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
> >  #1:  (&ldata->atomic_read_lock){+.+.}, at: [<00000000870ebf25>]
> > n_tty_read+0x2f2/0x1a10 drivers/tty/n_tty.c:2131
> > 1 lock held by syz-executor6/7377:
> >  #0:  (sk_lock-AF_ALG){+.+.}, at: [<0000000096d0e030>] lock_sock
> > include/net/sock.h:1463 [inline]
> >  #0:  (sk_lock-AF_ALG){+.+.}, at: [<0000000096d0e030>]
> > aead_recvmsg+0xb3/0x1bc0 crypto/algif_aead.c:327
> > 1 lock held by syz-executor6/7391:
> >  #0:  (sk_lock-AF_ALG){+.+.}, at: [<0000000096d0e030>] lock_sock
> > include/net/sock.h:1463 [inline]
> >  #0:  (sk_lock-AF_ALG){+.+.}, at: [<0000000096d0e030>]
> > aead_recvmsg+0xb3/0x1bc0 crypto/algif_aead.c:327
> >

I was able to reproduce this by trying to use 'pcrypt' recursively.  I am not
100% sure it is the exact same bug, but it probably is.  Here is a C reproducer:

	#include <linux/if_alg.h>
	#include <sys/socket.h>
	#include <unistd.h>

	int main()
	{
		struct sockaddr_alg addr = {
			.salg_type = "aead",
			.salg_name = "pcrypt(pcrypt(rfc4106-gcm-aesni))",
		};
		int algfd, reqfd;
		char buf[32] = { 0 };

		algfd = socket(AF_ALG, SOCK_SEQPACKET, 0);
		bind(algfd, (void *)&addr, sizeof(addr));
		setsockopt(algfd, SOL_ALG, ALG_SET_KEY, buf, 20);

		reqfd = accept(algfd, 0, 0);
		write(reqfd, buf, 32);
		read(reqfd, buf, 16);
	}

It seems the problem is that all 'pcrypt' instances use the same
'padata_instance', which completes works in the order they are submitted.  But
with nested use, the outer work is submitted before the inner work, so the inner
work isn't allowed to complete until the outer work does, which deadlocks
because actually the inner work needs to complete first.

What a mess.  Maybe there should be a separate 'padata_instance' per pcrypt
instance?  Or maybe there should be a way for an algorithm to declare that it
can only appear in the stack one time?  

Eric

Re: INFO: task hung in aead_recvmsg

[Steffen Klassert]

On Sat, Dec 23, 2017 at 02:29:42PM -0600, Eric Biggers wrote:
> [+Cc Steffen Klassert <steffen.klassert@secunet.com>]
> 
> 
> I was able to reproduce this by trying to use 'pcrypt' recursively.  I am not
> 100% sure it is the exact same bug, but it probably is.  Here is a C reproducer:
> 
> 	#include <linux/if_alg.h>
> 	#include <sys/socket.h>
> 	#include <unistd.h>
> 
> 	int main()
> 	{
> 		struct sockaddr_alg addr = {
> 			.salg_type = "aead",
> 			.salg_name = "pcrypt(pcrypt(rfc4106-gcm-aesni))",
> 		};
> 		int algfd, reqfd;
> 		char buf[32] = { 0 };
> 
> 		algfd = socket(AF_ALG, SOCK_SEQPACKET, 0);
> 		bind(algfd, (void *)&addr, sizeof(addr));
> 		setsockopt(algfd, SOL_ALG, ALG_SET_KEY, buf, 20);
> 
> 		reqfd = accept(algfd, 0, 0);
> 		write(reqfd, buf, 32);
> 		read(reqfd, buf, 16);
> 	}
> 
> It seems the problem is that all 'pcrypt' instances use the same
> 'padata_instance', which completes works in the order they are submitted.  But
> with nested use, the outer work is submitted before the inner work, so the inner
> work isn't allowed to complete until the outer work does, which deadlocks
> because actually the inner work needs to complete first.
> 
> What a mess.  Maybe there should be a separate 'padata_instance' per pcrypt
> instance?  Or maybe there should be a way for an algorithm to declare that it
> can only appear in the stack one time?  

Having two nested pcrypt templates in one algorithm instance
does not make so much sense in the first place. I thought
that the crypto layer would refuse to build an instance
with two nested templates of the same type.

At least for pcrypt, refusing such instantiations would
be the correct behaviour. Are there any other templates
where a nested use would make sense?

Re: INFO: task hung in aead_recvmsg

[Eric Biggers]

On Sat, Dec 30, 2017 at 09:37:44AM +0100, Steffen Klassert wrote:
> On Sat, Dec 23, 2017 at 02:29:42PM -0600, Eric Biggers wrote:
> > [+Cc Steffen Klassert <steffen.klassert@secunet.com>]
> > 
> > 
> > I was able to reproduce this by trying to use 'pcrypt' recursively.  I am not
> > 100% sure it is the exact same bug, but it probably is.  Here is a C reproducer:
> > 
> > 	#include <linux/if_alg.h>
> > 	#include <sys/socket.h>
> > 	#include <unistd.h>
> > 
> > 	int main()
> > 	{
> > 		struct sockaddr_alg addr = {
> > 			.salg_type = "aead",
> > 			.salg_name = "pcrypt(pcrypt(rfc4106-gcm-aesni))",
> > 		};
> > 		int algfd, reqfd;
> > 		char buf[32] = { 0 };
> > 
> > 		algfd = socket(AF_ALG, SOCK_SEQPACKET, 0);
> > 		bind(algfd, (void *)&addr, sizeof(addr));
> > 		setsockopt(algfd, SOL_ALG, ALG_SET_KEY, buf, 20);
> > 
> > 		reqfd = accept(algfd, 0, 0);
> > 		write(reqfd, buf, 32);
> > 		read(reqfd, buf, 16);
> > 	}
> > 
> > It seems the problem is that all 'pcrypt' instances use the same
> > 'padata_instance', which completes works in the order they are submitted.  But
> > with nested use, the outer work is submitted before the inner work, so the inner
> > work isn't allowed to complete until the outer work does, which deadlocks
> > because actually the inner work needs to complete first.
> > 
> > What a mess.  Maybe there should be a separate 'padata_instance' per pcrypt
> > instance?  Or maybe there should be a way for an algorithm to declare that it
> > can only appear in the stack one time?  
> 
> Having two nested pcrypt templates in one algorithm instance
> does not make so much sense in the first place. I thought
> that the crypto layer would refuse to build an instance
> with two nested templates of the same type.
> 
> At least for pcrypt, refusing such instantiations would
> be the correct behaviour. Are there any other templates
> where a nested use would make sense?

Maybe.  But either way, I don't see a straightforward way to prevent it
currently.  In particular, the links from an instance to its inner algorithms
are stored in the crypto_instance_ctx() which has a template-specific format, so
it isn't currently possible to recursively search an instance to check whether a
particular template is present.  We could perhaps add such links in a standard
format, though...

Eric

Re: [RFC PATCH] crypto: pcrypt - forbid recursive instantiation

[Herbert Xu]

On Wed, Apr 18, 2018 at 07:35:33AM +0200, Steffen Klassert wrote:
> 
> Yes sure, I just wanted to know if it is worth to think about
> preventing template recursions. If there is a valid usecase,
> then we don't even need to think in this direction.
> 
> While I think each pcrypt instance should have it's own
> padata instance on the long run, it would be good to have
> a not so intrusive fix that can be backported to the stable
> trees.

Steffen, has there been any progress on this work?

We need to fix this soon or we'll have to disable pcrypt because
it is a security issue.

It's not just about nested templates either.  You can trigger
the same issue where a pcrypt instance over an AEAD algorithm
that uses a fallback which also happens to be pcrypt.

Cheers,
-- 
Email: Herbert Xu <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

Re: [RFC PATCH] crypto: pcrypt - forbid recursive instantiation

[Steffen Klassert]

On Wed, Feb 20, 2019 at 12:06:28PM +0800, Herbert Xu wrote:
> On Wed, Apr 18, 2018 at 07:35:33AM +0200, Steffen Klassert wrote:
> > 
> > Yes sure, I just wanted to know if it is worth to think about
> > preventing template recursions. If there is a valid usecase,
> > then we don't even need to think in this direction.
> > 
> > While I think each pcrypt instance should have it's own
> > padata instance on the long run, it would be good to have
> > a not so intrusive fix that can be backported to the stable
> > trees.
> 
> Steffen, has there been any progress on this work?

I had a look on what we need to use separate padata
instances for each pcrypt instance. But that's comlicated
and will create incompatibilities on the sysfs cpuset
configuration options. So that's not really a thing that
could be a fix.

> 
> We need to fix this soon or we'll have to disable pcrypt because
> it is a security issue.
> 
> It's not just about nested templates either.  You can trigger
> the same issue where a pcrypt instance over an AEAD algorithm
> that uses a fallback which also happens to be pcrypt.

Would it be possible to forbid pcrypt for algorithms
that needs a fallback?

If I see this correct, only crypto algorithms used by
HW crypto accelerators need a fallback to software
crypto. HW crypto can't benefit from pcrypt anyway,
so it would be no loss to disable pcrypt in that case.

We could use the initial fix from Eric in combination
with disableing pcrypt for algorithms that need a fallback.

Re: [RFC PATCH] crypto: pcrypt - forbid recursive instantiation

[Herbert Xu]

On Wed, Feb 20, 2019 at 12:42:08PM +0100, Steffen Klassert wrote:
> 
> I had a look on what we need to use separate padata
> instances for each pcrypt instance. But that's comlicated
> and will create incompatibilities on the sysfs cpuset
> configuration options. So that's not really a thing that
> could be a fix.

I don't see why it'll create incompatibilities for the cpu mask
configuration.  You can just maintain two global configuration
masks as you do now, and read them from each instance.  What's
the problem with that?

> > We need to fix this soon or we'll have to disable pcrypt because
> > it is a security issue.
> > 
> > It's not just about nested templates either.  You can trigger
> > the same issue where a pcrypt instance over an AEAD algorithm
> > that uses a fallback which also happens to be pcrypt.
> 
> Would it be possible to forbid pcrypt for algorithms
> that needs a fallback?

This is complicated and not fool-proof.  pcrypt itself might
be embedded into some other algorithm directly rather than as
a fallback.

Basically anyone who does a crypto_alloc_aead could end up with
a pcrypt instance unwittingly.  If they were then used as part
of another AEAD algorithm's encrypt/decrypt path then we'd have
a dead-lock as we do now.

Granted we may not have this situation right now but relying on
it to never occur is not a good choice IMHO.

Cheers,
-- 
Email: Herbert Xu <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

Re: INFO: task hung in aead_recvmsg

[syzbot]

syzbot has found a reproducer for the following crash on:

HEAD commit:    99d20a461c43 Merge git://git.kernel.org/pub/scm/linux/kern..
git tree:       net-next
console output: https://syzkaller.appspot.com/x/log.txt?x=1593e1c2400000
kernel config:  https://syzkaller.appspot.com/x/.config?x=acf770f568ef945b
dashboard link:  
https://syzkaller.appspot.com/bug?extid=56c7151cad94eec37c521f0e47d2eee53f9361c4
compiler:       gcc (GCC) 8.0.1 20180413 (experimental)
syzkaller repro:https://syzkaller.appspot.com/x/repro.syz?x=174a932c400000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=10cc732c400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by:  
syzbot+56c7151cad94eec37c521f0e47d2eee53f9361c4@syzkaller.appspotmail.com

INFO: task syz-executor592:4465 blocked for more than 140 seconds.
       Not tainted 4.18.0-rc5+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor592 D24544  4465   4464 0x00000000
Call Trace:
  context_switch kernel/sched/core.c:2853 [inline]
  __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
  schedule+0xfb/0x450 kernel/sched/core.c:3545
  schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
  do_wait_for_common kernel/sched/completion.c:83 [inline]
  __wait_for_common kernel/sched/completion.c:104 [inline]
  wait_for_common kernel/sched/completion.c:115 [inline]
  wait_for_completion+0x430/0x8d0 kernel/sched/completion.c:136
  crypto_wait_req include/linux/crypto.h:512 [inline]
  _aead_recvmsg crypto/algif_aead.c:313 [inline]
  aead_recvmsg+0x1544/0x1bb0 crypto/algif_aead.c:334
  sock_recvmsg_nosec+0x8c/0xb0 net/socket.c:814
  ___sys_recvmsg+0x2b6/0x680 net/socket.c:2287
  __sys_recvmmsg+0x301/0xba0 net/socket.c:2399
  do_sys_recvmmsg+0x181/0x1a0 net/socket.c:2475
  __do_sys_recvmmsg net/socket.c:2493 [inline]
  __se_sys_recvmmsg net/socket.c:2489 [inline]
  __x64_sys_recvmmsg+0xbe/0x150 net/socket.c:2489
  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4407b9
Code: Bad RIP value.
RSP: 002b:00007ffe6735bf58 EFLAGS: 00000207 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 0000000020000000 RCX: 00000000004407b9
RDX: 0000000000000002 RSI: 0000000020003340 RDI: 0000000000000019
RBP: 00000000006cb018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000207 R12: 0000000000401c40
R13: 0000000000401cd0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor592:4466 blocked for more than 140 seconds.
       Not tainted 4.18.0-rc5+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor592 D24448  4466   4464 0x00000000
Call Trace:
  context_switch kernel/sched/core.c:2853 [inline]
  __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
  schedule+0xfb/0x450 kernel/sched/core.c:3545
  schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
  do_wait_for_common kernel/sched/completion.c:83 [inline]
  __wait_for_common kernel/sched/completion.c:104 [inline]
  wait_for_common kernel/sched/completion.c:115 [inline]
  wait_for_completion+0x430/0x8d0 kernel/sched/completion.c:136
  crypto_wait_req include/linux/crypto.h:512 [inline]
  _aead_recvmsg crypto/algif_aead.c:313 [inline]
  aead_recvmsg+0x1544/0x1bb0 crypto/algif_aead.c:334
  sock_recvmsg_nosec+0x8c/0xb0 net/socket.c:814
  ___sys_recvmsg+0x2b6/0x680 net/socket.c:2287
  __sys_recvmmsg+0x301/0xba0 net/socket.c:2399
  do_sys_recvmmsg+0x181/0x1a0 net/socket.c:2475
  __do_sys_recvmmsg net/socket.c:2493 [inline]
  __se_sys_recvmmsg net/socket.c:2489 [inline]
  __x64_sys_recvmmsg+0xbe/0x150 net/socket.c:2489
  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4407b9
Code: Bad RIP value.
RSP: 002b:00007ffe6735bf58 EFLAGS: 00000207 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 0000000020000000 RCX: 00000000004407b9
RDX: 0000000000000002 RSI: 0000000020003340 RDI: 0000000000000013
RBP: 00000000006cb018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000207 R12: 0000000000401c40
R13: 0000000000401cd0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor592:4467 blocked for more than 140 seconds.
       Not tainted 4.18.0-rc5+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor592 D24240  4467   4464 0x00000000
Call Trace:
  context_switch kernel/sched/core.c:2853 [inline]
  __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
  schedule+0xfb/0x450 kernel/sched/core.c:3545
  schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
  do_wait_for_common kernel/sched/completion.c:83 [inline]
  __wait_for_common kernel/sched/completion.c:104 [inline]
  wait_for_common kernel/sched/completion.c:115 [inline]
  wait_for_completion+0x430/0x8d0 kernel/sched/completion.c:136
  crypto_wait_req include/linux/crypto.h:512 [inline]
  _aead_recvmsg crypto/algif_aead.c:313 [inline]
  aead_recvmsg+0x1544/0x1bb0 crypto/algif_aead.c:334
  sock_recvmsg_nosec+0x8c/0xb0 net/socket.c:814
  ___sys_recvmsg+0x2b6/0x680 net/socket.c:2287
  __sys_recvmmsg+0x301/0xba0 net/socket.c:2399
  do_sys_recvmmsg+0x181/0x1a0 net/socket.c:2475
  __do_sys_recvmmsg net/socket.c:2493 [inline]
  __se_sys_recvmmsg net/socket.c:2489 [inline]
  __x64_sys_recvmmsg+0xbe/0x150 net/socket.c:2489
  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4407b9
Code: Bad RIP value.
RSP: 002b:00007ffe6735bf58 EFLAGS: 00000207 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 0000000020000000 RCX: 00000000004407b9
RDX: 0000000000000002 RSI: 0000000020003340 RDI: 0000000000000016
RBP: 00000000006cb018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000207 R12: 0000000000401c40
R13: 0000000000401cd0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor592:4468 blocked for more than 140 seconds.
       Not tainted 4.18.0-rc5+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor592 D24240  4468   4464 0x00000000
Call Trace:
  context_switch kernel/sched/core.c:2853 [inline]
  __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
  schedule+0xfb/0x450 kernel/sched/core.c:3545
  schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
  do_wait_for_common kernel/sched/completion.c:83 [inline]
  __wait_for_common kernel/sched/completion.c:104 [inline]
  wait_for_common kernel/sched/completion.c:115 [inline]
  wait_for_completion+0x430/0x8d0 kernel/sched/completion.c:136
  crypto_wait_req include/linux/crypto.h:512 [inline]
  _aead_recvmsg crypto/algif_aead.c:313 [inline]
  aead_recvmsg+0x1544/0x1bb0 crypto/algif_aead.c:334
  sock_recvmsg_nosec+0x8c/0xb0 net/socket.c:814
  ___sys_recvmsg+0x2b6/0x680 net/socket.c:2287
  __sys_recvmmsg+0x301/0xba0 net/socket.c:2399
  do_sys_recvmmsg+0x181/0x1a0 net/socket.c:2475
  __do_sys_recvmmsg net/socket.c:2493 [inline]
  __se_sys_recvmmsg net/socket.c:2489 [inline]
  __x64_sys_recvmmsg+0xbe/0x150 net/socket.c:2489
  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4407b9
Code: Bad RIP value.
RSP: 002b:00007ffe6735bf58 EFLAGS: 00000207 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 0000000020000000 RCX: 00000000004407b9
RDX: 0000000000000002 RSI: 0000000020003340 RDI: 0000000000000019
RBP: 00000000006cb018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000207 R12: 0000000000401c40
R13: 0000000000401cd0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor592:4469 blocked for more than 140 seconds.
       Not tainted 4.18.0-rc5+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor592 D24592  4469   4464 0x00000000
Call Trace:
  context_switch kernel/sched/core.c:2853 [inline]
  __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
  schedule+0xfb/0x450 kernel/sched/core.c:3545
  schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
  do_wait_for_common kernel/sched/completion.c:83 [inline]
  __wait_for_common kernel/sched/completion.c:104 [inline]
  wait_for_common kernel/sched/completion.c:115 [inline]
  wait_for_completion+0x430/0x8d0 kernel/sched/completion.c:136
  crypto_wait_req include/linux/crypto.h:512 [inline]
  _aead_recvmsg crypto/algif_aead.c:313 [inline]
  aead_recvmsg+0x1544/0x1bb0 crypto/algif_aead.c:334
  sock_recvmsg_nosec+0x8c/0xb0 net/socket.c:814
  ___sys_recvmsg+0x2b6/0x680 net/socket.c:2287
  __sys_recvmmsg+0x301/0xba0 net/socket.c:2399
  do_sys_recvmmsg+0x181/0x1a0 net/socket.c:2475
  __do_sys_recvmmsg net/socket.c:2493 [inline]
  __se_sys_recvmmsg net/socket.c:2489 [inline]
  __x64_sys_recvmmsg+0xbe/0x150 net/socket.c:2489
  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4407b9
Code: Bad RIP value.
RSP: 002b:00007ffe6735bf58 EFLAGS: 00000207 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 0000000020000000 RCX: 00000000004407b9
RDX: 0000000000000002 RSI: 0000000020003340 RDI: 0000000000000010
RBP: 00000000006cb018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000207 R12: 0000000000401c40
R13: 0000000000401cd0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor592:4470 blocked for more than 140 seconds.
       Not tainted 4.18.0-rc5+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor592 D24592  4470   4464 0x00000000
Call Trace:
  context_switch kernel/sched/core.c:2853 [inline]
  __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
  schedule+0xfb/0x450 kernel/sched/core.c:3545
  schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
  do_wait_for_common kernel/sched/completion.c:83 [inline]
  __wait_for_common kernel/sched/completion.c:104 [inline]
  wait_for_common kernel/sched/completion.c:115 [inline]
  wait_for_completion+0x430/0x8d0 kernel/sched/completion.c:136
  crypto_wait_req include/linux/crypto.h:512 [inline]
  _aead_recvmsg crypto/algif_aead.c:313 [inline]
  aead_recvmsg+0x1544/0x1bb0 crypto/algif_aead.c:334
  sock_recvmsg_nosec+0x8c/0xb0 net/socket.c:814
  ___sys_recvmsg+0x2b6/0x680 net/socket.c:2287
  __sys_recvmmsg+0x301/0xba0 net/socket.c:2399
  do_sys_recvmmsg+0x181/0x1a0 net/socket.c:2475
  __do_sys_recvmmsg net/socket.c:2493 [inline]
  __se_sys_recvmmsg net/socket.c:2489 [inline]
  __x64_sys_recvmmsg+0xbe/0x150 net/socket.c:2489
  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4407b9
Code: Bad RIP value.
RSP: 002b:00007ffe6735bf58 EFLAGS: 00000207 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 0000000020000000 RCX: 00000000004407b9
RDX: 0000000000000002 RSI: 0000000020003340 RDI: 0000000000000013
RBP: 00000000006cb018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000207 R12: 0000000000401c40
R13: 0000000000401cd0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor592:4471 blocked for more than 140 seconds.
       Not tainted 4.18.0-rc5+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor592 D24032  4471   4464 0x00000000
Call Trace:
  context_switch kernel/sched/core.c:2853 [inline]
  __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
  schedule+0xfb/0x450 kernel/sched/core.c:3545
  schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
  do_wait_for_common kernel/sched/completion.c:83 [inline]
  __wait_for_common kernel/sched/completion.c:104 [inline]
  wait_for_common kernel/sched/completion.c:115 [inline]
  wait_for_completion+0x430/0x8d0 kernel/sched/completion.c:136
  crypto_wait_req include/linux/crypto.h:512 [inline]
  _aead_recvmsg crypto/algif_aead.c:313 [inline]
  aead_recvmsg+0x1544/0x1bb0 crypto/algif_aead.c:334
  sock_recvmsg_nosec+0x8c/0xb0 net/socket.c:814
  ___sys_recvmsg+0x2b6/0x680 net/socket.c:2287
  __sys_recvmmsg+0x301/0xba0 net/socket.c:2399
  do_sys_recvmmsg+0x181/0x1a0 net/socket.c:2475
  __do_sys_recvmmsg net/socket.c:2493 [inline]
  __se_sys_recvmmsg net/socket.c:2489 [inline]
  __x64_sys_recvmmsg+0xbe/0x150 net/socket.c:2489
  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4407b9
Code: Bad RIP value.
RSP: 002b:00007ffe6735bf58 EFLAGS: 00000207 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 0000000020000000 RCX: 00000000004407b9
RDX: 0000000000000002 RSI: 0000000020003340 RDI: 0000000000000016
RBP: 00000000006cb018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000207 R12: 0000000000401c40
R13: 0000000000401cd0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor592:4472 blocked for more than 140 seconds.
       Not tainted 4.18.0-rc5+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor592 D24480  4472   4464 0x00000000
Call Trace:
  context_switch kernel/sched/core.c:2853 [inline]
  __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
  schedule+0xfb/0x450 kernel/sched/core.c:3545
  schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
  do_wait_for_common kernel/sched/completion.c:83 [inline]
  __wait_for_common kernel/sched/completion.c:104 [inline]
  wait_for_common kernel/sched/completion.c:115 [inline]
  wait_for_completion+0x430/0x8d0 kernel/sched/completion.c:136
  crypto_wait_req include/linux/crypto.h:512 [inline]
  _aead_recvmsg crypto/algif_aead.c:313 [inline]
  aead_recvmsg+0x1544/0x1bb0 crypto/algif_aead.c:334
  sock_recvmsg_nosec+0x8c/0xb0 net/socket.c:814
  ___sys_recvmsg+0x2b6/0x680 net/socket.c:2287
  __sys_recvmmsg+0x301/0xba0 net/socket.c:2399
  do_sys_recvmmsg+0x181/0x1a0 net/socket.c:2475
  __do_sys_recvmmsg net/socket.c:2493 [inline]
  __se_sys_recvmmsg net/socket.c:2489 [inline]
  __x64_sys_recvmmsg+0xbe/0x150 net/socket.c:2489
  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4407b9
Code: Bad RIP value.
RSP: 002b:00007ffe6735bf58 EFLAGS: 00000207 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 0000000020000000 RCX: 00000000004407b9
RDX: 0000000000000002 RSI: 0000000020003340 RDI: 0000000000000016
RBP: 00000000006cb018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000207 R12: 0000000000401c40
R13: 0000000000401cd0 R14: 0000000000000000 R15: 0000000000000000
INFO: lockdep is turned off.
NMI backtrace for cpu 0
CPU: 0 PID: 900 Comm: khungtaskd Not tainted 4.18.0-rc5+ #132
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x1c9/0x2b4 lib/dump_stack.c:113
  nmi_cpu_backtrace.cold.5+0x19/0xce lib/nmi_backtrace.c:103
  nmi_trigger_cpumask_backtrace+0x151/0x192 lib/nmi_backtrace.c:62
  arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
  trigger_all_cpu_backtrace include/linux/nmi.h:138 [inline]
  check_hung_uninterruptible_tasks kernel/hung_task.c:196 [inline]
  watchdog+0x9c4/0xf80 kernel/hung_task.c:252
  kthread+0x345/0x410 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:412
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt+0x6/0x10  
arch/x86/include/asm/irqflags.h:54

Re: INFO: task hung in aead_recvmsg

[syzbot]

syzbot has bisected this bug to:

commit 0c1e16cd1ec41987cc6671a2bff46ac958c41eb5
Author: Stephan Mueller <smueller@chronox.de>
Date:   Mon Dec 5 14:26:19 2016 +0000

     crypto: algif_aead - fix AEAD tag memory handling

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=12d6d0a6e00000
start commit:   618d919c Merge tag 'libnvdimm-fixes-5.1-rc6' of git://git...
git tree:       upstream
final crash:    https://syzkaller.appspot.com/x/report.txt?x=11d6d0a6e00000
console output: https://syzkaller.appspot.com/x/log.txt?x=16d6d0a6e00000
kernel config:  https://syzkaller.appspot.com/x/.config?x=856fc6d0fbbeede9
dashboard link:  
https://syzkaller.appspot.com/bug?extid=56c7151cad94eec37c521f0e47d2eee53f9361c4
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=11ef592d200000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=16b865fd200000

Reported-by:  
syzbot+56c7151cad94eec37c521f0e47d2eee53f9361c4@syzkaller.appspotmail.com
Fixes: 0c1e16cd1ec4 ("crypto: algif_aead - fix AEAD tag memory handling")

For information about bisection process see: https://goo.gl/tpsmEJ#bisection

Re: INFO: task hung in aead_recvmsg

[Stephan Müller]

Am Sonntag, 1. Dezember 2019, 08:58:00 CET schrieb syzbot:

Hi,

> syzbot has bisected this bug to:
> 
> commit 0c1e16cd1ec41987cc6671a2bff46ac958c41eb5
> Author: Stephan Mueller <smueller@chronox.de>
> Date:   Mon Dec 5 14:26:19 2016 +0000
> 
>      crypto: algif_aead - fix AEAD tag memory handling
> 
> bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=12d6d0a6e00000
> start commit:   618d919c Merge tag 'libnvdimm-fixes-5.1-rc6' of git://git...
> git tree:       upstream
> final crash:    https://syzkaller.appspot.com/x/report.txt?x=11d6d0a6e00000
> console output: https://syzkaller.appspot.com/x/log.txt?x=16d6d0a6e00000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=856fc6d0fbbeede9
> dashboard link:
> https://syzkaller.appspot.com/bug?extid=56c7151cad94eec37c521f0e47d2eee53f93
> 61c4 syz repro:     
> https://syzkaller.appspot.com/x/repro.syz?x=11ef592d200000 C reproducer:  
> https://syzkaller.appspot.com/x/repro.c?x=16b865fd200000
> 
> Reported-by:
> syzbot+56c7151cad94eec37c521f0e47d2eee53f9361c4@syzkaller.appspotmail.com
> Fixes: 0c1e16cd1ec4 ("crypto: algif_aead - fix AEAD tag memory handling")
> 
> For information about bisection process see: https://goo.gl/tpsmEJ#bisection

This issue seems to be triggered when using pcrypt. Pcrypt received a number 
of fixes recently.

Did the test include all of those fixes?

Thanks a lot for the testing!

Ciao
Stephan

Re: INFO: task hung in aead_recvmsg

[Eric Biggers]

On Sun, Dec 01, 2019 at 06:58:17PM +0100, Stephan Müller wrote:
> Am Sonntag, 1. Dezember 2019, 08:58:00 CET schrieb syzbot:
> 
> Hi,
> 
> > syzbot has bisected this bug to:
> > 
> > commit 0c1e16cd1ec41987cc6671a2bff46ac958c41eb5
> > Author: Stephan Mueller <smueller@chronox.de>
> > Date:   Mon Dec 5 14:26:19 2016 +0000
> > 
> >      crypto: algif_aead - fix AEAD tag memory handling
> > 
> > bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=12d6d0a6e00000
> > start commit:   618d919c Merge tag 'libnvdimm-fixes-5.1-rc6' of git://git...
> > git tree:       upstream
> > final crash:    https://syzkaller.appspot.com/x/report.txt?x=11d6d0a6e00000
> > console output: https://syzkaller.appspot.com/x/log.txt?x=16d6d0a6e00000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=856fc6d0fbbeede9
> > dashboard link:
> > https://syzkaller.appspot.com/bug?extid=56c7151cad94eec37c521f0e47d2eee53f93
> > 61c4 syz repro:     
> > https://syzkaller.appspot.com/x/repro.syz?x=11ef592d200000 C reproducer:  
> > https://syzkaller.appspot.com/x/repro.c?x=16b865fd200000
> > 
> > Reported-by:
> > syzbot+56c7151cad94eec37c521f0e47d2eee53f9361c4@syzkaller.appspotmail.com
> > Fixes: 0c1e16cd1ec4 ("crypto: algif_aead - fix AEAD tag memory handling")
> > 
> > For information about bisection process see: https://goo.gl/tpsmEJ#bisection
> 
> This issue seems to be triggered when using pcrypt. Pcrypt received a number 
> of fixes recently.
> 
> Did the test include all of those fixes?
> 
> Thanks a lot for the testing!
> 

No, the pcrypt fixes haven't been applied yet.  One of Herbert's patches has:

	Reported-by: syzbot+56c7151cad94eec37c521f0e47d2eee53f9361c4@syzkaller.appspotmail.com

... so syzbot will close this bug report once this patch is applied and reaches
upstream or linux-next.  It's just a coincidence that syzbot happened to report
a bisection result now.

- Eric