Messages in this thread | | | From | "Jason A. Donenfeld" <> | Date | Thu, 27 Jan 2022 23:26:32 +0100 | Subject | Re: "BUG: Invalid wait context" in invalidate_batched_entropy |
| |
Hi Jonathan,
Thanks for the report. I'll try to reproduce this and see what's going on.
I'm emailing back right away, though, so that I can CC in Andy Lutomirski, who I know has been sitting on a stack of patches that fix up (actually, remove) the locking, so this might be one path to fixing this.
Thanks, Jason
On Thu, Jan 27, 2022 at 11:21 PM Jonathan Neuschäfer <j.neuschaefer@gmx.net> wrote: > > Hi, > > when booting my ARM board with lockdep and CONFIG_PROVE_LOCKING, I get the following message: > > [ 2.500000] ============================= > [ 2.500000] [ BUG: Invalid wait context ] > [ 2.500000] 5.17.0-rc1 #563 Not tainted > [ 2.500000] ----------------------------- > [ 2.500000] swapper/1 is trying to lock: > [ 2.500000] c0b0e9cc (batched_entropy_u32.lock){....}-{3:3}, at: invalidate_batched_entropy+0x18/0x4c > [ 2.500000] other info that might help us debug this: > [ 2.500000] context-{2:2} > [ 2.500000] 3 locks held by swapper/1: > [ 2.500000] #0: c0ae86ac (event_mutex){+.+.}-{4:4}, at: event_trace_init+0x4c/0xd8 > [ 2.500000] #1: c0ae81b8 (trace_event_sem){+.+.}-{4:4}, at: event_trace_init+0x68/0xd8 > [ 2.500000] #2: c19b05cc (&sb->s_type->i_mutex_key#2){+.+.}-{4:4}, at: start_creating+0x40/0xc4 > [ 2.500000] stack backtrace: > [ 2.500000] CPU: 0 PID: 1 Comm: swapper Not tainted 5.17.0-rc1 #563 > [ 2.500000] Hardware name: WPCM450 chip > [ 2.500000] [<c00100a8>] (unwind_backtrace) from [<c000db2c>] (show_stack+0x10/0x14) > [ 2.500000] [<c000db2c>] (show_stack) from [<c0054eec>] (__lock_acquire+0x3f0/0x189c) > [ 2.500000] [<c0054eec>] (__lock_acquire) from [<c0054478>] (lock_acquire+0x2b8/0x354) > [ 2.500000] [<c0054478>] (lock_acquire) from [<c0568028>] (_raw_spin_lock_irqsave+0x60/0x74) > [ 2.500000] [<c0568028>] (_raw_spin_lock_irqsave) from [<c030b6f4>] (invalidate_batched_entropy+0x18/0x4c) > [ 2.500000] [<c030b6f4>] (invalidate_batched_entropy) from [<c030e7fc>] (crng_fast_load+0xf0/0x110) > [ 2.500000] [<c030e7fc>] (crng_fast_load) from [<c030e954>] (add_interrupt_randomness+0x138/0x200) > [ 2.500000] [<c030e954>] (add_interrupt_randomness) from [<c0061b34>] (handle_irq_event_percpu+0x18/0x38) > [ 2.500000] [<c0061b34>] (handle_irq_event_percpu) from [<c0061b8c>] (handle_irq_event+0x38/0x5c) > [ 2.500000] [<c0061b8c>] (handle_irq_event) from [<c0065b28>] (handle_fasteoi_irq+0x9c/0x114) > [ 2.500000] [<c0065b28>] (handle_fasteoi_irq) from [<c0061178>] (handle_irq_desc+0x24/0x34) > [ 2.500000] [<c0061178>] (handle_irq_desc) from [<c056214c>] (generic_handle_arch_irq+0x28/0x3c) > [ 2.500000] [<c056214c>] (generic_handle_arch_irq) from [<c0008eb4>] (__irq_svc+0x54/0x80) > [ 2.500000] Exception stack(0xc1485d48 to 0xc1485d90) > [ 2.500000] 5d40: 9780e804 00000001 c09413d4 200000d3 60000053 c016af54 > [ 2.500000] 5d60: 00000000 c0afa5b8 c14194e0 c19a1d48 c0789ce0 00000000 c1490480 c1485d98 > [ 2.500000] 5d80: c0168970 c0168984 20000053 ffffffff > [ 2.500000] [<c0008eb4>] (__irq_svc) from [<c0168984>] (read_seqbegin.constprop.0+0x6c/0x90) > [ 2.500000] [<c0168984>] (read_seqbegin.constprop.0) from [<c016af54>] (d_lookup+0x14/0x40) > [ 2.500000] [<c016af54>] (d_lookup) from [<c015cecc>] (lookup_dcache+0x18/0x50) > [ 2.500000] [<c015cecc>] (lookup_dcache) from [<c015d868>] (lookup_one_len+0x90/0xe0) > [ 2.500000] [<c015d868>] (lookup_one_len) from [<c01e33e4>] (start_creating+0x68/0xc4) > [ 2.500000] [<c01e33e4>] (start_creating) from [<c01e398c>] (tracefs_create_file+0x30/0x11c) > [ 2.500000] [<c01e398c>] (tracefs_create_file) from [<c00c42f8>] (trace_create_file+0x14/0x38) > [ 2.500000] [<c00c42f8>] (trace_create_file) from [<c00cc854>] (event_create_dir+0x310/0x420) > [ 2.500000] [<c00cc854>] (event_create_dir) from [<c00cc9d8>] (__trace_early_add_event_dirs+0x28/0x50) > [ 2.500000] [<c00cc9d8>] (__trace_early_add_event_dirs) from [<c07c8d64>] (event_trace_init+0x70/0xd8) > [ 2.500000] [<c07c8d64>] (event_trace_init) from [<c07c8560>] (tracer_init_tracefs+0x14/0x284) > [ 2.500000] [<c07c8560>] (tracer_init_tracefs) from [<c000a330>] (do_one_initcall+0xdc/0x288) > [ 2.500000] [<c000a330>] (do_one_initcall) from [<c07bd1e8>] (kernel_init_freeable+0x1c4/0x20c) > [ 2.500000] [<c07bd1e8>] (kernel_init_freeable) from [<c05629c0>] (kernel_init+0x10/0x110) > [ 2.500000] [<c05629c0>] (kernel_init) from [<c00084f8>] (ret_from_fork+0x14/0x3c) > [ 2.500000] Exception stack(0xc1485fb0 to 0xc1485ff8) > [ 2.500000] 5fa0: 00000000 00000000 00000000 00000000 > [ 2.500000] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 > [ 2.500000] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000 > > > > I wasn't able to bisect it, but I can see it as far back as v5.13 > (I can't easily test earlier kernels). The lock in question was > introduced with v5.2-rc1: > > > commit b7d5dc21072cda7124d13eae2aefb7343ef94197 > Author: Sebastian Andrzej Siewior <bigeasy@linutronix.de> > Date: Sat Apr 20 00:09:51 2019 -0400 > > random: add a spinlock_t to struct batched_entropy > > The per-CPU variable batched_entropy_uXX is protected by get_cpu_var(). > This is just a preempt_disable() which ensures that the variable is only > from the local CPU. It does not protect against users on the same CPU > from another context. It is possible that a preemptible context reads > slot 0 and then an interrupt occurs and the same value is read again. > > [...] > Add a spinlock_t to the batched_entropy data structure and acquire the > lock while accessing it. Acquire the lock with disabled interrupts > because this function may be used from interrupt context. > > Remove the batched_entropy_reset_lock lock. Now that we have a lock for > the data scructure, we can access it from a remote CPU. > > Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> > Signed-off-by: Theodore Ts'o <tytso@mit.edu> > > > I'm not very familiar with the finer details of locking rules and > lockdep, so any ideas (or patches) to fix this will be appreciated. > > > Best regards, > Jonathan Neuschäfer > -- > > > In case it's relevant, here is my config: > > CONFIG_SYSVIPC=y > CONFIG_NO_HZ=y > CONFIG_HIGH_RES_TIMERS=y > CONFIG_PREEMPT=y > CONFIG_IKCONFIG=y > CONFIG_IKCONFIG_PROC=y > CONFIG_LOG_BUF_SHIFT=19 > CONFIG_CGROUPS=y > CONFIG_NAMESPACES=y > CONFIG_BLK_DEV_INITRD=y > CONFIG_INITRAMFS_SOURCE="rootfs.cpio" > CONFIG_CC_OPTIMIZE_FOR_SIZE=y > CONFIG_EXPERT=y > CONFIG_PROFILING=y > # CONFIG_ARCH_MULTI_V7 is not set > CONFIG_ARCH_NPCM=y > CONFIG_ARCH_WPCM450=y > CONFIG_CPU_DCACHE_WRITETHROUGH=y > CONFIG_AEABI=y > CONFIG_HIGHMEM=y > CONFIG_UACCESS_WITH_MEMCPY=y > CONFIG_ARM_APPENDED_DTB=y > CONFIG_CMDLINE="earlyprintk debug console=ttyS0,115200 panic=-1" > CONFIG_CMDLINE_EXTEND=y > CONFIG_KEXEC=y > # CONFIG_ATAGS_PROC is not set > CONFIG_CPU_FREQ=y > CONFIG_CPU_FREQ_STAT=y > CONFIG_CPU_FREQ_DEFAULT_GOV_ONDEMAND=y > CONFIG_CPU_IDLE=y > CONFIG_KPROBES=y > CONFIG_MODULES=y > CONFIG_MODULE_UNLOAD=y > CONFIG_ZSWAP=y > CONFIG_ZSWAP_DEFAULT_ON=y > CONFIG_Z3FOLD=y > CONFIG_NET=y > CONFIG_PACKET=y > CONFIG_UNIX=y > CONFIG_INET=y > CONFIG_IP_MULTICAST=y > CONFIG_IP_PNP=y > CONFIG_IP_PNP_DHCP=y > CONFIG_IP_PNP_BOOTP=y > CONFIG_NET_DSA=y > CONFIG_NET_DSA_TAG_DSA=y > CONFIG_NET_DSA_TAG_EDSA=y > CONFIG_NET_DSA_TAG_TRAILER=y > CONFIG_NET_NCSI=y > CONFIG_NCSI_OEM_CMD_GET_MAC=y > CONFIG_NET_PKTGEN=m > # CONFIG_WIRELESS is not set > CONFIG_DEVTMPFS=y > CONFIG_DEVTMPFS_MOUNT=y > CONFIG_DEVTMPFS_SAFE=y > CONFIG_MTD=y > CONFIG_MTD_CMDLINE_PARTS=y > CONFIG_MTD_BLOCK=y > CONFIG_MTD_CFI=y > CONFIG_MTD_JEDECPROBE=y > CONFIG_MTD_CFI_ADV_OPTIONS=y > CONFIG_MTD_CFI_GEOMETRY=y > # CONFIG_MTD_MAP_BANK_WIDTH_4 is not set > CONFIG_MTD_CFI_INTELEXT=y > CONFIG_MTD_CFI_STAA=y > CONFIG_MTD_PHYSMAP=y > CONFIG_MTD_SPI_NOR=y > CONFIG_BLK_DEV_LOOP=y > CONFIG_SRAM=y > CONFIG_EEPROM_AT24=y > CONFIG_SCSI=y > # CONFIG_SCSI_PROC_FS is not set > # CONFIG_SCSI_LOWLEVEL is not set > CONFIG_NETDEVICES=y > # CONFIG_NET_VENDOR_ALACRITECH is not set > # CONFIG_NET_VENDOR_AMAZON is not set > # CONFIG_NET_VENDOR_AQUANTIA is not set > # CONFIG_NET_VENDOR_ARC is not set > # CONFIG_NET_VENDOR_BROADCOM is not set > # CONFIG_NET_VENDOR_CADENCE is not set > # CONFIG_NET_VENDOR_CAVIUM is not set > # CONFIG_NET_VENDOR_CIRRUS is not set > # CONFIG_NET_VENDOR_CORTINA is not set > # CONFIG_NET_VENDOR_EZCHIP is not set > # CONFIG_NET_VENDOR_FARADAY is not set > # CONFIG_NET_VENDOR_GOOGLE is not set > # CONFIG_NET_VENDOR_HISILICON is not set > # CONFIG_NET_VENDOR_HUAWEI is not set > # CONFIG_NET_VENDOR_INTEL is not set > # CONFIG_NET_VENDOR_MICROSOFT is not set > # CONFIG_NET_VENDOR_LITEX is not set > # CONFIG_NET_VENDOR_MARVELL is not set > # CONFIG_NET_VENDOR_MELLANOX is not set > # CONFIG_NET_VENDOR_MICREL is not set > # CONFIG_NET_VENDOR_MICROCHIP is not set > # CONFIG_NET_VENDOR_MICROSEMI is not set > # CONFIG_NET_VENDOR_NATSEMI is not set > # CONFIG_NET_VENDOR_NETRONOME is not set > # CONFIG_NET_VENDOR_NI is not set > # CONFIG_NET_VENDOR_PENSANDO is not set > # CONFIG_NET_VENDOR_QUALCOMM is not set > # CONFIG_NET_VENDOR_RENESAS is not set > # CONFIG_NET_VENDOR_ROCKER is not set > # CONFIG_NET_VENDOR_SAMSUNG is not set > # CONFIG_NET_VENDOR_SEEQ is not set > # CONFIG_NET_VENDOR_SOLARFLARE is not set > # CONFIG_NET_VENDOR_SMSC is not set > # CONFIG_NET_VENDOR_SOCIONEXT is not set > # CONFIG_NET_VENDOR_STMICRO is not set > # CONFIG_NET_VENDOR_SYNOPSYS is not set > # CONFIG_NET_VENDOR_VIA is not set > # CONFIG_NET_VENDOR_WIZNET is not set > # CONFIG_NET_VENDOR_XILINX is not set > CONFIG_DAVICOM_PHY=y > CONFIG_MARVELL_PHY=y > CONFIG_MICREL_PHY=y > CONFIG_REALTEK_PHY=y > # CONFIG_WLAN is not set > CONFIG_INPUT_EVDEV=y > CONFIG_KEYBOARD_QT1070=m > CONFIG_KEYBOARD_GPIO=y > # CONFIG_INPUT_MOUSE is not set > CONFIG_VT_HW_CONSOLE_BINDING=y > CONFIG_LEGACY_PTY_COUNT=16 > CONFIG_SERIAL_8250=y > CONFIG_SERIAL_8250_CONSOLE=y > CONFIG_SERIAL_8250_NR_UARTS=6 > CONFIG_SERIAL_8250_RUNTIME_UARTS=6 > CONFIG_SERIAL_8250_EXTENDED=y > CONFIG_SERIAL_8250_MANY_PORTS=y > CONFIG_SERIAL_8250_ASPEED_VUART=m > CONFIG_SERIAL_OF_PLATFORM=y > CONFIG_HW_RANDOM=y > CONFIG_I2C=y > # CONFIG_I2C_COMPAT is not set > CONFIG_I2C_CHARDEV=y > CONFIG_I2C_MUX=y > CONFIG_SPI=y > CONFIG_SPI_BITBANG=y > CONFIG_PINCTRL_SINGLE=y > CONFIG_GPIOLIB=y > CONFIG_DEBUG_GPIO=y > CONFIG_GPIO_SYSFS=y > CONFIG_GPIO_PCF857X=y > CONFIG_POWER_RESET=y > CONFIG_POWER_RESET_GPIO=y > CONFIG_POWER_SUPPLY=y > CONFIG_THERMAL=y > CONFIG_WATCHDOG=y > CONFIG_NPCM7XX_WATCHDOG=y > CONFIG_MFD_ATMEL_HLCDC=y > CONFIG_MFD_SYSCON=y > CONFIG_REGULATOR=y > CONFIG_REGULATOR_FIXED_VOLTAGE=y > # CONFIG_DRM_DEBUG_MODESET_LOCK is not set > CONFIG_FB=y > CONFIG_FB_MODE_HELPERS=y > CONFIG_HID_A4TECH=y > CONFIG_HID_APPLE=y > CONFIG_HID_BELKIN=y > CONFIG_HID_CHERRY=y > CONFIG_HID_CYPRESS=y > CONFIG_HID_DRAGONRISE=y > CONFIG_HID_EZKEY=y > CONFIG_HID_GYRATION=y > CONFIG_HID_ITE=y > CONFIG_HID_TWINHAN=y > CONFIG_HID_KENSINGTON=y > CONFIG_HID_REDRAGON=y > CONFIG_HID_MICROSOFT=y > CONFIG_HID_MONTEREY=y > CONFIG_HID_PANTHERLORD=y > CONFIG_HID_PETALYNX=y > CONFIG_HID_SUNPLUS=y > CONFIG_HID_GREENASIA=y > CONFIG_HID_SMARTJOYPLUS=y > CONFIG_HID_TOPSEED=y > CONFIG_HID_ZEROPLUS=y > CONFIG_USB_CHIPIDEA=y > CONFIG_USB_CHIPIDEA_UDC=y > CONFIG_NOP_USB_XCEIV=y > CONFIG_USB_GADGET=y > CONFIG_U_SERIAL_CONSOLE=y > CONFIG_USB_CONFIGFS=y > CONFIG_USB_CONFIGFS_SERIAL=y > CONFIG_USB_CONFIGFS_RNDIS=y > CONFIG_USB_CONFIGFS_MASS_STORAGE=y > CONFIG_USB_CONFIGFS_F_HID=y > CONFIG_MMC=y > CONFIG_SDIO_UART=y > CONFIG_MMC_SDHCI=m > CONFIG_MMC_SDHCI_PLTFM=m > CONFIG_MMC_SDHCI_OF_ASPEED=m > CONFIG_NEW_LEDS=y > CONFIG_LEDS_CLASS=y > CONFIG_LEDS_GPIO=y > CONFIG_LEDS_TRIGGERS=y > CONFIG_LEDS_TRIGGER_TIMER=y > CONFIG_LEDS_TRIGGER_ONESHOT=y > CONFIG_LEDS_TRIGGER_MTD=y > CONFIG_LEDS_TRIGGER_HEARTBEAT=y > CONFIG_LEDS_TRIGGER_CPU=y > CONFIG_LEDS_TRIGGER_ACTIVITY=y > CONFIG_LEDS_TRIGGER_DEFAULT_ON=y > CONFIG_LEDS_TRIGGER_PANIC=y > CONFIG_LEDS_TRIGGER_TTY=y > CONFIG_RTC_CLASS=y > CONFIG_RTC_DRV_RS5C372=y > CONFIG_RTC_DRV_PCF8563=y > CONFIG_RTC_DRV_S35390A=y > CONFIG_RTC_DRV_RV3029C2=m > CONFIG_DMADEVICES=y > CONFIG_SYNC_FILE=y > # CONFIG_DMABUF_DEBUG is not set > # CONFIG_VIRTIO_MENU is not set > # CONFIG_VHOST_MENU is not set > CONFIG_STAGING=y > # CONFIG_SURFACE_PLATFORMS is not set > # CONFIG_IOMMU_SUPPORT is not set > CONFIG_MEMORY=y > CONFIG_PWM=y > CONFIG_PWM_ATMEL_HLCDC_PWM=m > CONFIG_GENERIC_PHY=y > CONFIG_ISO9660_FS=m > CONFIG_JOLIET=y > CONFIG_UDF_FS=m > CONFIG_MSDOS_FS=y > CONFIG_VFAT_FS=y > CONFIG_TMPFS=y > # CONFIG_MISC_FILESYSTEMS is not set > # CONFIG_NETWORK_FILESYSTEMS is not set > CONFIG_NLS_CODEPAGE_437=y > CONFIG_NLS_CODEPAGE_850=y > CONFIG_NLS_ISO8859_1=y > CONFIG_NLS_ISO8859_2=y > CONFIG_NLS_UTF8=y > CONFIG_KEYS=y > CONFIG_LSM="lockdown,yama,loadpin,safesetid,integrity,bpf" > CONFIG_CRYPTO_RSA=y > CONFIG_CRYPTO_CCM=y > CONFIG_CRYPTO_GCM=y > CONFIG_CRYPTO_CMAC=y > CONFIG_CRYPTO_SHA256=y > CONFIG_CRYPTO_AES=y > CONFIG_CRYPTO_DEFLATE=y > CONFIG_CRYPTO_ZSTD=y > CONFIG_ASYMMETRIC_KEY_TYPE=y > CONFIG_ASYMMETRIC_PUBLIC_KEY_SUBTYPE=y > CONFIG_X509_CERTIFICATE_PARSER=y > CONFIG_PKCS7_MESSAGE_PARSER=y > CONFIG_SYSTEM_TRUSTED_KEYRING=y > CONFIG_CRC_CCITT=y > CONFIG_CRC16=y > CONFIG_LIBCRC32C=y > CONFIG_DMA_API_DEBUG=y > CONFIG_PRINTK_TIME=y > CONFIG_DEBUG_INFO=y > CONFIG_DEBUG_INFO_COMPRESSED=y > CONFIG_MAGIC_SYSRQ=y > CONFIG_DEBUG_FS=y > # CONFIG_SCHED_DEBUG is not set > # CONFIG_DEBUG_PREEMPT is not set > CONFIG_PROVE_LOCKING=y > CONFIG_PROVE_RAW_LOCK_NESTING=y > CONFIG_DEBUG_LOCKDEP=y > CONFIG_DEBUG_ATOMIC_SLEEP=y > # CONFIG_FTRACE is not set > CONFIG_BACKTRACE_VERBOSE=y > CONFIG_DEBUG_USER=y > CONFIG_DEBUG_LL=y > CONFIG_DEBUG_LL_UART_8250=y > CONFIG_DEBUG_UART_PHYS=0xb8000000 > CONFIG_DEBUG_UART_VIRT=0x0ff000000 > CONFIG_DEBUG_UART_8250_WORD=y > CONFIG_EARLY_PRINTK=y
| |