search

dtrace4linux / linux

dtrace for linux - kernel driver and userland tools
http://crtags.blogspot.com
1.17k stars 226 forks source link

Kernel oops and 100% CPU usage on fbt:isofs:: probes #40

Open OmegaPhil opened 12 years ago

OmegaPhil commented 12 years ago

dtrace: commit d663d2dde5c56f79494306b50411d6a2e740e0e1, Sat Aug 18 16:24:10 2012 +0100 uname -a: Linux debian-testing-vm 3.2.0-3-amd64 #1 SMP Mon Jul 23 02:45:17 UTC 2012 x86_64 GNU/Linux

I am currently trying out dtrace in my Debian virtual machine (Debian Wheezy/Testing) via Virtualbox in order to probe anything that goes on in the isofs kernel module (trying to find out more about a hang).

After loading the module (sudo modprobe -v isofs) I run the following trivial script (my first):

#!/usr/sbin/dtrace -s

/* Intercepting all isofs function entries and exits */
fbt:isofs::
{
        trace("worked!");
        exit(0);
        /*printf("%s %s", probefunc, probename);*/
}

Originally I had the normal printf line, but thats commented out to test this in general. When the above script is ran, the following kernel oops happens:

Aug 19 19:44:36 debian-testing-vm kernel: [  146.857394] dtracedrv: module license 'CDDL' taints kernel.
Aug 19 19:44:36 debian-testing-vm kernel: [  146.857402] Disabling lock debugging due to kernel taint
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883607] Pid: 3198, comm: insmod Tainted: P           O 3.2.0-3-amd64 #1
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883614] Call Trace:
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883689]  [<ffffffffa052e001>] ? mutex_enter_common+0x27/0xcb [dtracedrv]
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883758]  [<ffffffffa0524807>] ? par_alloc+0x1f/0xc6 [dtracedrv]
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883798]  [<ffffffffa052b473>] ? fbt_provide_module+0x34/0x23e [dtracedrv]
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883808]  [<ffffffff8124d0e2>] ? device_create_vargs+0x86/0xbe
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883816]  [<ffffffff81036457>] ? should_resched+0x5/0x23
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883825]  [<ffffffff813499cf>] ? _cond_resched+0x7/0x1c
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883830]  [<ffffffff81036457>] ? should_resched+0x5/0x23
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883836]  [<ffffffff813499cf>] ? _cond_resched+0x7/0x1c
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883842]  [<ffffffff8134a1b0>] ? mutex_lock+0xd/0x2d
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883883]  [<ffffffffa050c86e>] ? dtrace_module_loaded+0x92/0x10d [dtracedrv]
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883891]  [<ffffffff8134dcd6>] ? notifier_call_chain+0x2e/0x5b
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883897]  [<ffffffff81036457>] ? should_resched+0x5/0x23
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883904]  [<ffffffff81063261>] ? __blocking_notifier_call_chain+0x48/0x5e
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883912]  [<ffffffff81074f6e>] ? sys_init_module+0x1b6/0x25b
Aug 19 19:44:36 debian-testing-vm kernel: [  146.883919]  [<ffffffff8134fc92>] ? system_call_fastpath+0x16/0x1b
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880448] BUG: unable to handle kernel paging request at ffffffffa0182086
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880453] IP: [<ffffffffa052b91a>] fbt_enable+0x5b/0x6a [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880464] PGD 1607067 PUD 160b063 PMD 3745b067 PTE 0
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880468] Oops: 0002 [#1] SMP 
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880470] CPU 0 
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880471] Modules linked in: isofs dtracedrv(P) vboxsf(O) pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) mperf cpufreq_stats cpufreq_conservative cpufreq_userspace cpufreq_powers
ave ppdev lp vboxvideo(O) drm rfcomm bnep bluetooth rfkill binfmt_misc fuse vhba(O) loop joydev i2c_piix4 snd_intel8x0 snd_ac97_codec snd_pcm snd_page_alloc snd_seq snd_seq_device snd_timer snd soundcore i2c_core ac97_bus parport_pc psmo
use ac serio_raw power_supply parport button processor evdev thermal_sys pcspkr vboxguest(O) ext4 crc16 jbd2 mbcache usbhid hid sd_mod crc_t10dif sr_mod cdrom ata_generic ata_piix ahci libahci ohci_hcd ehci_hcd e1000 libata usbcore scsi_
mod usb_common [last unloaded: scsi_wait_scan]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880507] 
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880509] Pid: 3225, comm: isofs_tracing.d Tainted: P           O 3.2.0-3-amd64 #1 innotek GmbH VirtualBox
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880512] RIP: 0010:[<ffffffffa052b91a>]  [<ffffffffa052b91a>] fbt_enable+0x5b/0x6a [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880520] RSP: 0018:ffff88003c965898  EFLAGS: 00010202
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880522] RAX: ffffffffa0182086 RBX: ffff88001e0c97c0 RCX: 0000000000000002
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880524] RDX: 7fffffffffffffcc RSI: ffff88003c965848 RDI: 000000003745b067
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880525] RBP: ffff88001e0c9740 R08: ffff880000000c18 R09: ffff88000160b800
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880526] R10: ffff88001e118ff8 R11: 0000000000000000 R12: ffff88003744ffc0
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880528] R13: 0000000000000000 R14: ffff88001e091600 R15: ffffffffa05194e1
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880536] FS:  00007fd4d9c4b700(0000) GS:ffff88003fc00000(0000) knlGS:0000000000000000
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880538] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880539] CR2: ffffffffa0182086 CR3: 000000001e118000 CR4: 00000000000006f0
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880543] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880545] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880546] Process isofs_tracing.d (pid: 3225, threadinfo ffff88003c964000, task ffff88003cede180)
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880548] Stack:
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880549]  ffff88001bfffd40 ffffffffa051b02d ffff88001e018200 0000000000000007
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880552]  ffff880000000006 ffff88001e0e66c0 ffff88001e0182c0 ffffffffa050c0da
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880555]  0000000000000006 ffff88003c9659f0 0000000000000007 ffff8800265bc300
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880557] Call Trace:
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880564]  [<ffffffffa051b02d>] ? dtrace_ecb_create_enable+0x1b4c/0x1be0 [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880574]  [<ffffffffa050c0da>] ? dtrace_match_probe+0x8c/0xa6 [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880579]  [<ffffffffa05194e1>] ? dtrace_ecb_destroy+0x555/0x555 [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880585]  [<ffffffffa050c2ec>] ? dtrace_match+0x1f8/0x226 [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880590]  [<ffffffff810eb6e5>] ? __kmalloc+0x100/0x112
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880596]  [<ffffffffa052456b>] ? kmem_zalloc+0x2e/0x54 [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880602]  [<ffffffffa051b231>] ? dtrace_probe_enable+0x170/0x177 [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880608]  [<ffffffffa050e34f>] ? dtrace_strcmp+0x1b/0x1b [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880613]  [<ffffffffa050e34f>] ? dtrace_strcmp+0x1b/0x1b [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880618]  [<ffffffffa0508f03>] ? dtrace_match_glob+0x199/0x199 [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880623]  [<ffffffffa0508f03>] ? dtrace_match_glob+0x199/0x199 [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880628]  [<ffffffffa051b372>] ? dtrace_enabling_match+0x13a/0x1ca [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880634]  [<ffffffffa0520fe5>] ? dtrace_ioctl+0xc3e/0x217a [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880637]  [<ffffffff810cd779>] ? pte_offset_kernel+0x16/0x35
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880644]  [<ffffffff810c926a>] ? zone_page_state_add+0x14/0x23
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880647]  [<ffffffff810c9ec0>] ? __inc_zone_state+0x41/0x49
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880650]  [<ffffffff810ca0dd>] ? zone_statistics+0x41/0x74
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880653]  [<ffffffff810ba446>] ? get_page_from_freelist+0x57a/0x665
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880656]  [<ffffffff810bad51>] ? __alloc_pages_nodemask+0x6bf/0x726
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880659]  [<ffffffff810b3c44>] ? find_get_page+0x40/0x63
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880661]  [<ffffffff81036457>] ? should_resched+0x5/0x23
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880665]  [<ffffffff813499cf>] ? _cond_resched+0x7/0x1c
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880668]  [<ffffffff810b5aa8>] ? filemap_fault+0x1e6/0x33e
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880671]  [<ffffffff810f5ef5>] ? lookup_page_cgroup+0x2d/0x42
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880673]  [<ffffffff810f18d1>] ? mem_cgroup_update_page_stat+0x17/0xd4
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880676]  [<ffffffff810cdecd>] ? __do_fault+0x371/0x3ac
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880678]  [<ffffffff810d019f>] ? handle_pte_fault+0x298/0x79f
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880680]  [<ffffffff810cd779>] ? pte_offset_kernel+0x16/0x35
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880687]  [<ffffffffa0523c2e>] ? dtracedrv_ioctl.isra.3+0x3c/0x4d [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880693]  [<ffffffffa0523c4f>] ? dtracedrv_unlocked_ioctl+0x6/0xa [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880697]  [<ffffffff81106911>] ? do_vfs_ioctl+0x459/0x49a
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880699]  [<ffffffff81036457>] ? should_resched+0x5/0x23
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880702]  [<ffffffff810d3612>] ? remove_vma+0x64/0x6b
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880704]  [<ffffffff810d47c7>] ? do_munmap+0x2da/0x2f3
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880706]  [<ffffffff8110699d>] ? sys_ioctl+0x4b/0x72
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880710]  [<ffffffff8134fc92>] ? system_call_fastpath+0x16/0x1b
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880714] Code: 54 a0 48 8b 73 08 31 c0 e8 ff 92 00 00 48 8b 7b 08 ba 01 00 00 00 be 01 00 00 00 e8 8e 8e ff ff 85 c0 74 09 48 8b 43 08 8a 53 12 <88> 10 48 8b 5b 48 48 85 db 75 b0 31 c0 5b c3 41 56 41 89 d6 41 
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880737] RIP  [<ffffffffa052b91a>] fbt_enable+0x5b/0x6a [dtracedrv]
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880744]  RSP <ffff88003c965898>
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880745] CR2: ffffffffa0182086
Aug 19 19:44:56 debian-testing-vm kernel: [  166.880747] ---[ end trace b484dd282d33d09e ]---

Something (no process name) then uses 100% kernel mode time on one CPU, and dtrace ignores SIGINT - time to reboot.

dtrace4linux commented 12 years ago

Hello OmegaPhil

interesting. Are you having success for things which have not been modprobe'd after the dtrace module?

On 19 August 2012 20:14, OmegaPhil notifications@github.com wrote:

dtrace: commit d663d2dhttps://github.com/dtrace4linux/linux/commit/d663d2dde5c56f79494306b50411d6a2e740e0e1, Sat Aug 18 16:24:10 2012 +0100 uname -a: Linux debian-testing-vm 3.2.0-3-amd64 #1https://github.com/dtrace4linux/linux/issues/1SMP Mon Jul 23 02:45:17 UTC 2012 x86_64 GNU/Linux

I am currently trying out dtrace in my Debian virtual machine via Virtualbox in order to probe anything that goes on in the isofs kernel module (trying to find out more about a hang).

After loading the module (sudo modprobe -v isofs) I run the following trivial script (my first):

!/usr/sbin/dtrace -s

/* Intercepting all isofs function entries and exits _/ fbt:isofs:: { trace("worked!"); exit(0); /_printf("%s %s", probefunc, probename);*/ }

Originally I had the normal printf line, but thats commented out to test this in general. When the above script is ran, the following kernel oops happens:

Aug 19 19:44:36 debian-testing-vm kernel: [ 146.857394] dtracedrv: module license 'CDDL' taints kernel. Aug 19 19:44:36 debian-testing-vm kernel: [ 146.857402] Disabling lock debugging due to kernel taint Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883607] Pid: 3198, comm: insmod Tainted: P O 3.2.0-3-amd64 #1 Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883614] Call Trace: Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883689] [] ? mutex_enter_common+0x27/0xcb [dtracedrv] Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883758] [] ? par_alloc+0x1f/0xc6 [dtracedrv] Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883798] [] ? fbt_provide_module+0x34/0x23e [dtracedrv] Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883808] [] ? device_create_vargs+0x86/0xbe Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883816] [] ? should_resched+0x5/0x23 Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883825] [] ? _cond_resched+0x7/0x1c Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883830] [] ? should_resched+0x5/0x23 Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883836] [] ? _cond_resched+0x7/0x1c Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883842] [] ? mutex_lock+0xd/0x2d Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883883] [] ? dtrace_module_loaded+0x92/0x10d [dtracedrv] Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883891] [] ? notifier_call_chain+0x2e/0x5b Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883897] [] ? should_resched+0x5/0x23 Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883904] [] ? blocking_notifier_call_chain+0x48/0x5e Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883912] [] ? sys_init_module+0x1b6/0x25b Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883919] [] ? system_call_fastpath+0x16/0x1b Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880448] BUG: unable to handle kernel paging request at ffffffffa0182086 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880453] IP: [] fbt_enable+0x5b/0x6a [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880464] PGD 1607067 PUD 160b063 PMD 3745b067 PTE 0 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880468] Oops: 0002 [#1] SMP Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880470] CPU 0 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880471] Modules linked in: isofs dtracedrv(P) vboxsf(O) pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) mperf cpufreq_stats cpufreq_conservative cpufreq_userspace cpufreq_powers ave ppdev lp vboxvideo(O) drm rfcomm bnep bluetooth rfkill binfmt_misc fuse vhba(O) loop joydev i2c_piix4 snd_intel8x0 snd_ac97_codec snd_pcm snd_page_alloc snd_seq snd_seq_device snd_timer snd soundcore i2c_core ac97_bus parport_pc psmo use ac serio_raw power_supply parport button processor evdev thermal_sys pcspkr vboxguest(O) ext4 crc16 jbd2 mbcache usbhid hid sd_mod crc_t10dif sr_mod cdrom ata_generic ata_piix ahci libahci ohci_hcd ehcihcd e1000 libata usbcore scsi mod usb_common [last unloaded: scsi_wait_scan] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880507] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880509] Pid: 3225, comm: isofs_tracing.d Tainted: P O 3.2.0-3-amd64 #1 innotek GmbH VirtualBox Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880512] RIP: 0010:[] [] fbt_enable+0x5b/0x6a [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880520] RSP: 0018:ffff88003c965898 EFLAGS: 00010202 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880522] RAX: ffffffffa0182086 RBX: ffff88001e0c97c0 RCX: 0000000000000002 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880524] RDX: 7fffffffffffffcc RSI: ffff88003c965848 RDI: 000000003745b067 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880525] RBP: ffff88001e0c9740 R08: ffff880000000c18 R09: ffff88000160b800 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880526] R10: ffff88001e118ff8 R11: 0000000000000000 R12: ffff88003744ffc0 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880528] R13: 0000000000000000 R14: ffff88001e091600 R15: ffffffffa05194e1 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880536] FS: 00007fd4d9c4b700(0000) GS:ffff88003fc00000(0000) knlGS:0000000000000000 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880538] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880539] CR2: ffffffffa0182086 CR3: 000000001e118000 CR4: 00000000000006f0 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880543] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880545] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880546] Process isofs_tracing.d (pid: 3225, threadinfo ffff88003c964000, task ffff88003cede180) Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880548] Stack: Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880549] ffff88001bfffd40 ffffffffa051b02d ffff88001e018200 0000000000000007 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880552] ffff880000000006 ffff88001e0e66c0 ffff88001e0182c0 ffffffffa050c0da Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880555] 0000000000000006 ffff88003c9659f0 0000000000000007 ffff8800265bc300 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880557] Call Trace: Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880564] [] ? dtrace_ecb_create_enable+0x1b4c/0x1be0 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880574] [] ? dtrace_match_probe+0x8c/0xa6 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880579] [] ? dtrace_ecb_destroy+0x555/0x555 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880585] [] ? dtrace_match+0x1f8/0x226 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880590] [] ? __kmalloc+0x100/0x112 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880596] [] ? kmem_zalloc+0x2e/0x54 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880602] [] ? dtrace_probe_enable+0x170/0x177 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880608] [] ? dtrace_strcmp+0x1b/0x1b [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880613] [] ? dtrace_strcmp+0x1b/0x1b [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880618] [] ? dtrace_match_glob+0x199/0x199 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880623] [] ? dtrace_match_glob+0x199/0x199 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880628] [] ? dtrace_enabling_match+0x13a/0x1ca [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880634] [] ? dtrace_ioctl+0xc3e/0x217a [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880637] [] ? pte_offset_kernel+0x16/0x35 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880644] [] ? zone_page_state_add+0x14/0x23 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880647] [] ? inc_zone_state+0x41/0x49 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880650] [] ? zone_statistics+0x41/0x74 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880653] [] ? get_page_from_freelist+0x57a/0x665 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880656] [] ? alloc_pages_nodemask+0x6bf/0x726 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880659] [] ? find_get_page+0x40/0x63 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880661] [] ? should_resched+0x5/0x23 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880665] [] ? _cond_resched+0x7/0x1c Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880668] [] ? filemap_fault+0x1e6/0x33e Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880671] [] ? lookup_page_cgroup+0x2d/0x42 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880673] [] ? mem_cgroup_update_page_stat+0x17/0xd4 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880676] [] ? do_fault+0x371/0x3ac Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880678] [] ? handle_pte_fault+0x298/0x79f Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880680] [] ? pte_offset_kernel+0x16/0x35 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880687] [] ? dtracedrv_ioctl.isra.3+0x3c/0x4d [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880693] [] ? dtracedrv_unlocked_ioctl+0x6/0xa [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880697] [] ? do_vfs_ioctl+0x459/0x49a Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880699] [] ? should_resched+0x5/0x23 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880702] [] ? remove_vma+0x64/0x6b Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880704] [] ? do_munmap+0x2da/0x2f3 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880706] [] ? sys_ioctl+0x4b/0x72 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880710] [] ? system_call_fastpath+0x16/0x1b Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880714] Code: 54 a0 48 8b 73 08 31 c0 e8 ff 92 00 00 48 8b 7b 08 ba 01 00 00 00 be 01 00 00 00 e8 8e 8e ff ff 85 c0 74 09 48 8b 43 08 8a 53 12 <88> 10 48 8b 5b 48 48 85 db 75 b0 31 c0 5b c3 41 56 41 89 d6 41 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880737] RIP [] fbt_enable+0x5b/0x6a [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880744] RSP Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880745] CR2: ffffffffa0182086 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880747] ---[ end trace b484dd282d33d09e ]---

Something (no process name) then uses 100% kernel mode time on one CPU, and dtrace ignores SIGINT - time to reboot.

— Reply to this email directly or view it on GitHubhttps://github.com/dtrace4linux/linux/issues/40.

dtrace4linux commented 12 years ago

I just reproduced on deb6-64 - worked fine on Ubuntu....off to debug.

On 19 August 2012 20:22, Paul Fox paul.d.fox@gmail.com wrote:

Hello OmegaPhil

interesting. Are you having success for things which have not been modprobe'd after the dtrace module?

On 19 August 2012 20:14, OmegaPhil notifications@github.com wrote:

dtrace: commit d663d2dhttps://github.com/dtrace4linux/linux/commit/d663d2dde5c56f79494306b50411d6a2e740e0e1, Sat Aug 18 16:24:10 2012 +0100 uname -a: Linux debian-testing-vm 3.2.0-3-amd64 #1https://github.com/dtrace4linux/linux/issues/1SMP Mon Jul 23 02:45:17 UTC 2012 x86_64 GNU/Linux

I am currently trying out dtrace in my Debian virtual machine via Virtualbox in order to probe anything that goes on in the isofs kernel module (trying to find out more about a hang).

After loading the module (sudo modprobe -v isofs) I run the following trivial script (my first):

!/usr/sbin/dtrace -s

/* Intercepting all isofs function entries and exits _/ fbt:isofs:: { trace("worked!"); exit(0); /_printf("%s %s", probefunc, probename);*/ }

Originally I had the normal printf line, but thats commented out to test this in general. When the above script is ran, the following kernel oops happens:

Aug 19 19:44:36 debian-testing-vm kernel: [ 146.857394] dtracedrv: module license 'CDDL' taints kernel. Aug 19 19:44:36 debian-testing-vm kernel: [ 146.857402] Disabling lock debugging due to kernel taint Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883607] Pid: 3198, comm: insmod Tainted: P O 3.2.0-3-amd64 #1 Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883614] Call Trace: Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883689] [] ? mutex_enter_common+0x27/0xcb [dtracedrv] Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883758] [] ? par_alloc+0x1f/0xc6 [dtracedrv] Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883798] [] ? fbt_provide_module+0x34/0x23e [dtracedrv] Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883808] [] ? device_create_vargs+0x86/0xbe Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883816] [] ? should_resched+0x5/0x23 Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883825] [] ? _cond_resched+0x7/0x1c Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883830] [] ? should_resched+0x5/0x23 Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883836] [] ? _cond_resched+0x7/0x1c Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883842] [] ? mutex_lock+0xd/0x2d Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883883] [] ? dtrace_module_loaded+0x92/0x10d [dtracedrv] Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883891] [] ? notifier_call_chain+0x2e/0x5b Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883897] [] ? should_resched+0x5/0x23 Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883904] [] ? blocking_notifier_call_chain+0x48/0x5e Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883912] [] ? sys_init_module+0x1b6/0x25b Aug 19 19:44:36 debian-testing-vm kernel: [ 146.883919] [] ? system_call_fastpath+0x16/0x1b Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880448] BUG: unable to handle kernel paging request at ffffffffa0182086 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880453] IP: [] fbt_enable+0x5b/0x6a [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880464] PGD 1607067 PUD 160b063 PMD 3745b067 PTE 0 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880468] Oops: 0002 [#1] SMP Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880470] CPU 0 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880471] Modules linked in: isofs dtracedrv(P) vboxsf(O) pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) mperf cpufreq_stats cpufreq_conservative cpufreq_userspace cpufreq_powers ave ppdev lp vboxvideo(O) drm rfcomm bnep bluetooth rfkill binfmt_misc fuse vhba(O) loop joydev i2c_piix4 snd_intel8x0 snd_ac97_codec snd_pcm snd_page_alloc snd_seq snd_seq_device snd_timer snd soundcore i2c_core ac97_bus parport_pc psmo use ac serio_raw power_supply parport button processor evdev thermal_sys pcspkr vboxguest(O) ext4 crc16 jbd2 mbcache usbhid hid sd_mod crc_t10dif sr_mod cdrom ata_generic ata_piix ahci libahci ohci_hcd ehcihcd e1000 libata usbcore scsi mod usb_common [last unloaded: scsi_wait_scan] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880507] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880509] Pid: 3225, comm: isofs_tracing.d Tainted: P O 3.2.0-3-amd64 #1 innotek GmbH VirtualBox Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880512] RIP: 0010:[] [] fbt_enable+0x5b/0x6a [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880520] RSP: 0018:ffff88003c965898 EFLAGS: 00010202 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880522] RAX: ffffffffa0182086 RBX: ffff88001e0c97c0 RCX: 0000000000000002 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880524] RDX: 7fffffffffffffcc RSI: ffff88003c965848 RDI: 000000003745b067 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880525] RBP: ffff88001e0c9740 R08: ffff880000000c18 R09: ffff88000160b800 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880526] R10: ffff88001e118ff8 R11: 0000000000000000 R12: ffff88003744ffc0 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880528] R13: 0000000000000000 R14: ffff88001e091600 R15: ffffffffa05194e1 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880536] FS: 00007fd4d9c4b700(0000) GS:ffff88003fc00000(0000) knlGS:0000000000000000 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880538] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880539] CR2: ffffffffa0182086 CR3: 000000001e118000 CR4: 00000000000006f0 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880543] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880545] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880546] Process isofs_tracing.d (pid: 3225, threadinfo ffff88003c964000, task ffff88003cede180) Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880548] Stack: Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880549] ffff88001bfffd40 ffffffffa051b02d ffff88001e018200 0000000000000007 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880552] ffff880000000006 ffff88001e0e66c0 ffff88001e0182c0 ffffffffa050c0da Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880555] 0000000000000006 ffff88003c9659f0 0000000000000007 ffff8800265bc300 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880557] Call Trace: Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880564] [] ? dtrace_ecb_create_enable+0x1b4c/0x1be0 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880574] [] ? dtrace_match_probe+0x8c/0xa6 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880579] [] ? dtrace_ecb_destroy+0x555/0x555 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880585] [] ? dtrace_match+0x1f8/0x226 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880590] [] ? __kmalloc+0x100/0x112 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880596] [] ? kmem_zalloc+0x2e/0x54 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880602] [] ? dtrace_probe_enable+0x170/0x177 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880608] [] ? dtrace_strcmp+0x1b/0x1b [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880613] [] ? dtrace_strcmp+0x1b/0x1b [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880618] [] ? dtrace_match_glob+0x199/0x199 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880623] [] ? dtrace_match_glob+0x199/0x199 [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880628] [] ? dtrace_enabling_match+0x13a/0x1ca [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880634] [] ? dtrace_ioctl+0xc3e/0x217a [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880637] [] ? pte_offset_kernel+0x16/0x35 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880644] [] ? zone_page_state_add+0x14/0x23 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880647] [] ? inc_zone_state+0x41/0x49 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880650] [] ? zone_statistics+0x41/0x74 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880653] [] ? get_page_from_freelist+0x57a/0x665 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880656] [] ? alloc_pages_nodemask+0x6bf/0x726 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880659] [] ? find_get_page+0x40/0x63 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880661] [] ? should_resched+0x5/0x23 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880665] [] ? _cond_resched+0x7/0x1c Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880668] [] ? filemap_fault+0x1e6/0x33e Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880671] [] ? lookup_page_cgroup+0x2d/0x42 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880673] [] ? mem_cgroup_update_page_stat+0x17/0xd4 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880676] [] ? do_fault+0x371/0x3ac Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880678] [] ? handle_pte_fault+0x298/0x79f Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880680] [] ? pte_offset_kernel+0x16/0x35 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880687] [] ? dtracedrv_ioctl.isra.3+0x3c/0x4d [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880693] [] ? dtracedrv_unlocked_ioctl+0x6/0xa [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880697] [] ? do_vfs_ioctl+0x459/0x49a Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880699] [] ? should_resched+0x5/0x23 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880702] [] ? remove_vma+0x64/0x6b Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880704] [] ? do_munmap+0x2da/0x2f3 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880706] [] ? sys_ioctl+0x4b/0x72 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880710] [] ? system_call_fastpath+0x16/0x1b Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880714] Code: 54 a0 48 8b 73 08 31 c0 e8 ff 92 00 00 48 8b 7b 08 ba 01 00 00 00 be 01 00 00 00 e8 8e 8e ff ff 85 c0 74 09 48 8b 43 08 8a 53 12 <88> 10 48 8b 5b 48 48 85 db 75 b0 31 c0 5b c3 41 56 41 89 d6 41 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880737] RIP [] fbt_enable+0x5b/0x6a [dtracedrv] Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880744] RSP Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880745] CR2: ffffffffa0182086 Aug 19 19:44:56 debian-testing-vm kernel: [ 166.880747] ---[ end trace b484dd282d33d09e ]---

Something (no process name) then uses 100% kernel mode time on one CPU, and dtrace ignores SIGINT - time to reboot.

— Reply to this email directly or view it on GitHubhttps://github.com/dtrace4linux/linux/issues/40.

OmegaPhil commented 12 years ago

Ha, wow, thanks for the fast feedback! Your last message came as I was just hacking together my first basic 'commandline' script:

dtrace -n 'proc:::start,proc:::exit { printf("Process: %s %s", execname, probename); }'

Works perfectly. Just say if you want me to test anything. If you use IRC, I'm OmegaPhil on Freenode, if you want faster feedback.

Cheers

dtrace4linux commented 12 years ago

Hello Phil

i've tracked the issue down to the way modules are loaded; when dtrace is loaded, it gets the callback as the module loads, but some of the pages in a module are freed (the .init section) but dtrace doesnt know this. I found

cat /proc/dtrace/fbt

will give a GPF for functions no longer in memory, so now I have something to debug.

I wont get around to fixing tonite - maybe in next day or two, so just be careful of modprobes; if you unload dtrace and reload after the new module, everything should be fine.

(Im normally on google chat).

Have fun!

On 19 August 2012 20:30, OmegaPhil notifications@github.com wrote:

Ha, wow, thanks for the fast feedback! Your last message came as I was just hacking together my first basic 'commandline' script:


execname, probename); }'

Works perfectly. Just say if you want me to test anything. If you use IRC,
I'm OmegaPhil on Freenode, if you want faster feedback.

Cheers

—
Reply to this email directly or view it on GitHubhttps://github.com/dtrace4linux/linux/issues/40#issuecomment-7855970.
OmegaPhil commented 12 years ago

Excellent, thanks for the workaround - should be fine (I'm basically a n00b doing my first kernel dive, looked into dtrace today).

OmegaPhil commented 12 years ago

Works great - heres the output when mount locks up with 100% kernel mode on trying to mount a presumably bad iso9660 filesystem:

dtrace: script './isofs_tracing.d' matched 96 probes
CPU     ID                    FUNCTION:NAME
  0 262919                isofs_mount:entry isofs_mount entry
  0 262920           isofs_fill_super:entry isofs_fill_super entry
  0 262934                   sb_bread:entry sb_bread entry
  0 262935                     brelse:entry brelse entry
  0 262936                    brelse:return brelse return
  0 262934                   sb_bread:entry sb_bread entry
  0 262935                     brelse:entry brelse entry
  0 262935                     brelse:entry brelse entry
  0 262995                 isofs_iget:entry isofs_iget entry
  0 262932          isofs_alloc_inode:entry isofs_alloc_inode entry
  0 262937                  init_once:entry init_once entry
  0 262937                  init_once:entry init_once entry
  0 262937                  init_once:entry init_once entry
  0 262937                  init_once:entry init_once entry
  0 262937                  init_once:entry init_once entry
  0 262937                  init_once:entry init_once entry
  0 262933         isofs_alloc_inode:return isofs_alloc_inode return
  0 262917            isofs_iget5_set:entry isofs_iget5_set entry
  0 262918           isofs_iget5_set:return isofs_iget5_set return
  0 262934                   sb_bread:entry sb_bread entry

Never returns from sb_bread presumably. Now to see how to work kgdb!

dtrace4linux commented 12 years ago

Just a note to say I fixed the driver loading issue.

Interested to see how you get on with this issue, and if dtrace helps you.

thanks

On 19 August 2012 22:29, OmegaPhil notifications@github.com wrote:

Works great - heres the output when mount locks up with 100% kernel mode on trying to mount a presumably bad iso9660 filesystem:

dtrace: script './isofs_tracing.d' matched 96 probes CPU ID FUNCTION:NAME 0 262919 isofs_mount:entry isofs_mount entry 0 262920 isofs_fill_super:entry isofs_fill_super entry 0 262934 sb_bread:entry sb_bread entry 0 262935 brelse:entry brelse entry 0 262936 brelse:return brelse return 0 262934 sb_bread:entry sb_bread entry 0 262935 brelse:entry brelse entry 0 262935 brelse:entry brelse entry 0 262995 isofs_iget:entry isofs_iget entry 0 262932 isofs_alloc_inode:entry isofs_alloc_inode entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262933 isofs_alloc_inode:return isofs_alloc_inode return 0 262917 isofs_iget5_set:entry isofs_iget5_set entry 0 262918 isofs_iget5_set:return isofs_iget5_set return 0 262934 sb_bread:entry sb_bread entry

Never returns from sb_bread presumably. Now to see how to work kgdb!

— Reply to this email directly or view it on GitHubhttps://github.com/dtrace4linux/linux/issues/40#issuecomment-7857051.

OmegaPhil commented 12 years ago

Cheers :)

Sure - should I spam here or somewhere else? I think this is pretty much what I was aiming to get out of dtrace (although I am somewhat ignorant of what it can achieve). I am currently levelling up to start diving into the kernel proper with kgdb, now I have some target functions to look at. I dont really know C and I'm certainly no kernel programmer - my target is more to find some crap code and then do a basic patch to detect the problem and exit out. Locking up mount and then making the operating system unrestartable without a hardboot is Windows-level failure, so I thought it would be a good introduction.

On 20/08/12 23:37, dtrace4linux wrote:

Just a note to say I fixed the driver loading issue.

Interested to see how you get on with this issue, and if dtrace helps you.

thanks

On 19 August 2012 22:29, OmegaPhil notifications@github.com wrote:

Works great - heres the output when mount locks up with 100% kernel mode on trying to mount a presumably bad iso9660 filesystem:

dtrace: script './isofs_tracing.d' matched 96 probes CPU ID FUNCTION:NAME 0 262919 isofs_mount:entry isofs_mount entry 0 262920 isofs_fill_super:entry isofs_fill_super entry 0 262934 sb_bread:entry sb_bread entry 0 262935 brelse:entry brelse entry 0 262936 brelse:return brelse return 0 262934 sb_bread:entry sb_bread entry 0 262935 brelse:entry brelse entry 0 262935 brelse:entry brelse entry 0 262995 isofs_iget:entry isofs_iget entry 0 262932 isofs_alloc_inode:entry isofs_alloc_inode entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262937 init_once:entry init_once entry 0 262933 isofs_alloc_inode:return isofs_alloc_inode return 0 262917 isofs_iget5_set:entry isofs_iget5_set entry 0 262918 isofs_iget5_set:return isofs_iget5_set return 0 262934 sb_bread:entry sb_bread entry

Never returns from sb_bread presumably. Now to see how to work kgdb!

— Reply to this email directly or view it on GitHubhttps://github.com/dtrace4linux/linux/issues/40#issuecomment-7857051.

— Reply to this email directly or view it on GitHub https://github.com/dtrace4linux/linux/issues/40#issuecomment-7885993.