[syzbot] WARNING: ODEBUG bug in kvm_xen_vcpu_set_attr

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: 032dcf09e2bf Merge tag 'gpio-fixes-for-v5.19-rc1' of git:/..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=122ece4ff00000
kernel config: https://syzkaller.appspot.com/x/.config?x=3096247591885bfa
dashboard link: https://syzkaller.appspot.com/bug?extid=e54f930ed78eb0f85281
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+e54f93...@syzkaller.appspotmail.com

------------[ cut here ]------------
ODEBUG: init active (active state 0) object type: hrtimer hint: xen_timer_callback+0x0/0xb0 arch/x86/kvm/xen.c:1086
WARNING: CPU: 1 PID: 26545 at lib/debugobjects.c:502 debug_print_object+0x16e/0x250 lib/debugobjects.c:502
Modules linked in:
CPU: 1 PID: 26545 Comm: syz-executor.4 Not tainted 5.18.0-syzkaller-13760-g032dcf09e2bf #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:debug_print_object+0x16e/0x250 lib/debugobjects.c:502
Code: ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 0f 85 af 00 00 00 48 8b 14 dd c0 5e 28 8a 4c 89 ee 48 c7 c7 a0 52 28 8a e8 74 08 32 05 <0f> 0b 83 05 35 b5 bb 09 01 48 83 c4 18 5b 5d 41 5c 41 5d 41 5e c3
RSP: 0018:ffffc900160df778 EFLAGS: 00010282
RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
RDX: ffff8880565a3b00 RSI: ffffffff8160ef28 RDI: fffff52002c1bee1
RBP: 0000000000000001 R08: 0000000000000005 R09: 0000000000000000
R10: 0000000080000000 R11: 0000000000000001 R12: ffffffff89cedc20
R13: ffffffff8a285820 R14: ffffffff816a8e30 R15: ffffffff911293e0
FS: 00007f720c5f2700(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000020402000 CR3: 000000004040a000 CR4: 00000000003526e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
__debug_object_init+0x524/0xd10 lib/debugobjects.c:590
debug_hrtimer_init kernel/time/hrtimer.c:414 [inline]
debug_init kernel/time/hrtimer.c:468 [inline]
hrtimer_init+0x23/0x2b0 kernel/time/hrtimer.c:1592
kvm_xen_init_timer arch/x86/kvm/xen.c:168 [inline]
kvm_xen_vcpu_set_attr+0x1ca/0x16c0 arch/x86/kvm/xen.c:716
kvm_arch_vcpu_ioctl+0x1bcd/0x39f0 arch/x86/kvm/x86.c:5695
kvm_vcpu_ioctl+0x973/0xf30 arch/x86/kvm/../../../virt/kvm/kvm_main.c:4100
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:870 [inline]
__se_sys_ioctl fs/ioctl.c:856 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f720b489109
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f720c5f2168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f720b59c030 RCX: 00007f720b489109
RDX: 0000000020003680 RSI: 000000004048aecb RDI: 000000000000000b
RBP: 00007f720b4e308d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007f720bacfb1f R14: 00007f720c5f2300 R15: 0000000000022000
</TASK>


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit: 70664fc10c0d Merge tag 'riscv-for-linus-5.19-rc8' of git:/..
git tree: upstream
console+strace: https://syzkaller.appspot.com/x/log.txt?x=11de4030080000
kernel config: https://syzkaller.appspot.com/x/.config?x=95c061eee05f8e15

dashboard link: https://syzkaller.appspot.com/bug?extid=e54f930ed78eb0f85281
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13e058ce080000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=151b2ec2080000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+e54f93...@syzkaller.appspotmail.com

------------[ cut here ]------------
ODEBUG: init active (active state 0) object type: hrtimer hint: xen_timer_callback+0x0/0xb0 arch/x86/kvm/xen.c:1086

WARNING: CPU: 0 PID: 3615 at lib/debugobjects.c:502 debug_print_object+0x16e/0x250 lib/debugobjects.c:502
Modules linked in:
CPU: 0 PID: 3615 Comm: syz-executor343 Not tainted 5.19.0-rc7-syzkaller-00190-g70664fc10c0d #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022

RIP: 0010:debug_print_object+0x16e/0x250 lib/debugobjects.c:502

Code: ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 0f 85 af 00 00 00 48 8b 14 dd 40 79 28 8a 4c 89 ee 48 c7 c7 20 6d 28 8a e8 7c 1e 32 05 <0f> 0b 83 05 b5 62 bb 09 01 48 83 c4 18 5b 5d 41 5c 41 5d 41 5e c3
RSP: 0018:ffffc9000306f778 EFLAGS: 00010282

RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000

RDX: ffff88801d968000 RSI: ffffffff8160d1a8 RDI: fffff5200060dee1

RBP: 0000000000000001 R08: 0000000000000005 R09: 0000000000000000

R10: 0000000080000000 R11: 0000000000000001 R12: ffffffff89cee540
R13: ffffffff8a2872a0 R14: ffffffff816a72e0 R15: ffffffff9114ced8
FS: 0000555555da53c0(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 0000000021000000 CR3: 000000001f980000 CR4: 00000000003526f0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
__debug_object_init+0x524/0xd10 lib/debugobjects.c:590
debug_hrtimer_init kernel/time/hrtimer.c:414 [inline]
debug_init kernel/time/hrtimer.c:468 [inline]
hrtimer_init+0x23/0x2b0 kernel/time/hrtimer.c:1592
kvm_xen_init_timer arch/x86/kvm/xen.c:168 [inline]
kvm_xen_vcpu_set_attr+0x1ca/0x16c0 arch/x86/kvm/xen.c:716

kvm_arch_vcpu_ioctl+0x1bb3/0x39d0 arch/x86/kvm/x86.c:5715
kvm_vcpu_ioctl+0x973/0xf30 arch/x86/kvm/../../../virt/kvm/kvm_main.c:4104

vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:870 [inline]
__se_sys_ioctl fs/ioctl.c:856 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80

entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7f859bb34cd9
Code: 28 c3 e8 2a 14 00 00 66 2e 0f 1f 84 00 00 00 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 c0 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007ffd7a0db668 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007ffd7a0db678 RCX: 00007f859bb34cd9

RDX: 0000000020003680 RSI: 000000004048aecb RDI: 000000000000000b

RBP: 00007ffd7a0db670 R08: 00007f859baf7b00 R09: 00007f859baf7b00
R10: 00007f859baf7b00 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
</TASK>

[syzbot]

syzbot has bisected this issue to:

commit 536395260582be7443b0b35b0bbb89ffe3947f62
Author: Joao Martins <joao.m....@oracle.com>
Date: Thu Mar 3 15:41:22 2022 +0000

KVM: x86/xen: handle PV timers oneshot mode

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=1607b2c2080000
start commit: 70664fc10c0d Merge tag 'riscv-for-linus-5.19-rc8' of git:/..
git tree: upstream
final oops: https://syzkaller.appspot.com/x/report.txt?x=1507b2c2080000
console output: https://syzkaller.appspot.com/x/log.txt?x=1107b2c2080000

kernel config: https://syzkaller.appspot.com/x/.config?x=95c061eee05f8e15
dashboard link: https://syzkaller.appspot.com/bug?extid=e54f930ed78eb0f85281

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13e058ce080000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=151b2ec2080000

Reported-by: syzbot+e54f93...@syzkaller.appspotmail.com
Fixes: 536395260582 ("KVM: x86/xen: handle PV timers oneshot mode")

For information about bisection process see: https://goo.gl/tpsmEJ#bisection

[Coleman Dietsch]

This crash appears to be happening when vcpu->arch.xen.timer is already set and kvm_xen_init_timer(vcpu) is called.

During testing with the syzbot reproducer code it seemed apparent that the else if statement in kvm_xen_vcpu_set_attr() was not being reached, which is where the kvm_xen_stop_timer(vcpu) call is located.

#syz test: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master

--- a/arch/x86/kvm/xen.c
+++ b/arch/x86/kvm/xen.c
@@ -707,6 +707,12 @@ int kvm_xen_vcpu_set_attr(struct kvm_vcpu *vcpu, struct kvm_xen_vcpu_attr *data)
         break;
 
     case KVM_XEN_VCPU_ATTR_TYPE_TIMER:
+        /* Stop current timer if it is enabled */
+        if (kvm_xen_timer_enabled(vcpu)) {
+            kvm_xen_stop_timer(vcpu);
+            vcpu->arch.xen.timer_virq = 0;
+        }
+
         if (data->u.timer.port) {
             if (data->u.timer.priority != KVM_IRQ_ROUTING_XEN_EVTCHN_PRIO_2LEVEL) {
                 r = -EINVAL;
@@ -720,9 +726,6 @@ int kvm_xen_vcpu_set_attr(struct kvm_vcpu *vcpu, struct kvm_xen_vcpu_attr *data)
                 kvm_xen_start_timer(vcpu, data->u.timer.expires_ns,
                             data->u.timer.expires_ns -
                             get_kvmclock_ns(vcpu->kvm));
-        } else if (kvm_xen_timer_enabled(vcpu)) {
-            kvm_xen_stop_timer(vcpu);
-            vcpu->arch.xen.timer_virq = 0;
         }
 
         r = 0;
--

On Saturday, July 23, 2022 at 8:43:08 PM UTC-5 syzbot wrote:

syzbot has bisected this issue to:

commit 536395260582be7443b0b35b0bbb89ffe3947f62
Author: Joao Martins <joao.m....@oracle.com>
Date: Thu Mar 3 15:41:22 2022 +0000

KVM: x86/xen: handle PV timers oneshot mode

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=1607b2c2080000
start commit: 70664fc10c0d Merge tag 'riscv-for-linus-5.19-rc8' of git:/..
git tree: upstream
final oops: https://syzkaller.appspot.com/x/report.txt?x=1507b2c2080000
console output: https://syzkaller.appspot.com/x/log.txt?x=1107b2c2080000
kernel config: https://syzkaller.appspot.com/x/.config?x=95c061eee05f8e15
dashboard link: https://syzkaller.appspot.com/bug?extid=e54f930ed78eb0f85281
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13e058ce080000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=151b2ec2080000

Reported-by: syzbot+e54f930ed78eb0f85281@syzkaller.appspotmail.com

[syzbot]

> This crash appears to be happening when vcpu->arch.xen.timer is already set
> and kvm_xen_init_timer(vcpu) is called.
>
> During testing with the syzbot reproducer code it seemed apparent that the
> else if statement in kvm_xen_vcpu_set_attr() was not being reached, which
> is where the kvm_xen_stop_timer(vcpu) call is located.
>
> #syz test:

I see the command but can't find the corresponding bug.
Please resend the email to syzbo...@syzkaller.appspotmail.com address
that is the sender of the bug report (also present in the Reported-by tag).

>> Reported-by: syzbot+e54f93...@syzkaller.appspotmail.com

>> Fixes: 536395260582 ("KVM: x86/xen: handle PV timers oneshot mode")
>>
>> For information about bisection process see:
>> https://goo.gl/tpsmEJ#bisection
>>
>

> --
> You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bug...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/8dbb4bf6-102b-4ac3-a4aa-b7e75a30ce94n%40googlegroups.com.

[syzbot]

Hello,

syzbot tried to test the proposed patch but the build/boot failed:

failed to apply patch:
checking file arch/x86/kvm/xen.c
patch: **** unexpected end of file in patch



Tested on:

commit: 6e7765cb Merge tag 'asm-generic-fixes-5.19-2' of git:/..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master

dashboard link: https://syzkaller.appspot.com/bug?extid=e54f930ed78eb0f85281
compiler:

patch: https://syzkaller.appspot.com/x/patch.diff?x=108cc4e2080000

[syzbot]

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger any issue:

Reported-and-tested-by: syzbot+e54f93...@syzkaller.appspotmail.com

Tested on:

commit: 6e7765cb Merge tag 'asm-generic-fixes-5.19-2' of git:/..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master

console output: https://syzkaller.appspot.com/x/log.txt?x=13526dce080000
kernel config: https://syzkaller.appspot.com/x/.config?x=26034e6fe0075dad
dashboard link: https://syzkaller.appspot.com/bug?extid=e54f930ed78eb0f85281

compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2

patch: https://syzkaller.appspot.com/x/patch.diff?x=11769422080000

Note: testing is done by a robot and is best-effort only.