lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <CAJfuBxyKVXwL+UU12EhZ8V7Omf_gGjzyYo8MezRC+1LnqG6pGQ@mail.gmail.com>
Date:   Wed, 12 Aug 2020 09:11:19 -0600
From:   jim.cromie@...il.com
To:     kernel test robot <lkp@...el.com>
Cc:     Jason Baron <jbaron@...mai.com>,
        LKML <linux-kernel@...r.kernel.org>,
        Sumit Semwal <sumit.semwal@...aro.org>,
        linux-media@...r.kernel.org, dri-devel@...ts.freedesktop.org,
        linaro-mm-sig@...ts.linaro.org, lkp@...ts.01.org
Subject: Re: [dyndbg] 4397a3e7bf: BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h

On Sat, Aug 8, 2020 at 10:36 PM kernel test robot <lkp@...el.com> wrote:
>
>
> If you fix the issue, kindly add following tag
> Reported-by: kernel test robot <lkp@...el.com>
>
>
> [   29.668135] BUG: sleeping function called from invalid context at mm/slab.h:567
> [   29.668942] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 1, name: swapper/0
> [   29.669798] 4 locks held by swapper/0/1:
> [   29.670263]  #0: ffff8fe0d5065040 (&zspage->lock){.+.+}-{2:2}, at: zs_map_object+0x82/0x330
> [   29.671178]  #1: ffff8fe0d5065040 (&zspage->lock){.+.+}-{2:2}, at: zs_map_object+0x82/0x330
> [   29.672091]  #2: ffff8fe0d5065040 (&zspage->lock){.+.+}-{2:2}, at: zs_map_object+0x82/0x330
> [   29.672988]  #3: ffff8fe0d5065040 (&zspage->lock){.+.+}-{2:2}, at: zs_map_object+0x82/0x330
> [   29.673892] Preemption disabled at:
> [   29.673894] [<ffffffff97bcb678>] zs_map_object+0x38/0x330

So, this looks worrying.
I mean, 4 locks taken by same code.
Its feeling like an api misunderstanding.

so 1st question:  is zpool / zmalloc not intended for use / setup
during __init ?
I seem to be breaking basic rules.
my zpool is filled with a late_initcall, I also tried
late_initcall_sync to try to
wait out all the other init stuff, that didnt work.

the point of this patch was to not retire every mapping right after it is used,
but to keep those for enabled callsites.
all these are mapped RO
It appears those locks are held across the map-unmap interval ??
I wouldnt expect that much pr-debug traffic, nor any parellelism at
all (no -smp qemu args)

Id also add that Ive seen a bunch of different lockdep reports
from different configurations, all more complicated than this one.



> [   29.674897] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.8.0-10185-g4397a3e7bf020 #1
> [   29.675728] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> [   29.676622] Call Trace:
> [   29.676956]  dump_stack+0x96/0xd0
> [   29.677358]  ___might_sleep.cold+0xff/0x115
> [   29.677831]  ? getname_kernel+0x25/0x110
> [   29.678281]  kmem_cache_alloc+0x212/0x2d0
> [   29.678739]  getname_kernel+0x25/0x110
> [   29.679175]  ? rest_init+0x23e/0x23e
> [   29.679598]  kernel_execve+0x19/0x1c0
> [   29.680034]  kernel_init+0x6e/0x112
> [   29.680450]  ret_from_fork+0x22/0x30
> [   29.680905]
> [   29.681171] =============================
> [   29.681629] [ BUG: Invalid wait context ]
> [   29.682087] 5.8.0-10185-g4397a3e7bf020 #1 Tainted: G        W
> [   29.682741] -----------------------------
> [   29.683200] swapper/0/1 is trying to lock:
> [   29.683663] ffff8fe003808128 (&mm->mmap_lock#2){++++}-{3:3}, at: alloc_bprm+0x126/0x2b0
> [   29.684537] other info that might help us debug this:
> [   29.685079] context-{4:4}
> [   29.685426] 4 locks held by swapper/0/1:
> [   29.685876]  #0: ffff8fe0d5065040 (&zspage->lock){.+.+}-{2:2}, at: zs_map_object+0x82/0x330
> [   29.686767]  #1: ffff8fe0d5065040 (&zspage->lock){.+.+}-{2:2}, at: zs_map_object+0x82/0x330
> [   29.687659]  #2: ffff8fe0d5065040 (&zspage->lock){.+.+}-{2:2}, at: zs_map_object+0x82/0x330
> [   29.688557]  #3: ffff8fe0d5065040 (&zspage->lock){.+.+}-{2:2}, at: zs_map_object+0x82/0x330
> [   29.689449] stack backtrace:
> [   29.689817] CPU: 1 PID: 1 Comm: swapper/0 Tainted: G        W         5.8.0-10185-g4397a3e7bf020 #1
> [   29.690762] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> [   29.691651] Call Trace:
> [   29.691990]  dump_stack+0x96/0xd0
> [   29.692396]  __lock_acquire.cold+0xc4/0x1a5
> [   29.692870]  lock_acquire+0xab/0x390
> [   29.693295]  ? alloc_bprm+0x126/0x2b0
> [   29.693728]  down_write_killable+0x3d/0xa0
> [   29.695267]  ? alloc_bprm+0x126/0x2b0
> [   29.695701]  alloc_bprm+0x126/0x2b0
> [   29.696125]  ? rest_init+0x23e/0x23e
> [   29.696551]  kernel_execve+0x38/0x1c0
> [   29.696983]  kernel_init+0x6e/0x112
> [   29.697401]  ret_from_fork+0x22/0x30
> [   29.697888] BUG: scheduling while atomic: swapper/0/1/0x00000011
> [   29.698541] INFO: lockdep is turned off.
> [   29.699000] Modules linked in:
> [   29.699396] Preemption disabled at:
> [   29.699398] [<ffffffff97bcb678>] zs_map_object+0x38/0x330
> [   29.700414] CPU: 1 PID: 1 Comm: swapper/0 Tainted: G        W         5.8.0-10185-g4397a3e7bf020 #1
> [   29.701373] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> [   29.702268] Call Trace:
> [   29.702604]  dump_stack+0x96/0xd0
> [   29.703012]  __schedule_bug.cold+0xa1/0xb2
> [   29.703482]  __schedule+0x8e3/0xa90
> [   29.703906]  ? try_to_wake_up+0x1d0/0x860
> [   29.704371]  ? wait_for_completion+0x81/0x110
> [   29.704861]  schedule+0x53/0x100
> [   29.705259]  schedule_timeout+0x205/0x2b0
> [   29.705722]  ? try_to_wake_up+0x7d/0x860
> [   29.706176]  ? _raw_spin_unlock_irq+0x24/0x50
> [   29.706666]  ? wait_for_completion+0x81/0x110
> [   29.707155]  ? wait_for_completion+0x81/0x110
> [   29.707646]  wait_for_completion+0xab/0x110
> [   29.708130]  stop_one_cpu+0x87/0xb0
> [   29.708551]  ? set_cpus_allowed_ptr+0x20/0x20
> [   29.709044]  ? _raw_spin_unlock_irqrestore+0x41/0x70
> [   29.709581]  sched_exec+0x98/0xd0
> [   29.709989]  bprm_execve+0x1d7/0x3a0
> [   29.710416]  ? rest_init+0x23e/0x23e
> [   29.710844]  kernel_execve+0x135/0x1c0
> [   29.711284]  kernel_init+0x6e/0x112
> [   29.711703]  ret_from_fork+0x22/0x30
> [   29.712298] Failed to execute /init (error -14)
> [   29.713523] Run /sbin/init as init process
> [   29.714612]   with arguments:
> [   29.715484]     /sbin/init
> [   29.716328]   with environment:
> [   29.717235]     HOME=/
> [   29.717983]     TERM=linux
> [   29.718801]     user=lkp
> [   29.719587]     job=/lkp/jobs/scheduled/vm-snb-151/boot-1-aliyun-x86_64-20190626.cgz-4397a3e7bf020ef040be371dcc178db258b928b4-20200808-11882-w8z2ep-10.yaml
> [   29.721551]     ARCH=x86_64
> [   29.721986]     kconfig=x86_64-rhel-7.6-kselftests
> [   29.722623]     branch=linux-review/Jim-Cromie/dyndbg-WIP-diet-plan/20200808-041343
> [   29.723634]     commit=4397a3e7bf020ef040be371dcc178db258b928b4
> [   29.724395]     BOOT_IMAGE=/pkg/linux/x86_64-rhel-7.6-kselftests/gcc-9/4397a3e7bf020ef040be371dcc178db258b928b4/vmlinuz-5.8.0-10185-g4397a3e7bf020
> [   29.725943]     max_uptime=600
> [   29.726406]     RESULT_ROOT=/result/boot/1/vm-snb/aliyun-x86_64-20190626.cgz/x86_64-rhel-7.6-kselftests/gcc-9/4397a3e7bf020ef040be371dcc178db258b928b4/8
> [   29.728009]     LKP_SERVER=inn
> [   29.728475]     softlockup_panic=1
> [   29.728969]     prompt_ramdisk=0
> [   29.729449]     vga=normal
> [   29.729967] Starting init: /sbin/init exists but couldn't execute it (error -14)
> [   29.730967] Run /etc/init as init process
> [   29.731526]   with arguments:
> [   29.731986]     /etc/init
> [   29.732410]   with environment:
> [   29.732880]     HOME=/
> [   29.733277]     TERM=linux
> [   29.733711]     user=lkp
> [   29.734125]     job=/lkp/jobs/scheduled/vm-snb-151/boot-1-aliyun-x86_64-20190626.cgz-4397a3e7bf020ef040be371dcc178db258b928b4-20200808-11882-w8z2ep-10.yaml
> [   29.735762]     ARCH=x86_64
> [   29.736211]     kconfig=x86_64-rhel-7.6-kselftests
> [   29.736844]     branch=linux-review/Jim-Cromie/dyndbg-WIP-diet-plan/20200808-041343
> [   29.737860]     commit=4397a3e7bf020ef040be371dcc178db258b928b4
> [   29.738609]     BOOT_IMAGE=/pkg/linux/x86_64-rhel-7.6-kselftests/gcc-9/4397a3e7bf020ef040be371dcc178db258b928b4/vmlinuz-5.8.0-10185-g4397a3e7bf020
> [   29.740172]     max_uptime=600
> [   29.740634]     RESULT_ROOT=/result/boot/1/vm-snb/aliyun-x86_64-20190626.cgz/x86_64-rhel-7.6-kselftests/gcc-9/4397a3e7bf020ef040be371dcc178db258b928b4/8
> [   29.742238]     LKP_SERVER=inn
> [   29.742699]     softlockup_panic=1
> [   29.743202]     prompt_ramdisk=0
> [   29.743680]     vga=normal
> [   29.744156] Run /bin/init as init process
> [   29.744719]   with arguments:
> [   29.745179]     /bin/init
> [   29.745599]   with environment:
> [   29.746074]     HOME=/
> [   29.746468]     TERM=linux
> [   29.746894]     user=lkp
> [   29.747309]     job=/lkp/jobs/scheduled/vm-snb-151/boot-1-aliyun-x86_64-20190626.cgz-4397a3e7bf020ef040be371dcc178db258b928b4-20200808-11882-w8z2ep-10.yaml
> [   29.748964]     ARCH=x86_64
> [   29.749406]     kconfig=x86_64-rhel-7.6-kselftests
> [   29.750047]     branch=linux-review/Jim-Cromie/dyndbg-WIP-diet-plan/20200808-041343
> [   29.751067]     commit=4397a3e7bf020ef040be371dcc178db258b928b4
> [   29.751818]     BOOT_IMAGE=/pkg/linux/x86_64-rhel-7.6-kselftests/gcc-9/4397a3e7bf020ef040be371dcc178db258b928b4/vmlinuz-5.8.0-10185-g4397a3e7bf020
> [   29.753381]     max_uptime=600
> [   29.753845]     RESULT_ROOT=/result/boot/1/vm-snb/aliyun-x86_64-20190626.cgz/x86_64-rhel-7.6-kselftests/gcc-9/4397a3e7bf020ef040be371dcc178db258b928b4/8
> [   29.755455]     LKP_SERVER=inn
> [   29.755923]     softlockup_panic=1
> [   29.756425]     prompt_ramdisk=0
> [   29.756905]     vga=normal
> [   29.757375] Run /bin/sh as init process
> [   29.757921]   with arguments:
> [   29.758380]     /bin/sh
> [   29.758782]   with environment:
> [   29.759256]     HOME=/
> [   29.759650]     TERM=linux
> [   29.760089]     user=lkp
> [   29.760501]     job=/lkp/jobs/scheduled/vm-snb-151/boot-1-aliyun-x86_64-20190626.cgz-4397a3e7bf020ef040be371dcc178db258b928b4-20200808-11882-w8z2ep-10.yaml
> [   29.762137]     ARCH=x86_64
> [   29.762574]     kconfig=x86_64-rhel-7.6-kselftests
> [   29.763213]     branch=linux-review/Jim-Cromie/dyndbg-WIP-diet-plan/20200808-041343
> [   29.764255]     commit=4397a3e7bf020ef040be371dcc178db258b928b4
> [   29.765006]     BOOT_IMAGE=/pkg/linux/x86_64-rhel-7.6-kselftests/gcc-9/4397a3e7bf020ef040be371dcc178db258b928b4/vmlinuz-5.8.0-10185-g4397a3e7bf020
> [   29.766567]     max_uptime=600
>
>
> To reproduce:
>
>         # build kernel
>         cd linux
>         cp config-5.8.0-10185-g4397a3e7bf020 .config
>         make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
>
>         git clone https://github.com/intel/lkp-tests.git
>         cd lkp-tests
>         bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
>
>
>
> Thanks,
> lkp
>

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ