realtime-lock-pain.txt

[Wed Feb  3 19:56:33 2021] ------------[ cut here ]------------
[Wed Feb  3 19:56:33 2021] WARNING: CPU: 0 PID: 6943 at /build/linux-MzwM29/linux-4.9.88/debian/build/source_rt/kernel/locking/rtmutex.c:2144 rt_mutex_trylock+0xbf/0xe0
[Wed Feb  3 19:56:33 2021] Modules linked in: c_fgraph_X_21068(O) joydev iTCO_wdt iTCO_vendor_support snd_hda_codec_generic evdev crct10dif_pclmul crc32_pclmul snd_hda_intel ghash_clmulni_intel snd_hda_codec virtio_rng serio_raw pcspkr snd_hda_core rng_core virtio_balloon snd_hwdep qxl virtio_console snd_pcm ttm snd_timer drm_kms_helper lpc_ich snd mfd_core soundcore drm shpchp button ip_tables x_tables autofs4 hid_generic usbhid hid ext4 crc16 jbd2 crc32c_generic fscrypto ecb mbcache crc32c_intel ahci virtio_blk virtio_net aesni_intel libahci aes_x86_64 xhci_pci glue_helper lrw libata gf128mul xhci_hcd ablk_helper i2c_i801 cryptd psmouse scsi_mod i2c_smbus usbcore usb_common virtio_pci virtio_ring virtio
[Wed Feb  3 19:56:33 2021] CPU: 0 PID: 6943 Comm: sshd Tainted: G           O    4.9.0-6-rt-amd64 #1 Debian 4.9.88-1
[Wed Feb  3 19:56:33 2021] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[Wed Feb  3 19:56:33 2021]  0000000000000000 ffffffffa6d43e9b 0000000000000000 0000000000000000
[Wed Feb  3 19:56:33 2021]  ffffffffa6a7c617 ffffffffc075e348 ffffffffc060c5a0 0000000000000000
[Wed Feb  3 19:56:33 2021]  0000000000000006 ffffffffc060c5a0 ffff8d6e2af5c948 ffffffffa703151f
[Wed Feb  3 19:56:33 2021] Call Trace:
[Wed Feb  3 19:56:33 2021]  <IRQ> 
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6d43e9b>] ? dump_stack+0x5c/0x81
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6a7c617>] ? __warn+0xd7/0xf0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa703151f>] ? rt_mutex_trylock+0xbf/0xe0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa7034050>] ? rt_read_trylock+0x30/0x70
[Wed Feb  3 19:56:33 2021]  [<ffffffffc05f6e4a>] ? stp_lock_probe+0x7a/0xb0 [c_fgraph_X_21068]
[Wed Feb  3 19:56:33 2021]  [<ffffffffc0605b1b>] ? probe_66+0x38b/0x470 [c_fgraph_X_21068]
[Wed Feb  3 19:56:33 2021]  [<ffffffffc0605df7>] ? handle_perf_probe.constprop.55+0x1f7/0x390 [c_fgraph_X_21068]
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6b80c42>] ? __perf_event_overflow+0x52/0xf0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6b80dd8>] ? perf_swevent_hrtimer+0xf8/0x160
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6ab30b9>] ? update_cfs_rq_load_avg+0x299/0x4c0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6ab676f>] ? update_curr+0xef/0x1b0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6ab8cfd>] ? enqueue_entity+0x30d/0x9e0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6ab9457>] ? enqueue_task_fair+0x87/0x980
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6aede62>] ? rcu_check_callbacks+0x242/0x9c0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6d4cefe>] ? timerqueue_del+0x1e/0x60
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6af6a8d>] ? __remove_hrtimer+0x3d/0xb0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6b80ce0>] ? __perf_event_overflow+0xf0/0xf0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6af7641>] ? __hrtimer_run_queues+0x161/0x4c0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6af7fd4>] ? hrtimer_interrupt+0xb4/0x280
[Wed Feb  3 19:56:33 2021]  [<ffffffffa7037adf>] ? smp_apic_timer_interrupt+0x3f/0x50
[Wed Feb  3 19:56:33 2021]  [<ffffffffa7035ff6>] ? apic_timer_interrupt+0x96/0xa0
[Wed Feb  3 19:56:33 2021]  <EOI> 
[Wed Feb  3 19:56:33 2021]  [<ffffffffc0604f2e>] ? __stp_call_mmap_callbacks_for_task+0x1ee/0x240 [c_fgraph_X_21068]
[Wed Feb  3 19:56:33 2021]  [<ffffffffa7033be1>] ? _raw_spin_unlock_irqrestore+0x11/0x60
[Wed Feb  3 19:56:33 2021]  [<ffffffffc05fbecc>] ? _stp_mem_debug_free+0xac/0x190 [c_fgraph_X_21068]
[Wed Feb  3 19:56:33 2021]  [<ffffffffc06081f6>] ? __stp_tf_quiesce_worker+0xa6/0xb0 [c_fgraph_X_21068]
[Wed Feb  3 19:56:33 2021]  [<ffffffffc05fc1f9>] ? __stp_tf_task_worker_fn+0xa9/0xb0 [c_fgraph_X_21068]
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6a9c6ff>] ? task_work_run+0x7f/0xa0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6a8e068>] ? get_signal+0x6a8/0x6d0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6a28656>] ? do_signal+0x36/0x6a0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6a5ca0f>] ? kvm_clock_read+0x1f/0x50
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6afe07c>] ? ktime_get_ts64+0x4c/0xf0
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6c2b14f>] ? poll_select_copy_remaining+0xdf/0x150
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6a037f9>] ? exit_to_usermode_loop+0xb9/0x100
[Wed Feb  3 19:56:33 2021]  [<ffffffffa6a03d00>] ? do_syscall_64+0xf0/0x110
[Wed Feb  3 19:56:33 2021]  [<ffffffffa703418e>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
[Wed Feb  3 19:56:33 2021] ---[ end trace 0000000000000002 ]---

warn.c

int __sched __rt_mutex_trylock(struct rt_mutex *lock)
{
#ifdef CONFIG_PREEMPT_RT_FULL
	if (WARN_ON_ONCE(in_irq() || in_nmi()))
#else
	if (WARN_ON_ONCE(in_irq() || in_nmi() || in_serving_softirq()))
#endif
		return 0;
	return rt_mutex_fasttrylock(lock, rt_mutex_slowtrylock);
}