Your message dated Thu, 20 Feb 2025 11:12:51 +0100 (CET)
with message-id <20250220101251.f400ebe2...@eldamar.lan>
and subject line Closing this bug (BTS maintenance for src:linux bugs)
has caused the Debian Bug report #793394,
regarding NMI handler & perf interrupts take too long
to be marked as done.
This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.
(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact ow...@bugs.debian.org
immediately.)
--
793394: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=793394
Debian Bug Tracking System
Contact ow...@bugs.debian.org with problems
--- Begin Message ---
Package: src:linux
Version: 3.16.7-ckt11-1+deb8u2
Severity: normal
File: /boot/vmlinuz-3.16.0-4-amd64
Hello,
I am regularly getting messages of the following form from the kernel:
| Jul 23 06:46:30 ebox kernel: [ 1.432009] perf interrupt took too long (3688 >
2500), lowering kernel.perf_event_max_sample_rate to 50000
| Jul 23 07:01:11 ebox kernel: [ 883.330989] NMI handler
(perf_event_nmi_handler) took too long to run: xxx msecs
where xxx is typically multiple msecs.
I am not using perf, and this happens even right after boot (see the
timestamp above).
This looks as if it is related to
http://linux-kernel.2935.n7.nabble.com/scheduling-while-atomic-amp-hang-td679062i20.html.
Best,
-Nikolaus
-- Package-specific info:
** Version:
Linux version 3.16.0-4-amd64 (debian-kernel@lists.debian.org) (gcc version
4.8.4 (Debian 4.8.4-1) ) #1 SMP Debian 3.16.7-ckt11-1+deb8u2 (2015-07-17)
** Command line:
BOOT_IMAGE=/root/boot/vmlinuz-3.16.0-4-amd64 root=/dev/sda ro
rootflags=subvol=root console=ttyS0,19200n8
** Not tainted
** Kernel log:
[ 1.376821] systemd[1]: Inserted module 'autofs4'
[ 1.377948] systemd[1]: Set hostname to <ebox>.
[ 1.432009] perf interrupt took too long (3688 > 2500), lowering
kernel.perf_event_max_sample_rate to 50000
[ 1.438130] systemd[1]: Cannot add dependency job for unit
display-manager.service, ignoring: Unit display-manager.service failed to load:
No such file or directory.
[ 1.441345] systemd[1]: Expecting device dev-ttyS0.device...
[ 1.443868] systemd[1]: Starting Forward Password Requests to Wall Directory
Watch.
[ 1.445187] systemd[1]: Started Forward Password Requests to Wall Directory
Watch.
[ 1.446518] systemd[1]: Starting Remote File Systems (Pre).
[ 1.448749] systemd[1]: Reached target Remote File Systems (Pre).
[ 1.449796] systemd[1]: Starting Arbitrary Executable File Formats File
System Automount Point.
[ 1.453026] systemd[1]: Set up automount Arbitrary Executable File Formats
File System Automount Point.
[ 1.455141] systemd[1]: Starting Encrypted Volumes.
[ 1.457297] systemd[1]: Reached target Encrypted Volumes.
[ 1.458288] systemd[1]: Starting Dispatch Password Requests to Console
Directory Watch.
[ 1.459711] systemd[1]: Started Dispatch Password Requests to Console
Directory Watch.
[ 1.460998] systemd[1]: Starting Paths.
[ 1.462654] systemd[1]: Reached target Paths.
[ 1.463391] systemd[1]: Expecting device dev-sdb.device...
[ 1.465424] systemd[1]: Expecting device dev-sda.device...
[ 1.467370] systemd[1]: Starting Root Slice.
[ 1.469176] systemd[1]: Created slice Root Slice.
[ 1.469957] systemd[1]: Starting User and Session Slice.
[ 1.472220] systemd[1]: Created slice User and Session Slice.
[ 1.473229] systemd[1]: Starting Delayed Shutdown Socket.
[ 1.475477] systemd[1]: Listening on Delayed Shutdown Socket.
[ 1.476481] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
[ 1.479219] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[ 1.480493] systemd[1]: Starting Journal Socket (/dev/log).
[ 1.482755] systemd[1]: Listening on Journal Socket (/dev/log).
[ 1.483823] systemd[1]: Starting udev Kernel Socket.
[ 1.485828] systemd[1]: Listening on udev Kernel Socket.
[ 1.486724] systemd[1]: Starting udev Control Socket.
[ 1.488792] systemd[1]: Listening on udev Control Socket.
[ 1.489686] systemd[1]: Starting Journal Socket.
[ 1.491529] systemd[1]: Listening on Journal Socket.
[ 1.492424] systemd[1]: Starting System Slice.
[ 1.494513] systemd[1]: Created slice System Slice.
[ 1.495329] systemd[1]: Started File System Check on Root Device.
[ 1.496339] systemd[1]: Starting system-systemd\x2dfsck.slice.
[ 1.498750] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[ 1.499872] systemd[1]: Starting system-serial\x2dgetty.slice.
[ 1.502153] systemd[1]: Created slice system-serial\x2dgetty.slice.
[ 1.503216] systemd[1]: Starting Increase datagram queue length...
[ 1.507085] systemd[1]: Starting Load Kernel Modules...
[ 1.509518] systemd[1]: Starting Create list of required static device nodes
for the current kernel...
[ 1.513371] systemd[1]: Starting udev Coldplug all Devices...
[ 1.518738] systemd[1]: Mounting Huge Pages File System...
[ 1.520698] tsc: Refined TSC clocksource calibration: 2800.076 MHz
[ 1.524858] fuse init (API version 7.23)
[ 1.529101] systemd[1]: Started Set Up Additional Binary Formats.
[ 1.530156] systemd[1]: Mounting POSIX Message Queue File System...
[ 1.533151] systemd[1]: Mounting Debug File System...
[ 1.535665] systemd[1]: Starting Slices.
[ 1.539506] systemd[1]: Reached target Slices.
[ 1.542982] systemd[1]: Starting Remount Root and Kernel File Systems...
[ 1.550397] systemd[1]: Started Increase datagram queue length.
[ 1.553028] systemd[1]: Started Load Kernel Modules.
[ 1.556443] systemd[1]: Started Create list of required static device nodes
for the current kernel.
[ 1.564616] systemd[1]: Starting Create Static Device Nodes in /dev...
[ 1.572570] BTRFS info (device sda): disk space caching is enabled
[ 1.575423] systemd[1]: Mounted Configuration File System.
[ 1.579904] systemd[1]: Mounting FUSE Control File System...
[ 1.586042] systemd[1]: Starting Apply Kernel Variables...
[ 1.591751] systemd[1]: Starting Syslog Socket.
[ 1.596204] systemd[1]: Listening on Syslog Socket.
[ 1.598167] systemd[1]: Starting Journal Service...
[ 1.601993] systemd[1]: Started Journal Service.
[ 1.652649] systemd-udevd[178]: starting version 215
[ 1.712918] input: Power Button as
/devices/LNXSYSTM:00/LNXPWRBN:00/input/input2
[ 1.714457] ACPI: Power Button [PWRF]
[ 1.726485] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700,
revision 0
[ 1.731859] [drm] Initialized drm 1.1.0 20060810
[ 1.737006] input: PC Speaker as /devices/platform/pcspkr/input/input3
[ 1.785301] AVX version of gcm_enc/dec engaged.
[ 1.807396] Adding 262140k swap on /dev/sdb. Priority:-1 extents:1
across:262140k FS
[ 1.817676] ppdev: user-space parallel port driver
[ 1.819850] alg: No test for __gcm-aes-aesni (__driver-gcm-aes-aesni)
[ 1.828955] random: nonblocking pool is initialized
[ 1.856274] alg: No test for crc32 (crc32-pclmul)
[ 1.937561] systemd-journald[177]: Received request to flush runtime journal
from PID 1
[ 2.409036] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 2.471744] nf_conntrack version 0.5.0 (8002 buckets, 32008 max)
[ 2.482590] tun: Universal TUN/TAP device driver, 1.6
[ 2.483417] tun: (C) 1999-2004 Max Krasnyansky <m...@qualcomm.com>
[ 2.582265] input: ImExPS/2 Generic Explorer Mouse as
/devices/platform/i8042/serio1/input/input4
[ 2.628009] perf interrupt took too long (7140 > 5000), lowering
kernel.perf_event_max_sample_rate to 25000
[ 3.561638] perf interrupt took too long (10299 > 10000), lowering
kernel.perf_event_max_sample_rate to 12500
[ 6.804009] perf interrupt took too long (22551 > 20000), lowering
kernel.perf_event_max_sample_rate to 6250
[ 883.330989] perf interrupt took too long (40417 > 38461), lowering
kernel.perf_event_max_sample_rate to 3250
[ 3335.619344] perf interrupt took too long (77281 > 71428), lowering
kernel.perf_event_max_sample_rate to 1750
[ 5318.728154] perf interrupt took too long (143697 > 125000), lowering
kernel.perf_event_max_sample_rate to 1000
[ 5718.600013] INFO: NMI handler (perf_event_nmi_handler) took too long to run:
1.213 msecs
[10577.262551] INFO: NMI handler (perf_event_nmi_handler) took too long to run:
1.234 msecs
[11242.180440] perf interrupt took too long (254126 > 250000), lowering
kernel.perf_event_max_sample_rate to 500
[13235.256007] INFO: NMI handler (perf_event_nmi_handler) took too long to run:
143.779 msecs
[13235.256007] perf interrupt took too long (1399797 > 500000), lowering
kernel.perf_event_max_sample_rate to 250
[14477.800068] INFO: NMI handler (perf_event_nmi_handler) took too long to run:
199.616 msecs
[15361.013057] INFO: NMI handler (perf_event_nmi_handler) took too long to run:
201.356 msecs
[21339.824010] INFO: NMI handler (perf_event_nmi_handler) took too long to run:
229.600 msecs
[22534.624019] INFO: NMI handler (perf_event_nmi_handler) took too long to run:
319.880 msecs
** Model information
sys_vendor: QEMU
product_name: Standard PC (i440FX + PIIX, 1996)
product_version: pc-i440fx-2.3
chassis_vendor: QEMU
chassis_version: pc-i440fx-2.3
bios_vendor: SeaBIOS
bios_version: rel-1.8.1-0-g4adadbd-20150316_085822-nilsson.home.kraxel.org
** Loaded modules:
xt_nat
xt_LOG
xt_limit
xt_conntrack
ipt_REJECT
iptable_filter
xt_REDIRECT
xt_tcpudp
xt_recent
iptable_nat
nf_conntrack_ipv4
nf_defrag_ipv4
nf_nat_ipv4
nf_nat
tun
nf_conntrack
ip_tables
x_tables
crc32_pclmul
ghash_clmulni_intel
ppdev
aesni_intel
aes_x86_64
lrw
gf128mul
glue_helper
ttm
ablk_helper
drm_kms_helper
cryptd
evdev
psmouse
serio_raw
pcspkr
drm
i2c_piix4
i2c_core
parport_pc
processor
parport
thermal_sys
button
fuse
autofs4
btrfs
xor
raid6_pq
sg
sd_mod
crc_t10dif
crct10dif_generic
sr_mod
cdrom
ata_generic
virtio_scsi
virtio_net
crct10dif_pclmul
crct10dif_common
crc32c_intel
ata_piix
floppy
libata
scsi_mod
virtio_pci
virtio_ring
virtio
** PCI devices:
not available
** USB devices:
not available
-- System Information:
Debian Release: 8.1
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 3.16.0-4-amd64 (SMP w/1 CPU core)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages linux-image-3.16.0-4-amd64 depends on:
ii debconf [debconf-2.0] 1.5.56
ii initramfs-tools [linux-initramfs-tool] 0.120
ii kmod 18-3
ii linux-base 3.5
Versions of packages linux-image-3.16.0-4-amd64 recommends:
ii firmware-linux-free 3.3
ii irqbalance 1.0.6-3
Versions of packages linux-image-3.16.0-4-amd64 suggests:
pn debian-kernel-handbook <none>
ii grub-pc 2.02~beta2-22
pn linux-doc-3.16 <none>
Versions of packages linux-image-3.16.0-4-amd64 is related to:
pn firmware-atheros <none>
pn firmware-bnx2 <none>
pn firmware-bnx2x <none>
pn firmware-brcm80211 <none>
pn firmware-intelwimax <none>
pn firmware-ipw2x00 <none>
pn firmware-ivtv <none>
pn firmware-iwlwifi <none>
pn firmware-libertas <none>
pn firmware-linux <none>
pn firmware-linux-nonfree <none>
pn firmware-myricom <none>
pn firmware-netxen <none>
pn firmware-qlogic <none>
pn firmware-ralink <none>
pn firmware-realtek <none>
pn xen-hypervisor <none>
-- debconf information:
linux-image-3.16.0-4-amd64/prerm/removing-running-kernel-3.16.0-4-amd64: true
linux-image-3.16.0-4-amd64/postinst/depmod-error-initrd-3.16.0-4-amd64: false
linux-image-3.16.0-4-amd64/postinst/mips-initrd-3.16.0-4-amd64:
--- End Message ---
--- Begin Message ---
Hi
This bug was filed for a very old kernel or the bug is old itself
without resolution.
If you can reproduce it with
- the current version in unstable/testing
- the latest kernel from backports
please reopen the bug, see https://www.debian.org/Bugs/server-control
for details.
Regards,
Salvatore
--- End Message ---
