[ktap] "BUG: unable to handle kernel paging request" after ktap script to trace SyS_write

  • From: Azat Khuzhin <a3at.mail@xxxxxxxxx>
  • To: ktap@xxxxxxxxxxxxx
  • Date: Sat, 19 Oct 2013 13:06:44 +0400

Hi all,

I used next script, and after a few seconds of working, I have all ssh
sessions killed.
#! /usr/bin/env ktap
trace probe:SyS_write {
        print(backtrace(0, 100))
}

However, I can login after this, and have next messages in dmesg:
[  951.257429] CPU: 1 PID: 3368 Comm: bash Tainted: G      D    O
3.12.0-rc5+ #38
[  951.257429] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS
VirtualBox 12/01/2006
[  951.257429] task: ffff88007ba6d850 ti: ffff88007cbec000 task.ti:
ffff88007cbec000
[  951.257429] RIP: 0010:[<ffffffff622272b5>]  [<ffffffff622272b5>]
0xffffffff622272b4
[  951.257429] RSP: 0018:ffff88007cbedf78  EFLAGS: 00010293
[  951.257429] RAX: 0000000000000001 RBX: 000000000158bc48 RCX: 0000000000000000
[  951.257429] RDX: 0000000000000032 RSI: 000000000158bc48 RDI: 000000000000000a
[  951.257429] RBP: 0000000000000000 R08: 0000000000000032 R09: 746b2f676f6c2f72
[  951.257429] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[  951.257429] R13: 00000000015a1e28 R14: 00000000015d9d78 R15: 0000000000000032
[  951.257429] FS:  00007f6637b05700(0000) GS:ffff88007fd00000(0000)
knlGS:0000000000000000
[  951.257429] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  951.257429] CR2: ffffffff622272b5 CR3: 000000007cb8e000 CR4: 00000000000006e0
[  951.257429] Stack:
[  951.257429]  0000000000000000 ffffffff813b2962 0000000000000246
0000000000000000
[  951.257429]  746b2f676f6c2f72 0000000000000032 0000000000000001
0000000000000000
[  951.257429]  0000000000000032 000000000158bc48 000000000000000a
0000000000000001
[  951.257429] Call Trace:
[  951.257429]  [<ffffffff813b2962>] ? system_call_fastpath+0x16/0x1b
[  951.257429] Code:  Bad RIP value.
[  951.257429] RIP  [<ffffffff622272b5>] 0xffffffff622272b4
[  951.257429]  RSP <ffff88007cbedf78>
[  951.257429] CR2: ffffffff622272b5
[  951.257429] ---[ end trace 9787bc9112dbc81a ]---
[ 1002.927472] BUG: unable to handle kernel paging request at ffffffff624b4dea
[ 1002.928067] IP: [<ffffffff624b4dea>] 0xffffffff624b4de9
[ 1002.928094] PGD 160c067 PUD 0
[ 1002.928094] Oops: 0010 [#10] PREEMPT SMP
[ 1002.928094] Modules linked in: ktapvm(O) vboxvideo(O) drm vboxsf(O)
nfsd auth_rpcgss oid_registry nfs_acl nfs lockd fscache sunrpc loop
fuse joydev hid_generic usbhid hid vboxguest(O) snd_pcm snd_page_alloc
snd_timer psmouse serio_raw processor microcode snd soundcore pc
spkr evdev parport_pc ohci_pci parport ohci_hcd thermal_sys ehci_hcd
ac button usbcore usb_common i2c_piix4 i2c_core ext4 crc16 jbd2
mbcache sd_mod sg crc_t10dif crct10dif_common sr_mod cdrom ata_generic
ahci libahci ata_piix libata scsi_mod e1000
[ 1002.928094] CPU: 0 PID: 3768 Comm: cp Tainted: G      D    O 3.12.0-rc5+ #38
[ 1002.928094] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS
VirtualBox 12/01/2006
[ 1002.928094] task: ffff88007aa3d790 ti: ffff88007a00a000 task.ti:
ffff88007a00a000
[ 1002.928094] RIP: 0010:[<ffffffff624b4dea>]  [<ffffffff624b4dea>]
0xffffffff624b4de9
[ 1002.928094] RSP: 0018:ffff88007a00be70  EFLAGS: 00010246
[ 1002.928094] RAX: 0000000000018000 RBX: ffff8800377eda20 RCX: 0000000003731000
[ 1002.928094] RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000001
[ 1002.928094] RBP: ffff88007a00be70 R08: 0000000000000000 R09: 00007fffaca4d82f
[ 1002.928094] R10: 00007fffaca4ca00 R11: 0000000000000246 R12: 0000000000000001
[ 1002.928094] R13: 0000000000000020 R14: 0000000000000001 R15: 0000000000010000
[ 1002.928094] FS:  00007f3e012aa800(0000) GS:ffff88007fc00000(0000)
knlGS:0000000000000000
[ 1002.928094] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 1002.928094] CR2: ffffffff624b4dea CR3: 000000007cabe000 CR4: 00000000000006f0
[ 1002.928094] Stack:
[ 1002.928094]  ffff88007a00bea0 ffffffff811feb77 ffff8800377ed800
0000000000000001
[ 1002.928094]  ffff88007a00bf01 0000000000000220 ffff88007a00bf00
ffffffff8112380d
[ 1002.928094]  ffff88007a28b9c0 0000000000000002 0000000000000001
ffff88007a00bee8
[ 1002.928094] Call Trace:
[ 1002.928094]  [<ffffffff811feb77>] __percpu_counter_add+0x1e/0x90
[ 1002.928094]  [<ffffffff8112380d>] __sb_start_write+0xb8/0xec
[ 1002.928094]  [<ffffffff81191d0d>] ? security_file_permission+0x29/0x2e
[ 1002.928094]  [<ffffffff81121522>] file_start_write+0x27/0x29
[ 1002.928094]  [<ffffffff81121b2e>] vfs_write+0x91/0x113
[ 1002.928094]  [<ffffffff8112219b>] SyS_write+0x41/0x74
[ 1002.928094]  [<ffffffff813b2962>] system_call_fastpath+0x16/0x1b
[ 1002.928094] Code:  Bad RIP value.
[ 1002.928094] RIP  [<ffffffff624b4dea>] 0xffffffff624b4de9
[ 1002.928094]  RSP <ffff88007a00be70>
[ 1002.928094] CR2: ffffffff624b4dea
[ 1002.928094] ---[ end trace 9787bc9112dbc81b ]---
[ 1012.897743] BUG: unable to handle kernel paging request at ffffffff622272b5

And other stuff like this
It's unikely that kernel have this, after unloading killing ktap and
unloading ktapvm, all back to normal.

Anything I can help to investigate this?

Tested on:
linux 3.12.0-rc5+ d6099aeb4a9aad5e7ab1c72eb119ebd52dee0d52 ("Merge
branch 'fixes' of git://git.linaro.org/people/rmk/linux-arm")
ktap 27c59c75fa265c695dc3d38b15bc49c576a24251 ("make kp_init_state a
little faster")

-- 
Respectfully
Azat Khuzhin

Other related posts: