Hello
> You can use ftrace to help you watch the flow of your driver before it
> crashes, or just printk, as you have found out, is the best way to debug
> things.
Thanks for the hints. I will give ftrace a go.
It takes me around 5-7 minutes to see the kernel crash, and then reboot,
make changes, and try again (more if I use eclipse). I am wondering, if
there are ways to allow faster turnaround times. Maybe, it would be an
option to run the tests in an emulator, such as qemu? Any experience with that?
The first crash that is also logged I am getting in
usbrsa_allocate_write_urbs when calling spin_lock_irqsave. I see no obvious
mistakes, and on an old 3.0.x kernel, this was running fine. Any suggestion
of what am I doing wrong here?
printk("%s -- clear_bit",__func__);
spin_lock_irqsave(&priv_data->lock,flags);
clear_bit( i,&priv_data->write_urb_pool_lock);
spin_unlock_irqrestore(&priv_data->lock,flags);
printk("%s -- clear_bit end",__func__);
Here the log:
usbrsa: module verification failed: signature and/o
r required key missing - tainting kernel
usbcore: registered new interface driver usbrsa
usbserial: USB Serial support registered for IO-DAT
A - USB-RSA - (prerenumeration) usbserial: USB Serial support registered
for IO-DATA - USB-RSA
usb 3-3: new full-speed USB device number 2 using x
hci_hcd
usb 3-3: New USB device found, idVendor=04bb, idPro
duct=0a01
usb 3-3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
usb 3-3: usbrsa_firmware_download
usb 3-3: usbrsa_firmware_download(): Firmware downloaded.
usb 3-3: usbrsa_firmware_download(): Device with new firmware reset.
usbrsa 3-3:1.0: IO-DATA - USB-RSA - (prerenumeration) converter detected
Feb 22 07:48:52 btron mtp-probe: checking bus 3, device 2:
"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-3"
mtp-probe: bus: 3, device: 2 was not an MTP device
usb 3-3: USB disconnect, device number 2
usbrsa 3-3:1.0: device disconnected
usb 3-3: new full-speed USB device number 3 using xhci_hcd
usb 3-3: New USB device found, idVendor=04bb, idProduct=0a02
usb 3-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
usb 3-3: Product: USB-RS232C CONVERTER
usb 3-3: Manufacturer: I-O DATA DEVICE,Inc.
usb 3-3: SerialNumber: USB-RSA Rev.1䰑<U+F480>羐
USB-RSA converter detected
usbrsa_attach start
usb 3-3: usbrsa_attach
usbrsa_attach about to enter
'usbrsa_allocate_write_urbs'usbrsa_allocate_write_urbs() Mark 1
usb-serial (null): usbrsa_allocate_write_urbs()
usbrsa_allocate_write_urbs() Mark 2usbrsa_allocate_write_urbs; i=0
usbrsa_allocate_write_urbs; Mark3
usbrsa_allocate_write_urbs; Mark4
usbrsa_allocate_write_urbs -- clear_bit
BUG: unable to handle kernel paging request at 00001ddc00017654
IP: [<ffffffff810bfa94>] native_queued_spin_lock_slowpath+0x104/0x190
PGD 0
Oops: 0002 [#1] SMP
Modules linked in: usbrsa(OE) usbserial ezusb drbg ansi_cprng ctr ccm bnep
rfcomm dm_crypt nfsd auth_rpcgss nfs_acl nfs lockd grace sunrpc binfmt_misc
fscache nls_iso8859_1 uvcvideo videobuf2_vmalloc videobuf2_memops
videobuf2_v4l2 videobuf2_core videodev arc4 iwldvm mac80211
snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_codec
btusb intel_rapl x86_pkg_temp_thermal intel_powerclamp btrtl btbcm coretemp
snd_hda_core btintel snd_hwdep kvm_intel iwlwifi bluetooth kvm snd_pcm
snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq irqbypass mei_me
snd_seq_device snd_timer snd cfg80211 mei asus_nb_wmi asus_wmi sparse_keymap
crct10dif_pclmul soundcore crc32_pclmul ghash_clmulni_intel aesni_intel
shpchp lpc_ich aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd joydev
serio_raw mac_hid parport_pc ppdev lp parport nouveau i915 mxm_wmi ttm
i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops
drm ahci psmouse alx libahci mdio wmi video
CPU: 4 PID: 37 Comm: kworker/4:0 Tainted: G OE 4.5.0-rc4-custom #1
Hardware name: ASUSTeK COMPUTER INC. N56VZ/N56VZ, BIOS N56VZ.215 11/02/2012
Workqueue: usb_hub_wq hub_event
task: ffff88041c54d7c0 ti: ffff88041c57c000 task.ti ffff88041c57c000
RIP: 0010:[<ffffffff810bfa94>] [<ffffffff810bfa94>]
native_queued_spin_lock_slowpath+0x104/0x190
RSP: 0018:ffff88041c57f700 EFLAGS: 00010002
RAX: 00000000000039df RBX: 0000000000000282 RCX: 0000000000140000
RDX: 00001ddc00017654 RSI: 00000000e78092ef RDI: ffff8800b971aa10
RBP: ffff88041c57f700 R08: ffff88042ef17640 R09: 0000000000000000
R10: 0000000000000005 R11: 00000000000004b7 R12: 0000000000000000
R13: ffff8800b971aa10 R14: ffff88041aaaca80 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff88042ef00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00001ddc00017654 CR3: 0000000001c0c000 CR4: 00000000001406e0
Stack:
ffff88041c57f710 ffffffff811726fd ffff88041c57f728 ffffffff817a47e7
ffff8800b971aa00 ffff88041c57f760 ffffffffa09e7655 0000000000000002
ffff88041c6ab800 ffff88041c6ab810 ffff88041a1aaa80 ffffffffa09ea000
Call Trace:
[<ffffffff811726fd>] queued_spin_lock_slowpath+0xb/0xf
[<ffffffff817a47e7>] _raw_spin_lock_irqsave+0x37/0x40
[<ffffffffa09e7655>] usbrsa_attach+0x1b5/0x660 [usbrsa]
[<ffffffffa09d433f>] usb_serial_probe+0xdcf/0x1220 [usbserial]
[<ffffffff817a28cf>] ? __mutex_lock_slowpath+0x2f/0x110
[<ffffffff813ad9b5>] ? ida_simple_get+0x85/0xe0
[<ffffffff8150e148>] ? __pm_runtime_set_status+0x128/0x1e0
[<ffffffff815c35ff>] usb_probe_interface+0x1bf/0x310
[<ffffffff815026f9>] driver_probe_device+0x239/0x460
[<ffffffff81502a54>] __device_attach_driver+0x74/0x80
[<ffffffff815029e0>] ? driver_allows_async_probing+0x30/0x30
[<ffffffff81500488>] bus_for_each_drv+0x58/0x90
[<ffffffff8150233b>] __device_attach+0xbb/0x140
[<ffffffff81502be3>] device_initial_probe+0x13/0x20
[<ffffffff815016e2>] bus_probe_device+0x92/0xa0
[<ffffffff814ff532>] device_add+0x422/0x610
[<ffffffff815c1541>] usb_set_configuration+0x4f1/0x7f0
[<ffffffff815cbc2e>] generic_probe+0x2e/0xa0
[<ffffffff815c3402>] usb_probe_device+0x32/0x70
[<ffffffff815026f9>] driver_probe_device+0x239/0x460
[<ffffffff81502a54>] __device_attach_driver+0x74/0x80
[<ffffffff815029e0>] ? driver_allows_async_probing+0x30/0x30
[<ffffffff81500488>] bus_for_each_drv+0x58/0x90
[<ffffffff8150233b>] __device_attach+0xbb/0x140
[<ffffffff81502be3>] device_initial_probe+0x13/0x20
[<ffffffff815016e2>] bus_probe_device+0x92/0xa0
[<ffffffff814ff532>] device_add+0x422/0x610
[<ffffffff815b6d76>] usb_new_device+0x276/0x4d0
[<ffffffff815b8c1a>] hub_event+0xd7a/0x1430
[<ffffffff8108f981>] process_one_work+0x151/0x3d0
[<ffffffff8109006b>] worker_thread+0x12b/0x4b0
[<ffffffff8108ff40>] ? rescuer_thread+0x340/0x340
[<ffffffff81095809>] kthread+0xc9/0xe0
[<ffffffff81095740>] ? kthread_park+0x60/0x60
[<ffffffff817a4d8f>] ret_from_fork+0x3f/0x70
[<ffffffff81095740>] ? kthread_park+0x60/0x60
Code: c1 e0 10 45 31 c9 85 c0 74 46 48 89 c2 c1 e8 12 48 c1 ea 0c 83 e8 01
83 e2 30 48 98 48 81 c2 40 76 01 00 48 03 14 c5 c0 d2 d3 81 <4c> 89 02 41 8b
40 08 85 c0 75 0a f3 90 41 8b 40 08 85 c0 74 f6
RIP [<ffffffff810bfa94>] native_queued_spin_lock_slowpath+0x104/0x190
RSP <ffff88041c57f700>
CR2: 00001ddc00017654
---[ end trace a78fe1b9025ad592 ]---
BUG: unable to handle kernel paging request at ffffffffffffffd8
Many thanks
Tilman
��.n��������+%������w��{.n�����{���)�� jg��� �����ݢj����G���� ���j:+v���w�m������w�������h�����٥
