Bug 2217459

Summary: [RHEL9.3.0] [ESXi] Found VMCI related Call Trace log when boot up with kernel-debug
Product: Red Hat Enterprise Linux 9 Reporter: ldu <ldu>
Component: kernelAssignee: Ani Sinha <anisinha>
kernel sub component: ESXi QA Contact: ldu <ldu>
Status: CLOSED ERRATA Docs Contact:
Severity: unspecified    
Priority: unspecified CC: andavis, anisinha, bdas, boyang, cavery, jsavanyo, ldu, vdasa, yacao, yanjin
Version: 9.3Keywords: Triaged
Target Milestone: rcFlags: vdasa: needinfo-
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: kernel-5.14.0-353.el9 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-11-07 08:48:33 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description ldu 2023-06-26 10:12:47 UTC
Description of problem:
Install a RHEL 9.3 as VM on ESXi host, then install kernel-debug package, reboot guest with kernel-debug, then found Call Trace log in dmesg.

Version-Release number of selected component (if applicable):
Host:ESXi 7.0 8.0 6.7
5.14.0-331.el9.x86_64+debug

How reproducible:
100%

Steps to Reproduce:
1.Install RHEL 9.3 as VM on ESXi host
2.Boot up guest and install kernel-debug package
3.Reboot guest to kernel-debug kernel and check the dmesg log.

Actual results:
Found Call Trace log in dmesg
The attachment file is full dmesg log.
[ 7430.339497] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
[ 7430.339500] Call Trace:
[ 7430.339502]  <IRQ>
[ 7430.339506]  ? schedule_preempt_disabled+0x1e/0x30
[ 7430.339512]  dump_stack_lvl+0x57/0x81
[ 7430.339520]  __might_resched.cold+0x222/0x26b
[ 7430.339534]  vmci_read_data+0x214/0x400 [vmw_vmci]
[ 7430.339553]  ? vmci_interrupt_bm+0x50/0x50 [vmw_vmci]
[ 7430.339566]  ? __lock_contended+0x980/0x980
[ 7430.339571]  ? do_raw_spin_trylock+0xb5/0x180
[ 7430.339582]  ? __wake_up_sync+0x30/0x30
[ 7430.339596]  vmci_dispatch_dgs+0x92/0x3a0 [vmw_vmci]
[ 7430.339617]  tasklet_action_common.constprop.0+0x252/0x2f0
[ 7430.339631]  __do_softirq+0x2d0/0x9a8
[ 7430.339650]  __irq_exit_rcu+0x185/0x230
[ 7430.339655]  irq_exit_rcu+0xa/0x30
[ 7430.339658]  common_interrupt+0xa9/0xc0
[ 7430.339664]  </IRQ>
[ 7430.339665]  <TASK>
[ 7430.339671]  asm_common_interrupt+0x22/0x40
[ 7430.339675] RIP: 0010:acpi_idle_do_entry+0x1a6/0x210
[ 7430.339679] Code: 48 89 ea 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 80 3c 02 00 75 5c 48 8b 45 00 a8 08 75 c3 66 90 0f 00 2d ac 27 9a 00 fb f4 <fa> eb b5 48 89 ef e8 df f8 ff ff 31 ff 5d c3 cc cc cc cc e8 02 ed
[ 7430.339683] RSP: 0018:ffffffffba207d50 EFLAGS: 00000246
[ 7430.339686] RAX: 0000000000004000 RBX: ffff8881032a7065 RCX: ffffffffb8c74d8c
[ 7430.339689] RDX: 1ffffffff7447980 RSI: 0000000000000008 RDI: ffffffffba23cc00
[ 7430.339691] RBP: ffffffffba23cc00 R08: 0000000000000000 R09: ffffffffba23cc07
[ 7430.339693] R10: fffffbfff7447980 R11: 0000000000000001 R12: 0000000000000001
[ 7430.339695] R13: ffffffffbab94bc0 R14: ffff8881032a7064 R15: ffff888002716004
[ 7430.339710]  ? acpi_idle_do_entry+0x17c/0x210
[ 7430.339723]  acpi_idle_enter+0x2aa/0x470
[ 7430.339735]  cpuidle_enter_state+0x15e/0x9b0
[ 7430.339750]  cpuidle_enter+0x4a/0xa0
[ 7430.339758]  cpuidle_idle_call+0x27d/0x3f0
[ 7430.339766]  ? arch_cpu_idle_exit+0x40/0x40
[ 7430.339776]  ? tsc_verify_tsc_adjust+0xa0/0x2e0
[ 7430.339790]  do_idle+0x127/0x200
[ 7430.339801]  cpu_startup_entry+0x19/0x20
[ 7430.339805]  rest_init+0x145/0x1f0
[ 7430.339812]  arch_call_rest_init+0xf/0x19
[ 7430.339819]  start_kernel+0x3e4/0x403
[ 7430.339827]  secondary_startup_64_no_verify+0xe5/0xeb
[ 7430.339856]  </TASK>


Expected results:
No Call Trace log in dmesg

Additional info:
Not reproduce on RHEL8.9

Comment 2 Ani Sinha 2023-06-26 11:04:33 UTC
Full call trace:

Jun 26 18:07:32 vm-197-175 kernel: BUG: sleeping function called from invalid context at drivers/misc/vmw_vmci/vmci_guest.c:145
Jun 26 18:07:32 vm-197-175 kernel: in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 820, name: vmtoolsd
Jun 26 18:07:32 vm-197-175 kernel: preempt_count: 101, expected: 0
Jun 26 18:07:32 vm-197-175 kernel: RCU nest depth: 0, expected: 0
Jun 26 18:07:32 vm-197-175 kernel: 1 lock held by vmtoolsd/820:
Jun 26 18:07:32 vm-197-175 kernel: #0: ffff88807e7e8a40 (sk_lock-AF_VSOCK){+.+.}-{0:0}, at: vsock_connect+0xff/0xa90 [vsock]
Jun 26 18:07:32 vm-197-175 kernel: Preemption disabled at:
Jun 26 18:07:32 vm-197-175 kernel: [<0000000000000000>] 0x0
Jun 26 18:07:32 vm-197-175 kernel: CPU: 1 PID: 820 Comm: vmtoolsd Tainted: G        W         -------  ---  5.14.0-330.el9.x86_64+debug #1
Jun 26 18:07:32 vm-197-175 kernel: Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
Jun 26 18:07:32 vm-197-175 kernel: Call Trace:
Jun 26 18:07:32 vm-197-175 kernel: <IRQ>
Jun 26 18:07:32 vm-197-175 kernel: dump_stack_lvl+0x57/0x81
Jun 26 18:07:32 vm-197-175 kernel: __might_resched.cold+0x222/0x26b
Jun 26 18:07:32 vm-197-175 kernel: vmci_read_data+0x214/0x400 [vmw_vmci]
Jun 26 18:07:32 vm-197-175 kernel: ? vmci_interrupt_bm+0x50/0x50 [vmw_vmci]
Jun 26 18:07:32 vm-197-175 kernel: ? mark_lock_irq+0xda0/0xda0
Jun 26 18:07:32 vm-197-175 kernel: ? __lock_contended+0x980/0x980
Jun 26 18:07:32 vm-197-175 kernel: ? mark_lock.part.0+0xca/0xa40
Jun 26 18:07:32 vm-197-175 kernel: ? __wake_up_sync+0x30/0x30
Jun 26 18:07:32 vm-197-175 kernel: vmci_dispatch_dgs+0x92/0x3a0 [vmw_vmci]
Jun 26 18:07:32 vm-197-175 kernel: tasklet_action_common.constprop.0+0x252/0x2f0
Jun 26 18:07:32 vm-197-175 kernel: __do_softirq+0x2d0/0x9a8
Jun 26 18:07:32 vm-197-175 kernel: __irq_exit_rcu+0x185/0x230
Jun 26 18:07:32 vm-197-175 kernel: irq_exit_rcu+0xa/0x30
Jun 26 18:07:32 vm-197-175 kernel: common_interrupt+0xa9/0xc0
Jun 26 18:07:32 vm-197-175 kernel: </IRQ>
Jun 26 18:07:32 vm-197-175 kernel: <TASK>
Jun 26 18:07:32 vm-197-175 kernel: asm_common_interrupt+0x22/0x40
Jun 26 18:07:32 vm-197-175 kernel: RIP: 0010:_raw_spin_unlock_irqrestore+0x3d/0x70
Jun 26 18:07:32 vm-197-175 kernel: Code: 74 24 10 e8 85 cc f2 fd 48 89 ef e8 fd 53 f3 fd 81 e3 00 02 00 00 75 29 9c 58 f6 c4 02 75 35 48 85 db 74 01 fb bf 01 00 00 00 <e8> be cd e3 fd 65 8b 05 a7 a1 1b 76 85 c0 74 0e 5b 5d c3 cc cc cc
Jun 26 18:07:32 vm-197-175 kernel: RSP: 0018:ffffc900018b7a58 EFLAGS: 00000206
Jun 26 18:07:32 vm-197-175 kernel: RAX: 0000000000000002 RBX: 0000000000000200 RCX: 1ffffffff1bc832a
Jun 26 18:07:32 vm-197-175 kernel: RDX: 0000000000000000 RSI: ffffffff8a4e1de0 RDI: 0000000000000001
Jun 26 18:07:32 vm-197-175 kernel: RBP: ffffffffc0c94720 R08: 0000000000000001 R09: ffffffff8dde6197
Jun 26 18:07:32 vm-197-175 kernel: R10: fffffbfff1bbcc32 R11: 0000000000000001 R12: 0000000000000000
Jun 26 18:07:32 vm-197-175 kernel: R13: 0000000000000286 R14: ffff88800d546208 R15: ffffffffffffffff
Jun 26 18:07:32 vm-197-175 kernel: vmci_send_datagram+0x7d/0xd0 [vmw_vmci]
Jun 26 18:07:32 vm-197-175 kernel: vmci_datagram_dispatch+0xf6/0x190 [vmw_vmci]
Jun 26 18:07:32 vm-197-175 kernel: ? dg_dispatch_as_host+0x800/0x800 [vmw_vmci]
Jun 26 18:07:32 vm-197-175 kernel: ? vmci_transport_packet_init+0x297/0x5d0 [vmw_vsock_vmci_transport]
Jun 26 18:07:32 vm-197-175 kernel: ? trace_kmalloc+0x3c/0x100
Jun 26 18:07:32 vm-197-175 kernel: ? kmem_cache_alloc_trace+0x221/0x430
Jun 26 18:07:32 vm-197-175 kernel: vmci_transport_send_control_pkt+0x18a/0x280 [vmw_vsock_vmci_transport]
Jun 26 18:07:32 vm-197-175 kernel: ? vmci_transport_send_reset.isra.0+0x60/0x60 [vmw_vsock_vmci_transport]
Jun 26 18:07:32 vm-197-175 kernel: ? vsock_accept+0xa50/0xa50 [vsock]
Jun 26 18:07:32 vm-197-175 kernel: ? vmci_transport_socket_init+0x295/0x350 [vmw_vsock_vmci_transport]
Jun 26 18:07:32 vm-197-175 kernel: ? 0xffffffffc10d2000
Jun 26 18:07:32 vm-197-175 kernel: vmci_transport_connect+0x54/0xf0 [vmw_vsock_vmci_transport]
Jun 26 18:07:32 vm-197-175 kernel: vsock_connect+0x6c9/0xa90 [vsock]
Jun 26 18:07:32 vm-197-175 kernel: ? do_raw_spin_trylock+0xb5/0x180
Jun 26 18:07:32 vm-197-175 kernel: ? __vsock_bind+0x770/0x770 [vsock]
Jun 26 18:07:32 vm-197-175 kernel: ? lockdep_hardirqs_on_prepare.part.0+0x18c/0x370
Jun 26 18:07:32 vm-197-175 kernel: ? prepare_to_wait_exclusive+0x2c0/0x2c0
Jun 26 18:07:32 vm-197-175 kernel: ? __local_bh_enable_ip+0xa5/0x120
Jun 26 18:07:32 vm-197-175 kernel: ? selinux_netlbl_socket_connect+0x2b/0x40
Jun 26 18:07:32 vm-197-175 kernel: __sys_connect+0x101/0x130
Jun 26 18:07:32 vm-197-175 kernel: ? __sys_connect_file+0x1a0/0x1a0
Jun 26 18:07:32 vm-197-175 kernel: ? lockdep_hardirqs_on_prepare.part.0+0x18c/0x370
Jun 26 18:07:32 vm-197-175 kernel: ? ktime_get_coarse_real_ts64+0x130/0x170
Jun 26 18:07:32 vm-197-175 kernel: ? lockdep_hardirqs_on+0x79/0x100
Jun 26 18:07:32 vm-197-175 kernel: ? ktime_get_coarse_real_ts64+0x130/0x170
Jun 26 18:07:32 vm-197-175 kernel: __x64_sys_connect+0x6e/0xb0
Jun 26 18:07:32 vm-197-175 kernel: do_syscall_64+0x59/0x90
Jun 26 18:07:32 vm-197-175 kernel: ? do_syscall_64+0x69/0x90
Jun 26 18:07:32 vm-197-175 kernel: ? lockdep_hardirqs_on+0x79/0x100
Jun 26 18:07:32 vm-197-175 kernel: ? do_syscall_64+0x69/0x90
Jun 26 18:07:32 vm-197-175 kernel: ? asm_exc_page_fault+0x22/0x30
Jun 26 18:07:32 vm-197-175 kernel: ? lockdep_hardirqs_on+0x79/0x100
Jun 26 18:07:32 vm-197-175 kernel: entry_SYSCALL_64_after_hwframe+0x63/0xcd
Jun 26 18:07:32 vm-197-175 kernel: RIP: 0033:0x7f120d14f617
Jun 26 18:07:32 vm-197-175 kernel: Code: 0a 00 f7 d8 64 89 02 b8 ff ff ff ff eb bc 0f 1f 44 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 2a 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 18 89 54 24 0c 48 89 34 24 89
Jun 26 18:07:32 vm-197-175 kernel: RSP: 002b:00007fffc26d8b88 EFLAGS: 00000246 ORIG_RAX: 000000000000002a
Jun 26 18:07:32 vm-197-175 kernel: RAX: ffffffffffffffda RBX: 00007f120d50c550 RCX: 00007f120d14f617
Jun 26 18:07:32 vm-197-175 kernel: RDX: 0000000000000010 RSI: 00007fffc26d8c20 RDI: 0000000000000007
Jun 26 18:07:32 vm-197-175 kernel: RBP: 00007fffc26d8c20 R08: 0000000000000003 R09: 0000556a94db4d70
Jun 26 18:07:32 vm-197-175 kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 0000556a94db5270
Jun 26 18:07:32 vm-197-175 kernel: R13: 0000000000000010 R14: 0000000000000007 R15: 00007fffc26d8c94
Jun 26 18:07:32 vm-197-175 kernel: </TASK>
Jun 26 18:07:32 vm-197-175 chronyd[835]: chronyd version 4.3 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +NTS +SECHASH +IPV6 +DEBUG)
Jun 26 18:07:32 vm-197-175 NetworkManager[811]: <info>  [1687774052.8450] NetworkManager (version 1.43.10-1.el9) is starting... (boot:d33c0f61-4e8c-43c3-a51b-5a38654cfd0a)
Jun 26 18:07:32 vm-197-175 NetworkManager[811]: <info>  [1687774052.8500] Read config: /etc/NetworkManager/NetworkManager.conf (run: 15-carrier-timeout.conf)
Jun 26 18:07:32 vm-197-175 chronyd[835]: Frequency 9.025 +/- 0.982 ppm read from /var/lib/chrony/drift
Jun 26 18:07:32 vm-197-175 chronyd[835]: Using right/UTC timezone to obtain leap second data
Jun 26 18:07:32 vm-197-175 chronyd[835]: Loaded seccomp filter (level 2)
Jun 26 18:07:32 vm-197-175 systemd[1]: Started NTP client/server.
Jun 26 18:07:32 vm-197-175 NetworkManager[811]: <info>  [1687774052.9595] manager[0x55ac30ce1080]: monitoring kernel firmware directory '/lib/firmware'.
Jun 26 18:08:06 vm-197-175 systemd[1]: Starting Hostname Service...
Jun 26 18:08:06 vm-197-175 kernel: ------------[ cut here ]------------
Jun 26 18:08:06 vm-197-175 kernel: do not call blocking ops when !TASK_RUNNING; state=1 set at [<0000000087e48273>] prepare_to_wait+0x7d/0x370
Jun 26 18:08:06 vm-197-175 kernel: WARNING: CPU: 1 PID: 820 at kernel/sched/core.c:10081 __might_sleep+0x113/0x160
Jun 26 18:08:06 vm-197-175 kernel: Modules linked in: vsock_loopback vmw_vsock_virtio_transport_common vmw_vsock_vmci_transport intel_rapl_msr vsock intel_rapl_common isst_if_mbox_msr isst_if_common nfit vmw_balloon libnvdimm rapl vmwgfx sunrpc pcspkr drm_ttm_helper ttm drm_kms_helper vmw_vmci syscopyarea sysfillrect sysimgblt i2c_piix4 fb_sys_fops joydev drm xfs libcrc32c sd_mod ata_generic t10_pi sg crct10dif_pclmul crc32_pclmul crc32c_intel ata_piix ahci libahci ghash_clmulni_intel libata vmxnet3 vmw_pvscsi serio_raw dm_mirror dm_region_hash dm_log dm_mod fuse
Jun 26 18:08:06 vm-197-175 kernel: CPU: 1 PID: 820 Comm: vmtoolsd Tainted: G        W         -------  ---  5.14.0-330.el9.x86_64+debug #1
Jun 26 18:08:06 vm-197-175 kernel: Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
Jun 26 18:08:06 vm-197-175 kernel: RIP: 0010:__might_sleep+0x113/0x160
Jun 26 18:08:06 vm-197-175 kernel: Code: f1 02 00 48 8d bb a8 31 00 00 48 89 fa 48 c1 ea 03 80 3c 02 00 75 34 48 8b 93 a8 31 00 00 48 c7 c7 80 bd 4c 8a e8 cd f1 f5 ff <0f> 0b e9 75 ff ff ff e8 41 f6 78 00 e9 26 ff ff ff 89 34 24 e8 44
Jun 26 18:08:06 vm-197-175 kernel: RSP: 0018:ffffc90000018dc0 EFLAGS: 00010286
Jun 26 18:08:06 vm-197-175 kernel: RAX: 0000000000000000 RBX: ffff88807c1b8000 RCX: 0000000000000000
Jun 26 18:08:06 vm-197-175 kernel: RDX: 0000000000000103 RSI: 0000000000000004 RDI: 0000000000000001
Jun 26 18:08:06 vm-197-175 kernel: RBP: ffffffffc0c84560 R08: 0000000000000001 R09: ffff888100defdab
Jun 26 18:08:06 vm-197-175 kernel: R10: ffffed10201bdfb5 R11: 0000000000000001 R12: 0000000000000091
Jun 26 18:08:06 vm-197-175 kernel: R13: 1ffff920000031bf R14: 0000000000011000 R15: ffff88807c709048
Jun 26 18:08:06 vm-197-175 kernel: FS:  00007f120ce70880(0000) GS:ffff888100c00000(0000) knlGS:0000000000000000
Jun 26 18:08:06 vm-197-175 kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun 26 18:08:06 vm-197-175 kernel: CR2: 000055d5df5cf040 CR3: 000000007ec98003 CR4: 00000000007706e0
Jun 26 18:08:06 vm-197-175 kernel: PKRU: 55555554
Jun 26 18:08:06 vm-197-175 kernel: Call Trace:
Jun 26 18:08:06 vm-197-175 kernel: <IRQ>
Jun 26 18:08:06 vm-197-175 kernel: ? vmci_read_data+0x203/0x400 [vmw_vmci]
Jun 26 18:08:06 vm-197-175 kernel: vmci_read_data+0x214/0x400 [vmw_vmci]
Jun 26 18:08:06 vm-197-175 kernel: ? vmci_interrupt_bm+0x50/0x50 [vmw_vmci]
Jun 26 18:08:06 vm-197-175 kernel: ? mark_lock_irq+0xda0/0xda0
Jun 26 18:08:06 vm-197-175 kernel: ? __lock_contended+0x980/0x980
Jun 26 18:08:06 vm-197-175 kernel: ? mark_lock.part.0+0xca/0xa40
Jun 26 18:08:06 vm-197-175 kernel: ? __wake_up_sync+0x30/0x30
Jun 26 18:08:06 vm-197-175 kernel: vmci_dispatch_dgs+0x92/0x3a0 [vmw_vmci]
Jun 26 18:08:06 vm-197-175 kernel: tasklet_action_common.constprop.0+0x252/0x2f0
Jun 26 18:08:06 vm-197-175 kernel: __do_softirq+0x2d0/0x9a8
Jun 26 18:08:06 vm-197-175 kernel: __irq_exit_rcu+0x185/0x230
Jun 26 18:08:06 vm-197-175 kernel: irq_exit_rcu+0xa/0x30
Jun 26 18:08:06 vm-197-175 kernel: common_interrupt+0xa9/0xc0
Jun 26 18:08:06 vm-197-175 kernel: </IRQ>
Jun 26 18:08:06 vm-197-175 kernel: <TASK>
Jun 26 18:08:06 vm-197-175 kernel: asm_common_interrupt+0x22/0x40
Jun 26 18:08:06 vm-197-175 kernel: RIP: 0010:_raw_spin_unlock_irqrestore+0x3d/0x70
Jun 26 18:08:06 vm-197-175 kernel: Code: 74 24 10 e8 85 cc f2 fd 48 89 ef e8 fd 53 f3 fd 81 e3 00 02 00 00 75 29 9c 58 f6 c4 02 75 35 48 85 db 74 01 fb bf 01 00 00 00 <e8> be cd e3 fd 65 8b 05 a7 a1 1b 76 85 c0 74 0e 5b 5d c3 cc cc cc
Jun 26 18:08:06 vm-197-175 kernel: RSP: 0018:ffffc900018b79e8 EFLAGS: 00000206
Jun 26 18:08:06 vm-197-175 kernel: RAX: 0000000000000002 RBX: 0000000000000200 RCX: 1ffffffff1bc832a
Jun 26 18:08:06 vm-197-175 kernel: RDX: 0000000000000000 RSI: ffffffff8a4e1de0 RDI: 0000000000000001
Jun 26 18:08:06 vm-197-175 kernel: RBP: ffff88807f640cc0 R08: 0000000000000001 R09: ffffffff8dde6197
Jun 26 18:08:06 vm-197-175 kernel: R10: fffffbfff1bbcc32 R11: 0000000000000001 R12: ffff88807c1b8000
Jun 26 18:08:06 vm-197-175 kernel: R13: ffffffffc10e2000 R14: ffff88807e7eb600 R15: ffffc900018b7b30
Jun 26 18:08:06 vm-197-175 kernel: vsock_connectible_wait_data+0x25c/0x530 [vsock]
Jun 26 18:08:06 vm-197-175 kernel: __vsock_stream_recvmsg+0x310/0x4b0 [vsock]
Jun 26 18:08:06 vm-197-175 kernel: ? sched_clock_cpu+0x15/0x1b0
Jun 26 18:08:06 vm-197-175 kernel: ? vsock_connectible_wait_data+0x530/0x530 [vsock]
Jun 26 18:08:06 vm-197-175 kernel: ? __lock_contended+0x8b0/0x980
Jun 26 18:08:06 vm-197-175 kernel: ? do_raw_spin_trylock+0xb5/0x180
Jun 26 18:08:06 vm-197-175 kernel: ? prepare_to_wait_exclusive+0x2c0/0x2c0
Jun 26 18:08:06 vm-197-175 kernel: ? lockdep_hardirqs_on_prepare.part.0+0x18c/0x370
Jun 26 18:08:06 vm-197-175 kernel: ? __local_bh_enable_ip+0xa5/0x120
Jun 26 18:08:06 vm-197-175 kernel: vsock_connectible_recvmsg+0x3ff/0x4f0 [vsock]
Jun 26 18:08:06 vm-197-175 kernel: ? __vsock_stream_recvmsg+0x4b0/0x4b0 [vsock]
Jun 26 18:08:06 vm-197-175 kernel: ? security_socket_recvmsg+0x53/0xa0
Jun 26 18:08:06 vm-197-175 kernel: __sys_recvfrom+0x15c/0x250
Jun 26 18:08:06 vm-197-175 kernel: ? __ia32_sys_send+0x100/0x100
Jun 26 18:08:06 vm-197-175 kernel: ? sched_clock_cpu+0x15/0x1b0
Jun 26 18:08:06 vm-197-175 kernel: ? lock_downgrade+0x130/0x130
Jun 26 18:08:06 vm-197-175 kernel: ? rcu_read_unlock+0x60/0x60
Jun 26 18:08:06 vm-197-175 kernel: ? ktime_get_coarse_real_ts64+0x130/0x170
Jun 26 18:08:06 vm-197-175 kernel: ? lockdep_hardirqs_on_prepare.part.0+0x18c/0x370
Jun 26 18:08:06 vm-197-175 kernel: ? ktime_get_coarse_real_ts64+0x130/0x170
Jun 26 18:08:06 vm-197-175 kernel: ? lockdep_hardirqs_on+0x79/0x100
Jun 26 18:08:06 vm-197-175 kernel: ? ktime_get_coarse_real_ts64+0x130/0x170
Jun 26 18:08:06 vm-197-175 kernel: __x64_sys_recvfrom+0xdc/0x1b0
Jun 26 18:08:06 vm-197-175 kernel: ? syscall_trace_enter.constprop.0+0x19c/0x280
Jun 26 18:08:06 vm-197-175 kernel: do_syscall_64+0x59/0x90
Jun 26 18:08:06 vm-197-175 kernel: ? asm_exc_page_fault+0x22/0x30
Jun 26 18:08:06 vm-197-175 kernel: ? lockdep_hardirqs_on+0x79/0x100
Jun 26 18:08:06 vm-197-175 kernel: entry_SYSCALL_64_after_hwframe+0x63/0xcd
Jun 26 18:08:06 vm-197-175 kernel: RIP: 0033:0x7f120d14f74e
Jun 26 18:08:06 vm-197-175 kernel: Code: 4c 24 1c e8 f4 c4 f4 ff 44 8b 54 24 1c 8b 3c 24 45 31 c9 41 89 c4 48 8b 54 24 10 48 8b 74 24 08 45 31 c0 b8 2d 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 32 44 89 e7 48 89 04 24 e8 3e c5 f4 ff 48 8b
Jun 26 18:08:06 vm-197-175 kernel: RSP: 002b:00007fffc26d8160 EFLAGS: 00000246 ORIG_RAX: 000000000000002d
Jun 26 18:08:06 vm-197-175 kernel: RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 00007f120d14f74e
Jun 26 18:08:06 vm-197-175 kernel: RDX: 0000000000000004 RSI: 00007fffc26d81e0 RDI: 0000000000000008
Jun 26 18:08:06 vm-197-175 kernel: RBP: 0000000000000008 R08: 0000000000000000 R09: 0000000000000000
Jun 26 18:08:06 vm-197-175 kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
Jun 26 18:08:06 vm-197-175 kernel: R13: 0000000000000004 R14: 00007fffc26d81e0 R15: 0000000000000008
Jun 26 18:08:06 vm-197-175 kernel: </TASK>
Jun 26 18:08:06 vm-197-175 kernel: irq event stamp: 89678
Jun 26 18:08:06 vm-197-175 kernel: hardirqs last  enabled at (89686): [<ffffffff87dc1d91>] console_trylock_spinning+0x201/0x240
Jun 26 18:08:06 vm-197-175 kernel: hardirqs last disabled at (89693): [<ffffffff87dc1d40>] console_trylock_spinning+0x1b0/0x240
Jun 26 18:08:06 vm-197-175 kernel: softirqs last  enabled at (88634): [<ffffffffc105e665>] vsock_connectible_recvmsg+0xa5/0x4f0 [vsock]
Jun 26 18:08:06 vm-197-175 kernel: softirqs last disabled at (88639): [<ffffffff87c2c105>] __irq_exit_rcu+0x185/0x230
Jun 26 18:08:06 vm-197-175 kernel: ---[ end trace 31de8806f0a8a9d3 ]---



Seems a bug in vmw_vmci driver.

Comment 4 ldu 2023-07-10 07:52:20 UTC
Hi YanJin,
Do you know any VMCI related dev could take look at this bug? 
Thanks very much!

Lili Du

Comment 5 Ani Sinha 2023-07-10 08:01:20 UTC
@vdasa We brought this up in our last meeting. Could you please add an update? Thanks.

Comment 6 vdasa 2023-07-10 18:34:01 UTC
@anisinha could you check if the following patch has
been applied?  If not, please apply that patch and check if you
still see the issue.

Thanks,
Vishnu

3daed63 ("VMCI: Use threaded irqs instead of tasklets")

Comment 7 Ani Sinha 2023-07-11 05:33:30 UTC
(In reply to vdasa from comment #6)
> @anisinha could you check if the following patch has
> been applied?  If not, please apply that patch and check if you
> still see the issue.
> 
> Thanks,
> Vishnu
> 
> 3daed63 ("VMCI: Use threaded irqs instead of tasklets")

Thanks! This patch was missing. I have sent an MR:
https://gitlab.com/redhat/centos-stream/src/kernel/centos-stream-9/-/merge_requests/2792

Comment 22 errata-xmlrpc 2023-11-07 08:48:33 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Important: kernel security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2023:6583