[opensuse-kernel] USBmidi(?) problem in 13.2 kernel
Hi all, I know this is for upstream. But 3.16 ist old, so nobody will care and additionally I know that both sound and USB maintainers are reading this list, this is why I come here :-) My daughters machine got updated to 13.2. She has a "Midiman M-Audio Keystation USB 49" keyboard. I have the following script to use the box as cheap synthesizer: --- #!/bin/sh trap 'killall -9 timidity; pasuspender /bin/true' 0 killall -9 timidity export TIMIDITY_PCM_NAME=sysdefault ( pasuspender -- timidity -Os -A250a -s 44100 -iA -B1,1 )& sleep 2; aconnect 20:0 128:0 sleep 1 echo "Enter zum beenden..." read x killall timidity --- Plug in keyboard in "boot" mode: 2014-11-21T17:50:47.095100+01:00 wendy kernel: [29816.287121] usb 4-2: new full-speed USB device number 3 using uhci_hcd 2014-11-21T17:50:47.244111+01:00 wendy kernel: [29816.436861] usb 4-2: New USB device found, idVendor=0763, idProduct=1014 2014-11-21T17:50:47.244165+01:00 wendy kernel: [29816.436871] usb 4-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0 ...firmware is uploaded... 2014-11-21T17:50:54.058158+01:00 wendy kernel: [29823.250222] usb 4-2: USB disconnect, device number 3 2014-11-21T17:50:55.014085+01:00 wendy kernel: [29824.206153] usb 4-2: new full-speed USB device number 4 using uhci_hcd 2014-11-21T17:50:55.146113+01:00 wendy kernel: [29824.338789] usb 4-2: New USB device found, idVendor=0763, idProduct=1015 2014-11-21T17:50:55.146163+01:00 wendy kernel: [29824.338804] usb 4-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0 ... device get's new USB is an dis usable. 2014-11-21T17:50:56.288141+01:00 wendy kernel: [29825.480162] usbcore: registered new interface driver snd-usb-audio This works well. However, She quickly got the following backtraces: 2014-11-21T17:51:08.319339+01:00 wendy kernel: [29837.511023] ------------[ cut here ]------------ 2014-11-21T17:51:08.319386+01:00 wendy kernel: [29837.511061] WARNING: CPU: 0 PID: 0 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() 2014-11-21T17:51:08.319396+01:00 wendy kernel: [29837.511069] URB ef705c40 submitted while active 2014-11-21T17:51:08.319410+01:00 wendy kernel: [29837.511074] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hrtimer snd_usb_audio snd_usbmidi_lib snd_rawmidi nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device r8169 snd_timer snd_mixer_oss snd mii iTCO_wdt iTCO_vendor_support ppdev parport_pc shpchp parport gpio_ich ite_cir rc_core lpc_ich mfd_core soundcore coretemp i2c_i801 serio_raw pcspkr tpm_infineon tpm_tis tpm dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg 2014-11-21T17:51:08.319420+01:00 wendy kernel: [29837.511209] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.6-2-desktop #1 2014-11-21T17:51:08.319429+01:00 wendy kernel: [29837.511215] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 2014-11-21T17:51:08.319436+01:00 wendy kernel: [29837.511221] c0984bfa f4009ed4 c078deaf f4009ee4 c024c884 c09a135c f4009f00 00000000 2014-11-21T17:51:08.319444+01:00 wendy kernel: [29837.511234] c0984bfa 00000153 c061ac4f c061ac4f 00000009 00000001 ef705c40 e854d1c0 2014-11-21T17:51:08.319451+01:00 wendy kernel: [29837.511247] f4009eec c024c8d3 00000009 f4009ee4 c09a135c f4009f00 f4009f04 c061ac4f 2014-11-21T17:51:08.319459+01:00 wendy kernel: [29837.511259] Call Trace: 2014-11-21T17:51:08.319466+01:00 wendy kernel: [29837.511283] [<c0205df6>] try_stack_unwind+0x156/0x170 2014-11-21T17:51:08.319474+01:00 wendy kernel: [29837.511303] [<c020482a>] dump_trace+0x5a/0x1b0 2014-11-21T17:51:08.319483+01:00 wendy kernel: [29837.511315] [<c0205e56>] show_trace_log_lvl+0x46/0x50 2014-11-21T17:51:08.319490+01:00 wendy kernel: [29837.511327] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 2014-11-21T17:51:08.319499+01:00 wendy kernel: [29837.511338] [<c0205eb7>] show_stack+0x27/0x50 2014-11-21T17:51:08.319507+01:00 wendy kernel: [29837.511350] [<c078deaf>] dump_stack+0x45/0x65 2014-11-21T17:51:08.319514+01:00 wendy kernel: [29837.511369] [<c024c884>] warn_slowpath_common+0x84/0xa0 2014-11-21T17:51:08.319523+01:00 wendy kernel: [29837.511381] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 2014-11-21T17:51:08.319531+01:00 wendy kernel: [29837.511393] [<c061ac4f>] usb_submit_urb+0x5f/0x70 2014-11-21T17:51:08.319539+01:00 wendy kernel: [29837.511415] [<f7974104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] 2014-11-21T17:51:08.319546+01:00 wendy kernel: [29837.511441] [<f797483a>] snd_usbmidi_error_timer+0x6a/0xa0 [snd_usbmidi_lib] 2014-11-21T17:51:08.319555+01:00 wendy kernel: [29837.511456] [<c02570c0>] call_timer_fn+0x30/0x130 2014-11-21T17:51:08.319563+01:00 wendy kernel: [29837.511468] [<c0257442>] run_timer_softirq+0x1c2/0x260 2014-11-21T17:51:08.319571+01:00 wendy kernel: [29837.511483] [<c0251493>] __do_softirq+0xc3/0x270 2014-11-21T17:51:08.319578+01:00 wendy kernel: [29837.511494] [<c0204732>] do_softirq_own_stack+0x22/0x30 2014-11-21T17:51:08.319585+01:00 wendy kernel: [29837.511505] [<c025186d>] irq_exit+0x8d/0xa0 2014-11-21T17:51:08.319591+01:00 wendy kernel: [29837.511520] [<c0795228>] smp_apic_timer_interrupt+0x38/0x50 2014-11-21T17:51:08.319598+01:00 wendy kernel: [29837.511533] [<c0794a3c>] apic_timer_interrupt+0x34/0x3c 2014-11-21T17:51:08.319605+01:00 wendy kernel: [29837.511550] [<c0673d9e>] cpuidle_enter_state+0x3e/0xd0 2014-11-21T17:51:08.319612+01:00 wendy kernel: [29837.511563] [<c028bb8d>] cpu_idle_loop+0x29d/0x3e0 2014-11-21T17:51:08.319619+01:00 wendy kernel: [29837.511575] [<c028bd23>] cpu_startup_entry+0x53/0x60 2014-11-21T17:51:08.319625+01:00 wendy kernel: [29837.511589] [<c0bfac1e>] start_kernel+0x415/0x41a 2014-11-21T17:51:08.319632+01:00 wendy kernel: [29837.511598] ---[ end trace f8fefbc2e004204d ]--- 2014-11-21T17:51:08.319639+01:00 wendy kernel: [29837.511609] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319646+01:00 wendy kernel: [29837.511616] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319653+01:00 wendy kernel: [29837.511622] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319659+01:00 wendy kernel: [29837.511636] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319665+01:00 wendy kernel: [29837.511643] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319673+01:00 wendy kernel: [29837.511650] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319680+01:00 wendy kernel: [29837.511656] ------------[ cut here ]------------ 2014-11-21T17:51:08.319688+01:00 wendy kernel: [29837.511665] WARNING: CPU: 0 PID: 0 at ../kernel/timer.c:1147 call_timer_fn+0x115/0x130() 2014-11-21T17:51:08.319695+01:00 wendy kernel: [29837.511676] timer: snd_usbmidi_error_timer+0x0/0xa0 [snd_usbmidi_lib] preempt leak: 00000101 -> 00000102 2014-11-21T17:51:08.319704+01:00 wendy kernel: [29837.511680] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hrtimer snd_usb_audio snd_usbmidi_lib snd_rawmidi nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device r8169 snd_timer snd_mixer_oss snd mii iTCO_wdt iTCO_vendor_support ppdev parport_pc shpchp parport gpio_ich ite_cir rc_core lpc_ich mfd_core soundcore coretemp i2c_i801 serio_raw pcspkr tpm_infineon tpm_tis tpm dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg 2014-11-21T17:51:08.319713+01:00 wendy kernel: [29837.511782] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W 3.16.6-2-desktop #1 2014-11-21T17:51:08.319719+01:00 wendy kernel: [29837.511787] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 2014-11-21T17:51:08.319727+01:00 wendy kernel: [29837.511792] c0940e36 f4009f28 c078deaf f4009f38 c024c884 c0936590 f4009f54 00000000 2014-11-21T17:51:08.319735+01:00 wendy kernel: [29837.511805] c0940e36 0000047b c02571a5 c02571a5 00000009 f4009f9c e854d1e0 00000101 2014-11-21T17:51:08.319745+01:00 wendy kernel: [29837.511818] f4009f40 c024c8d3 00000009 f4009f38 c0936590 f4009f54 f4009f74 c02571a5 2014-11-21T17:51:08.319754+01:00 wendy kernel: [29837.511830] Call Trace: 2014-11-21T17:51:08.319763+01:00 wendy kernel: [29837.511843] [<c0205df6>] try_stack_unwind+0x156/0x170 2014-11-21T17:51:08.319771+01:00 wendy kernel: [29837.511862] [<c020482a>] dump_trace+0x5a/0x1b0 2014-11-21T17:51:08.319778+01:00 wendy kernel: [29837.511873] [<c0205e56>] show_trace_log_lvl+0x46/0x50 2014-11-21T17:51:08.319786+01:00 wendy kernel: [29837.511885] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 2014-11-21T17:51:08.319795+01:00 wendy kernel: [29837.511896] [<c0205eb7>] show_stack+0x27/0x50 2014-11-21T17:51:08.319804+01:00 wendy kernel: [29837.511907] [<c078deaf>] dump_stack+0x45/0x65 2014-11-21T17:51:08.319813+01:00 wendy kernel: [29837.511918] [<c024c884>] warn_slowpath_common+0x84/0xa0 2014-11-21T17:51:08.319823+01:00 wendy kernel: [29837.511930] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 2014-11-21T17:51:08.319874+01:00 wendy kernel: [29837.511941] [<c02571a5>] call_timer_fn+0x115/0x130 2014-11-21T17:51:08.319883+01:00 wendy kernel: [29837.511954] [<c0257442>] run_timer_softirq+0x1c2/0x260 2014-11-21T17:51:08.319892+01:00 wendy kernel: [29837.511968] [<c0251493>] __do_softirq+0xc3/0x270 2014-11-21T17:51:08.319900+01:00 wendy kernel: [29837.511979] [<c0204732>] do_softirq_own_stack+0x22/0x30 2014-11-21T17:51:08.319908+01:00 wendy kernel: [29837.511990] [<c025186d>] irq_exit+0x8d/0xa0 2014-11-21T17:51:08.319916+01:00 wendy kernel: [29837.512021] [<c0795228>] smp_apic_timer_interrupt+0x38/0x50 2014-11-21T17:51:08.319924+01:00 wendy kernel: [29837.512034] [<c0794a3c>] apic_timer_interrupt+0x34/0x3c 2014-11-21T17:51:08.319932+01:00 wendy kernel: [29837.512047] [<c0673d9e>] cpuidle_enter_state+0x3e/0xd0 2014-11-21T17:51:08.319940+01:00 wendy kernel: [29837.512059] [<c028bb8d>] cpu_idle_loop+0x29d/0x3e0 2014-11-21T17:51:08.319949+01:00 wendy kernel: [29837.512070] [<c028bd23>] cpu_startup_entry+0x53/0x60 2014-11-21T17:51:08.319957+01:00 wendy kernel: [29837.512082] [<c0bfac1e>] start_kernel+0x415/0x41a 2014-11-21T17:51:08.319965+01:00 wendy kernel: [29837.512091] ---[ end trace f8fefbc2e004204e ]--- 2014-11-21T17:51:08.685138+01:00 wendy kernel: [29837.878046] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.685183+01:00 wendy kernel: [29837.878078] usb 4-2: usb_submit_urb: -16 the usb_submit_urb goes on and on until today, over several suspend to RAM cycles. The keyboard did still work. Until the machine finally panicked today 19:40+01:00. After reboot, the module was loaded during boot, same procedure: 2014-11-23T19:43:06.088478+01:00 wendy kernel: [ 27.562444] usb 4-2: new full-speed USB device number 3 using uhci_hcd 2014-11-23T19:43:06.088486+01:00 wendy kernel: [ 27.698944] usb 4-2: New USB device found, idVendor=0763, idProduct=1014 2014-11-23T19:43:06.088494+01:00 wendy kernel: [ 27.698954] usb 4-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0 2014-11-23T19:43:06.088502+01:00 wendy kernel: [ 34.954224] usb 4-2: USB disconnect, device number 3 something strange happens: 2014-11-23T19:43:06.088510+01:00 wendy kernel: [ 35.914169] usb 4-2: new full-speed USB device number 4 using uhci_hcd 2014-11-23T19:43:06.088518+01:00 wendy kernel: [ 36.042935] usb 4-2: config index 0 descriptor too short (expected 9, got 2) 2014-11-23T19:43:06.088526+01:00 wendy kernel: [ 36.042944] usb 4-2: can't read configurations, error -22 ...but the device appears finally: 2014-11-23T19:43:06.088549+01:00 wendy kernel: [ 36.146573] usb 4-2: new full-speed USB device number 5 using uhci_hcd 2014-11-23T19:43:06.088559+01:00 wendy kernel: [ 36.279939] usb 4-2: New USB device found, idVendor=0763, idProduct=1015 2014-11-23T19:43:06.088567+01:00 wendy kernel: [ 36.279948] usb 4-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0 2014-11-23T19:43:06.088593+01:00 wendy kernel: [ 37.406602] usbcore: registered new interface driver snd-usb-audio then again: 2014-11-23T19:44:17.179668+01:00 wendy kernel: [ 108.594035] ------------[ cut here ]------------ 2014-11-23T19:44:17.179728+01:00 wendy kernel: [ 108.594078] WARNING: CPU: 1 PID: 0 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() 2014-11-23T19:44:17.179739+01:00 wendy kernel: [ 108.594088] URB f6bcd700 submitted while active 2014-11-23T19:44:17.179785+01:00 wendy kernel: [ 108.594094] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_hda_codec_realtek snd_hda_codec_generic gpio_ich iTCO_wdt iTCO_vendor_support snd_hda_intel snd_hda_controller snd_hda_codec ppdev snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss coretemp serio_raw pcspkr i2c_i801 snd lpc_ich mfd_core r8169 mii shpchp soundcore parport_pc parport ite_cir rc_core tpm_infineon tpm_tis tpm dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg 2014-11-23T19:44:17.179796+01:00 wendy kernel: [ 108.594249] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 3.16.6-2-desktop #1 2014-11-23T19:44:17.179805+01:00 wendy kernel: [ 108.594266] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 2014-11-23T19:44:17.179814+01:00 wendy kernel: [ 108.594275] c0984bfa f416ded4 c078deaf f416dee4 c024c884 c09a135c f416df00 00000000 2014-11-23T19:44:17.179822+01:00 wendy kernel: [ 108.594293] c0984bfa 00000153 c061ac4f c061ac4f 00000009 00000002 f6bcd700 f6bcd040 2014-11-23T19:44:17.179831+01:00 wendy kernel: [ 108.594311] f416deec c024c8d3 00000009 f416dee4 c09a135c f416df00 f416df04 c061ac4f 2014-11-23T19:44:17.179839+01:00 wendy kernel: [ 108.594329] Call Trace: 2014-11-23T19:44:17.179847+01:00 wendy kernel: [ 108.594361] [<c0205df6>] try_stack_unwind+0x156/0x170 2014-11-23T19:44:17.179855+01:00 wendy kernel: [ 108.594391] [<c020482a>] dump_trace+0x5a/0x1b0 2014-11-23T19:44:17.179863+01:00 wendy kernel: [ 108.594412] [<c0205e56>] show_trace_log_lvl+0x46/0x50 2014-11-23T19:44:17.179871+01:00 wendy kernel: [ 108.594430] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 2014-11-23T19:44:17.179879+01:00 wendy kernel: [ 108.594448] [<c0205eb7>] show_stack+0x27/0x50 2014-11-23T19:44:17.179888+01:00 wendy kernel: [ 108.594466] [<c078deaf>] dump_stack+0x45/0x65 2014-11-23T19:44:17.179896+01:00 wendy kernel: [ 108.594486] [<c024c884>] warn_slowpath_common+0x84/0xa0 2014-11-23T19:44:17.179904+01:00 wendy kernel: [ 108.594503] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 2014-11-23T19:44:17.179912+01:00 wendy kernel: [ 108.594520] [<c061ac4f>] usb_submit_urb+0x5f/0x70 2014-11-23T19:44:17.179921+01:00 wendy kernel: [ 108.594554] [<f76eb104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] 2014-11-23T19:44:17.179928+01:00 wendy kernel: [ 108.594587] [<f76eb83a>] snd_usbmidi_error_timer+0x6a/0xa0 [snd_usbmidi_lib] 2014-11-23T19:44:17.179937+01:00 wendy kernel: [ 108.594611] [<c02570c0>] call_timer_fn+0x30/0x130 2014-11-23T19:44:17.179944+01:00 wendy kernel: [ 108.594631] [<c0257442>] run_timer_softirq+0x1c2/0x260 2014-11-23T19:44:17.179953+01:00 wendy kernel: [ 108.594655] [<c0251493>] __do_softirq+0xc3/0x270 2014-11-23T19:44:17.179960+01:00 wendy kernel: [ 108.594673] [<c0204732>] do_softirq_own_stack+0x22/0x30 2014-11-23T19:44:17.179968+01:00 wendy kernel: [ 108.594690] [<c025186d>] irq_exit+0x8d/0xa0 2014-11-23T19:44:17.179976+01:00 wendy kernel: [ 108.594713] [<c0795228>] smp_apic_timer_interrupt+0x38/0x50 2014-11-23T19:44:17.179984+01:00 wendy kernel: [ 108.594732] [<c0794a3c>] apic_timer_interrupt+0x34/0x3c 2014-11-23T19:44:17.180003+01:00 wendy kernel: [ 108.594751] [<c0673d9e>] cpuidle_enter_state+0x3e/0xd0 2014-11-23T19:44:17.180011+01:00 wendy kernel: [ 108.594770] [<c028bb8d>] cpu_idle_loop+0x29d/0x3e0 2014-11-23T19:44:17.180020+01:00 wendy kernel: [ 108.594787] [<c028bd23>] cpu_startup_entry+0x53/0x60 2014-11-23T19:44:17.180028+01:00 wendy kernel: [ 108.594818] [<c0230bdf>] start_secondary+0x20f/0x2e0 2014-11-23T19:44:17.180036+01:00 wendy kernel: [ 108.594833] ---[ end trace 952a2543044934e8 ]--- 2014-11-23T19:44:17.180044+01:00 wendy kernel: [ 108.594848] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180052+01:00 wendy kernel: [ 108.594867] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180060+01:00 wendy kernel: [ 108.594877] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180067+01:00 wendy kernel: [ 108.594888] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180075+01:00 wendy kernel: [ 108.594898] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180083+01:00 wendy kernel: [ 108.594908] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180091+01:00 wendy kernel: [ 108.594917] ------------[ cut here ]------------ 2014-11-23T19:44:17.180099+01:00 wendy kernel: [ 108.594930] WARNING: CPU: 1 PID: 0 at ../kernel/timer.c:1147 call_timer_fn+0x115/0x130() 2014-11-23T19:44:17.180107+01:00 wendy kernel: [ 108.594947] timer: snd_usbmidi_error_timer+0x0/0xa0 [snd_usbmidi_lib] preempt leak: 00000101 -> 00000102 2014-11-23T19:44:17.180117+01:00 wendy kernel: [ 108.594954] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_hda_codec_realtek snd_hda_codec_generic gpio_ich iTCO_wdt iTCO_vendor_support snd_hda_intel snd_hda_controller snd_hda_codec ppdev snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss coretemp serio_raw pcspkr i2c_i801 snd lpc_ich mfd_core r8169 mii shpchp soundcore parport_pc parport ite_cir rc_core tpm_infineon tpm_tis tpm dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg 2014-11-23T19:44:17.180126+01:00 wendy kernel: [ 108.595119] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G W 3.16.6-2-desktop #1 2014-11-23T19:44:17.180135+01:00 wendy kernel: [ 108.595129] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 2014-11-23T19:44:17.180142+01:00 wendy kernel: [ 108.595137] c0940e36 f416df28 c078deaf f416df38 c024c884 c0936590 f416df54 00000000 2014-11-23T19:44:17.180151+01:00 wendy kernel: [ 108.595156] c0940e36 0000047b c02571a5 c02571a5 00000009 f416df9c f6bcd060 00000101 2014-11-23T19:44:17.180158+01:00 wendy kernel: [ 108.595175] f416df40 c024c8d3 00000009 f416df38 c0936590 f416df54 f416df74 c02571a5 2014-11-23T19:44:17.180166+01:00 wendy kernel: [ 108.595195] Call Trace: 2014-11-23T19:44:17.180174+01:00 wendy kernel: [ 108.595221] [<c0205df6>] try_stack_unwind+0x156/0x170 2014-11-23T19:44:17.180181+01:00 wendy kernel: [ 108.595250] [<c020482a>] dump_trace+0x5a/0x1b0 2014-11-23T19:44:17.180189+01:00 wendy kernel: [ 108.595279] [<c0205e56>] show_trace_log_lvl+0x46/0x50 2014-11-23T19:44:17.180196+01:00 wendy kernel: [ 108.595298] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 2014-11-23T19:44:17.180205+01:00 wendy kernel: [ 108.595315] [<c0205eb7>] show_stack+0x27/0x50 2014-11-23T19:44:17.180212+01:00 wendy kernel: [ 108.595333] [<c078deaf>] dump_stack+0x45/0x65 2014-11-23T19:44:17.180219+01:00 wendy kernel: [ 108.595354] [<c024c884>] warn_slowpath_common+0x84/0xa0 2014-11-23T19:44:17.180227+01:00 wendy kernel: [ 108.595373] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 2014-11-23T19:44:17.180235+01:00 wendy kernel: [ 108.595391] [<c02571a5>] call_timer_fn+0x115/0x130 2014-11-23T19:44:17.180243+01:00 wendy kernel: [ 108.595411] [<c0257442>] run_timer_softirq+0x1c2/0x260 2014-11-23T19:44:17.180250+01:00 wendy kernel: [ 108.595434] [<c0251493>] __do_softirq+0xc3/0x270 2014-11-23T19:44:17.180258+01:00 wendy kernel: [ 108.595452] [<c0204732>] do_softirq_own_stack+0x22/0x30 2014-11-23T19:44:17.180266+01:00 wendy kernel: [ 108.595469] [<c025186d>] irq_exit+0x8d/0xa0 2014-11-23T19:44:17.180275+01:00 wendy kernel: [ 108.595491] [<c0795228>] smp_apic_timer_interrupt+0x38/0x50 2014-11-23T19:44:17.180282+01:00 wendy kernel: [ 108.595510] [<c0794a3c>] apic_timer_interrupt+0x34/0x3c 2014-11-23T19:44:17.180291+01:00 wendy kernel: [ 108.595532] [<c0673d9e>] cpuidle_enter_state+0x3e/0xd0 2014-11-23T19:44:17.180298+01:00 wendy kernel: [ 108.595551] [<c028bb8d>] cpu_idle_loop+0x29d/0x3e0 2014-11-23T19:44:17.180307+01:00 wendy kernel: [ 108.595570] [<c028bd23>] cpu_startup_entry+0x53/0x60 2014-11-23T19:44:17.180314+01:00 wendy kernel: [ 108.595588] [<c0230bdf>] start_secondary+0x20f/0x2e0 2014-11-23T19:44:17.180323+01:00 wendy kernel: [ 108.595604] ---[ end trace 952a2543044934e9 ]--- 2014-11-23T19:44:17.767840+01:00 wendy kernel: [ 109.183061] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.767889+01:00 wendy kernel: [ 109.183070] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.767899+01:00 wendy kernel: [ 109.183076] usb 4-2: usb_submit_urb: -16 .... on and on, until panic at 20:04 local time. My daughter took a picture of the second panic (but I don't know how good the quality is and if we can see anything on it) What did I already try? * update to 3.17.x from Kernel:stable * downgrade to 3.10.x from 13.1 Both show the same "usb_submit_urb: -16" flood. I did not try long enough to panic the box. My daughter suggested that the panic does happen when she starts playing with the special MIDI functions of the keyboard. I don't know if that's true or if the two panics today are just bad luck. Grepping through the archived syslog seems to suggest that it happened first on March 23 2014, with 13.1 kernel 3.11.10 With 3.11.10, there is only one call trace from [ 135.889057] WARNING: CPU: 3 PID: 1756 at /home/abuild/rpmbuild/BUILD/kernel-desktop-3.11.10/linux-3.11/drivers/usb/core/urb.c:327 usb_submit_urb+0x3a4/0x3c0() [ 135.889061] URB f3f710c0 submitted while active And the message is slightly different: [ 135.889439] ALSA midi.c:194 usb_submit_urb: -16 Going further back through the logs would suggest this started with 13.1, 12.3 (kernel 3.7) seems to have worked fine. OTOH the MIDI keyboard is only used once in a while, so this might not be true. Anything more you need from me? (and *please* don't say "git bisect" :-)) Best regards, seife -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
On Sun, Nov 23, 2014 at 10:27:40PM +0100, Stefan Seyfried wrote:
Hi all,
I know this is for upstream. But 3.16 ist old, so nobody will care and additionally I know that both sound and USB maintainers are reading this list, this is why I come here :-)
My daughters machine got updated to 13.2.
Which architecture? This setup suggests some Pi ;-)
2014-11-21T17:50:56.288141+01:00 wendy kernel: [29825.480162] usbcore: registered new interface driver snd-usb-audio
My first guess is that this is the problem.
This works well. However, She quickly got the following backtraces: 2014-11-21T17:51:08.319396+01:00 wendy kernel: [29837.511069] URB ef705c40 submitted while active
[...]
2014-11-21T17:51:08.319695+01:00 wendy kernel: [29837.511676] timer: snd_usbmidi_error_timer+0x0/0xa0 [snd_usbmidi_lib] preempt leak: 00000101 -> 00000102
After reboot, the module was loaded during boot, same procedure:
something strange happens: 2014-11-23T19:43:06.088510+01:00 wendy kernel: [ 35.914169] usb 4-2: new full-speed USB device number 4 using uhci_hcd 2014-11-23T19:43:06.088518+01:00 wendy kernel: [ 36.042935] usb 4-2: config index 0 descriptor too short (expected 9, got 2) 2014-11-23T19:43:06.088526+01:00 wendy kernel: [ 36.042944] usb 4-2: can't read configurations, error -22
What did I already try? * update to 3.17.x from Kernel:stable * downgrade to 3.10.x from 13.1
Both show the same "usb_submit_urb: -16" flood. I did not try long enough to panic the box. My daughter suggested that the panic does happen when she starts playing with the special MIDI functions of the keyboard. I don't know if that's true or if the two panics today are just bad luck.
Grepping through the archived syslog seems to suggest that it happened first on March 23 2014, with 13.1 kernel 3.11.10
Works fine here, 13.2, 3.16.6-2-desktop #1 SMP PREEMPT Mon Oct 20 13:47:22 UTC 2014 (feb42ea) x86_64 [ 2.711503] usb 3-1: new full-speed USB device number 2 using xhci_hcd [ 2.864383] usb 3-1: New USB device found, idVendor=1a86, idProduct=752d [ 2.864387] usb 3-1: New USB device strings: Mfr=0, Product=2, SerialNumber=0 [ 2.864389] usb 3-1: Product: USB2.0-MIDI But it's a MIDI-_only_ adaptor, cheap LogiLink idVendor 0x1a86 QinHeng Electronics idProduct 0x752d CH345 MIDI adapter bcdDevice 2.54 iManufacturer 0 iProduct 2 USB2.0-MIDI Maybe the kernel messes up the endpoint configuration, seeing the additional audio device? Sorry, that's all I can contribute for now. Torsten -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
"Torsten" == Torsten Duwe <duwe@suse.de> writes:
>> >> something strange happens: 2014-11-23T19:43:06.088510+01:00 wendy >> kernel: [ 35.914169] usb 4-2: new full-speed USB device number 4 using >> uhci_hcd 2014-11-23T19:43:06.088518+01:00 wendy kernel: [ 36.042935] >> usb 4-2: config index 0 descriptor too short (expected 9, got 2) >> 2014-11-23T19:43:06.088526+01:00 wendy kernel: [ 36.042944] usb 4-2: >> can't read configurations, error -22 >> I had similar problem. The only thing that made it work was shutdown the computer, unplug it wait 5-10 minutes,plug in turn on computer and everything worked, go figure -- Life is endless possibilities -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Am 28.11.2014 um 11:11 schrieb toganm@opensuse.org:
"Torsten" == Torsten Duwe <duwe@suse.de> writes:
>> >> something strange happens: 2014-11-23T19:43:06.088510+01:00 wendy >> kernel: [ 35.914169] usb 4-2: new full-speed USB device number 4 using >> uhci_hcd 2014-11-23T19:43:06.088518+01:00 wendy kernel: [ 36.042935] >> usb 4-2: config index 0 descriptor too short (expected 9, got 2) >> 2014-11-23T19:43:06.088526+01:00 wendy kernel: [ 36.042944] usb 4-2: >> can't read configurations, error -22 >>
I had similar problem. The only thing that made it work was shutdown the computer, unplug it wait 5-10 minutes,plug in turn on computer and everything worked, go figure
In the case of this Midiman keyboard, it needs a firmware upload after "cold boot". My guess is, that this sometimes is a bit flaky and only works on second try. I do not think that this has anything to do with the other problem of the continuous stream of usb errors and the recently occuring panic messages afterwards. I did think about the possibility of the keyboard being in a bad state and did unplug and replug it, but it did not change anything. I'll try the boot option (Oliver) and the patch (Takashi), but will probably only get to it on the weekend (after all, it's my daughter's PC and you should not disturb teenage girl's operations if you don't want to get into big trouble :-) Thanks! seife -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
On Fri, 2014-11-28 at 10:54 +0100, Torsten Duwe wrote:
On Sun, Nov 23, 2014 at 10:27:40PM +0100, Stefan Seyfried wrote:
Hi all,
I know this is for upstream. But 3.16 ist old, so nobody will care and additionally I know that both sound and USB maintainers are reading this list, this is why I come here :-)
My daughters machine got updated to 13.2.
Which architecture? This setup suggests some Pi ;-)
2014-11-21T17:50:56.288141+01:00 wendy kernel: [29825.480162] usbcore: registered new interface driver snd-usb-audio
My first guess is that this is the problem.
This works well. However, She quickly got the following backtraces: 2014-11-21T17:51:08.319396+01:00 wendy kernel: [29837.511069] URB ef705c40 submitted while active
[...]
2014-11-21T17:51:08.319695+01:00 wendy kernel: [29837.511676] timer: snd_usbmidi_error_timer+0x0/0xa0 [snd_usbmidi_lib] preempt leak: 00000101 -> 00000102
After reboot, the module was loaded during boot, same procedure:
something strange happens: 2014-11-23T19:43:06.088510+01:00 wendy kernel: [ 35.914169] usb 4-2: new full-speed USB device number 4 using uhci_hcd 2014-11-23T19:43:06.088518+01:00 wendy kernel: [ 36.042935] usb 4-2: config index 0 descriptor too short (expected 9, got 2) 2014-11-23T19:43:06.088526+01:00 wendy kernel: [ 36.042944] usb 4-2: can't read configurations, error -22
What did I already try? * update to 3.17.x from Kernel:stable * downgrade to 3.10.x from 13.1
Both show the same "usb_submit_urb: -16" flood. I did not try long enough to panic the box. My daughter suggested that the panic does happen when she starts playing with the special MIDI functions of the keyboard. I don't know if that's true or if the two panics today are just bad luck.
Grepping through the archived syslog seems to suggest that it happened first on March 23 2014, with 13.1 kernel 3.11.10
Works fine here, 13.2, 3.16.6-2-desktop #1 SMP PREEMPT Mon Oct 20 13:47:22 UTC 2014 (feb42ea) x86_64 [ 2.711503] usb 3-1: new full-speed USB device number 2 using xhci_hcd [ 2.864383] usb 3-1: New USB device found, idVendor=1a86, idProduct=752d [ 2.864387] usb 3-1: New USB device strings: Mfr=0, Product=2, SerialNumber=0 [ 2.864389] usb 3-1: Product: USB2.0-MIDI
But it's a MIDI-_only_ adaptor, cheap LogiLink idVendor 0x1a86 QinHeng Electronics idProduct 0x752d CH345 MIDI adapter bcdDevice 2.54 iManufacturer 0 iProduct 2 USB2.0-MIDI
Maybe the kernel messes up the endpoint configuration, seeing the additional audio device?
Sorry, that's all I can contribute for now.
Please try usbcore.old_scheme_first=1 and provide "lsusb -v" Reagrds Oliver -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Am 28.11.2014 um 12:01 schrieb Oliver Neukum:
Please try usbcore.old_scheme_first=1
this did not change anything to the better, now after the "submitted URB while active" warning / backtrace I got an additional [ 119.616525] WARNING: CPU: 1 PID: 1692 at ../kernel/timer.c:1147 call_timer_fn+0x115/0x130() [ 119.616534] timer: snd_usbmidi_error_timer+0x0/0xa0 [snd_usbmidi_lib] preempt leak: 00000100 -> 00000101 But Takashi's patch did help so this is probably not that important anymore :)
and provide "lsusb -v"
Bus 004 Device 005: ID 0763:1015 Midiman M-Audio Keystation Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 1.00 bDeviceClass 0 (Defined at Interface level) bDeviceSubClass 0 bDeviceProtocol 0 bMaxPacketSize0 64 idVendor 0x0763 Midiman idProduct 0x1015 M-Audio Keystation bcdDevice 1.21 iManufacturer 0 iProduct 0 iSerial 0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 39 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xa0 (Bus Powered) Remote Wakeup MaxPower 0mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 3 bInterfaceClass 255 Vendor Specific Class bInterfaceSubClass 0 bInterfaceProtocol 0 iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0020 1x 32 bytes bInterval 1 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x82 EP 2 IN bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0020 1x 32 bytes bInterval 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x02 EP 2 OUT bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0020 1x 32 bytes bInterval 0 Device Status: 0x0000 (Bus Powered) (in case this is still of interest :) Best regards, Stefan -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Hello, One thing I noticed was to using a usb mouse was to click both mouse buttons and move the scroll wheel around just the kernel boot sequence started. Result was the kernel did not crash -system was useable. If I did NOT click both buttons and move the scroll wheel around the kernel would stack dump and crash. Just my 2 cents worth. --Glenn # uname -a Linux test.site 3.10.1-3.g0cd5432-desktop #1 SMP PREEMPT Fri Jul 19 14:39:31 UTC 2013 (0cd5432) x86_64 x86_64 x86_64 GNU/Linux -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
At Sun, 23 Nov 2014 22:27:40 +0100, Stefan Seyfried wrote:
Hi all,
I know this is for upstream. But 3.16 ist old, so nobody will care and additionally I know that both sound and USB maintainers are reading this list, this is why I come here :-)
My daughters machine got updated to 13.2. She has a "Midiman M-Audio Keystation USB 49" keyboard. I have the following script to use the box as cheap synthesizer: --- #!/bin/sh trap 'killall -9 timidity; pasuspender /bin/true' 0 killall -9 timidity export TIMIDITY_PCM_NAME=sysdefault ( pasuspender -- timidity -Os -A250a -s 44100 -iA -B1,1 )& sleep 2; aconnect 20:0 128:0 sleep 1 echo "Enter zum beenden..." read x killall timidity ---
Plug in keyboard in "boot" mode:
2014-11-21T17:50:47.095100+01:00 wendy kernel: [29816.287121] usb 4-2: new full-speed USB device number 3 using uhci_hcd 2014-11-21T17:50:47.244111+01:00 wendy kernel: [29816.436861] usb 4-2: New USB device found, idVendor=0763, idProduct=1014 2014-11-21T17:50:47.244165+01:00 wendy kernel: [29816.436871] usb 4-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
...firmware is uploaded...
2014-11-21T17:50:54.058158+01:00 wendy kernel: [29823.250222] usb 4-2: USB disconnect, device number 3 2014-11-21T17:50:55.014085+01:00 wendy kernel: [29824.206153] usb 4-2: new full-speed USB device number 4 using uhci_hcd 2014-11-21T17:50:55.146113+01:00 wendy kernel: [29824.338789] usb 4-2: New USB device found, idVendor=0763, idProduct=1015 2014-11-21T17:50:55.146163+01:00 wendy kernel: [29824.338804] usb 4-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
... device get's new USB is an dis usable.
2014-11-21T17:50:56.288141+01:00 wendy kernel: [29825.480162] usbcore: registered new interface driver snd-usb-audio
This works well. However, She quickly got the following backtraces:
2014-11-21T17:51:08.319339+01:00 wendy kernel: [29837.511023] ------------[ cut here ]------------ 2014-11-21T17:51:08.319386+01:00 wendy kernel: [29837.511061] WARNING: CPU: 0 PID: 0 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() 2014-11-21T17:51:08.319396+01:00 wendy kernel: [29837.511069] URB ef705c40 submitted while active 2014-11-21T17:51:08.319410+01:00 wendy kernel: [29837.511074] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hrtimer snd_usb_audio snd_usbmidi_lib snd_rawmidi nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device r8169 snd_timer snd_mixer_oss snd mii iTCO_wdt iTCO_vendor_support ppdev parport_pc shpchp parport gpio_ich ite_cir rc_core lpc_ich mfd_core soundcore coretemp i2c_i801 serio_raw pcspkr tpm_infineon tpm_tis tpm dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg 2014-11-21T17:51:08.319420+01:00 wendy kernel: [29837.511209] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.6-2-desktop #1 2014-11-21T17:51:08.319429+01:00 wendy kernel: [29837.511215] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 2014-11-21T17:51:08.319436+01:00 wendy kernel: [29837.511221] c0984bfa f4009ed4 c078deaf f4009ee4 c024c884 c09a135c f4009f00 00000000 2014-11-21T17:51:08.319444+01:00 wendy kernel: [29837.511234] c0984bfa 00000153 c061ac4f c061ac4f 00000009 00000001 ef705c40 e854d1c0 2014-11-21T17:51:08.319451+01:00 wendy kernel: [29837.511247] f4009eec c024c8d3 00000009 f4009ee4 c09a135c f4009f00 f4009f04 c061ac4f 2014-11-21T17:51:08.319459+01:00 wendy kernel: [29837.511259] Call Trace: 2014-11-21T17:51:08.319466+01:00 wendy kernel: [29837.511283] [<c0205df6>] try_stack_unwind+0x156/0x170 2014-11-21T17:51:08.319474+01:00 wendy kernel: [29837.511303] [<c020482a>] dump_trace+0x5a/0x1b0 2014-11-21T17:51:08.319483+01:00 wendy kernel: [29837.511315] [<c0205e56>] show_trace_log_lvl+0x46/0x50 2014-11-21T17:51:08.319490+01:00 wendy kernel: [29837.511327] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 2014-11-21T17:51:08.319499+01:00 wendy kernel: [29837.511338] [<c0205eb7>] show_stack+0x27/0x50 2014-11-21T17:51:08.319507+01:00 wendy kernel: [29837.511350] [<c078deaf>] dump_stack+0x45/0x65 2014-11-21T17:51:08.319514+01:00 wendy kernel: [29837.511369] [<c024c884>] warn_slowpath_common+0x84/0xa0 2014-11-21T17:51:08.319523+01:00 wendy kernel: [29837.511381] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 2014-11-21T17:51:08.319531+01:00 wendy kernel: [29837.511393] [<c061ac4f>] usb_submit_urb+0x5f/0x70 2014-11-21T17:51:08.319539+01:00 wendy kernel: [29837.511415] [<f7974104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] 2014-11-21T17:51:08.319546+01:00 wendy kernel: [29837.511441] [<f797483a>] snd_usbmidi_error_timer+0x6a/0xa0 [snd_usbmidi_lib] 2014-11-21T17:51:08.319555+01:00 wendy kernel: [29837.511456] [<c02570c0>] call_timer_fn+0x30/0x130 2014-11-21T17:51:08.319563+01:00 wendy kernel: [29837.511468] [<c0257442>] run_timer_softirq+0x1c2/0x260 2014-11-21T17:51:08.319571+01:00 wendy kernel: [29837.511483] [<c0251493>] __do_softirq+0xc3/0x270 2014-11-21T17:51:08.319578+01:00 wendy kernel: [29837.511494] [<c0204732>] do_softirq_own_stack+0x22/0x30 2014-11-21T17:51:08.319585+01:00 wendy kernel: [29837.511505] [<c025186d>] irq_exit+0x8d/0xa0 2014-11-21T17:51:08.319591+01:00 wendy kernel: [29837.511520] [<c0795228>] smp_apic_timer_interrupt+0x38/0x50 2014-11-21T17:51:08.319598+01:00 wendy kernel: [29837.511533] [<c0794a3c>] apic_timer_interrupt+0x34/0x3c 2014-11-21T17:51:08.319605+01:00 wendy kernel: [29837.511550] [<c0673d9e>] cpuidle_enter_state+0x3e/0xd0 2014-11-21T17:51:08.319612+01:00 wendy kernel: [29837.511563] [<c028bb8d>] cpu_idle_loop+0x29d/0x3e0 2014-11-21T17:51:08.319619+01:00 wendy kernel: [29837.511575] [<c028bd23>] cpu_startup_entry+0x53/0x60 2014-11-21T17:51:08.319625+01:00 wendy kernel: [29837.511589] [<c0bfac1e>] start_kernel+0x415/0x41a 2014-11-21T17:51:08.319632+01:00 wendy kernel: [29837.511598] ---[ end trace f8fefbc2e004204d ]--- 2014-11-21T17:51:08.319639+01:00 wendy kernel: [29837.511609] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319646+01:00 wendy kernel: [29837.511616] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319653+01:00 wendy kernel: [29837.511622] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319659+01:00 wendy kernel: [29837.511636] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319665+01:00 wendy kernel: [29837.511643] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319673+01:00 wendy kernel: [29837.511650] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.319680+01:00 wendy kernel: [29837.511656] ------------[ cut here ]------------ 2014-11-21T17:51:08.319688+01:00 wendy kernel: [29837.511665] WARNING: CPU: 0 PID: 0 at ../kernel/timer.c:1147 call_timer_fn+0x115/0x130() 2014-11-21T17:51:08.319695+01:00 wendy kernel: [29837.511676] timer: snd_usbmidi_error_timer+0x0/0xa0 [snd_usbmidi_lib] preempt leak: 00000101 -> 00000102 2014-11-21T17:51:08.319704+01:00 wendy kernel: [29837.511680] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hrtimer snd_usb_audio snd_usbmidi_lib snd_rawmidi nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device r8169 snd_timer snd_mixer_oss snd mii iTCO_wdt iTCO_vendor_support ppdev parport_pc shpchp parport gpio_ich ite_cir rc_core lpc_ich mfd_core soundcore coretemp i2c_i801 serio_raw pcspkr tpm_infineon tpm_tis tpm dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg 2014-11-21T17:51:08.319713+01:00 wendy kernel: [29837.511782] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W 3.16.6-2-desktop #1 2014-11-21T17:51:08.319719+01:00 wendy kernel: [29837.511787] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 2014-11-21T17:51:08.319727+01:00 wendy kernel: [29837.511792] c0940e36 f4009f28 c078deaf f4009f38 c024c884 c0936590 f4009f54 00000000 2014-11-21T17:51:08.319735+01:00 wendy kernel: [29837.511805] c0940e36 0000047b c02571a5 c02571a5 00000009 f4009f9c e854d1e0 00000101 2014-11-21T17:51:08.319745+01:00 wendy kernel: [29837.511818] f4009f40 c024c8d3 00000009 f4009f38 c0936590 f4009f54 f4009f74 c02571a5 2014-11-21T17:51:08.319754+01:00 wendy kernel: [29837.511830] Call Trace: 2014-11-21T17:51:08.319763+01:00 wendy kernel: [29837.511843] [<c0205df6>] try_stack_unwind+0x156/0x170 2014-11-21T17:51:08.319771+01:00 wendy kernel: [29837.511862] [<c020482a>] dump_trace+0x5a/0x1b0 2014-11-21T17:51:08.319778+01:00 wendy kernel: [29837.511873] [<c0205e56>] show_trace_log_lvl+0x46/0x50 2014-11-21T17:51:08.319786+01:00 wendy kernel: [29837.511885] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 2014-11-21T17:51:08.319795+01:00 wendy kernel: [29837.511896] [<c0205eb7>] show_stack+0x27/0x50 2014-11-21T17:51:08.319804+01:00 wendy kernel: [29837.511907] [<c078deaf>] dump_stack+0x45/0x65 2014-11-21T17:51:08.319813+01:00 wendy kernel: [29837.511918] [<c024c884>] warn_slowpath_common+0x84/0xa0 2014-11-21T17:51:08.319823+01:00 wendy kernel: [29837.511930] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 2014-11-21T17:51:08.319874+01:00 wendy kernel: [29837.511941] [<c02571a5>] call_timer_fn+0x115/0x130 2014-11-21T17:51:08.319883+01:00 wendy kernel: [29837.511954] [<c0257442>] run_timer_softirq+0x1c2/0x260 2014-11-21T17:51:08.319892+01:00 wendy kernel: [29837.511968] [<c0251493>] __do_softirq+0xc3/0x270 2014-11-21T17:51:08.319900+01:00 wendy kernel: [29837.511979] [<c0204732>] do_softirq_own_stack+0x22/0x30 2014-11-21T17:51:08.319908+01:00 wendy kernel: [29837.511990] [<c025186d>] irq_exit+0x8d/0xa0 2014-11-21T17:51:08.319916+01:00 wendy kernel: [29837.512021] [<c0795228>] smp_apic_timer_interrupt+0x38/0x50 2014-11-21T17:51:08.319924+01:00 wendy kernel: [29837.512034] [<c0794a3c>] apic_timer_interrupt+0x34/0x3c 2014-11-21T17:51:08.319932+01:00 wendy kernel: [29837.512047] [<c0673d9e>] cpuidle_enter_state+0x3e/0xd0 2014-11-21T17:51:08.319940+01:00 wendy kernel: [29837.512059] [<c028bb8d>] cpu_idle_loop+0x29d/0x3e0 2014-11-21T17:51:08.319949+01:00 wendy kernel: [29837.512070] [<c028bd23>] cpu_startup_entry+0x53/0x60 2014-11-21T17:51:08.319957+01:00 wendy kernel: [29837.512082] [<c0bfac1e>] start_kernel+0x415/0x41a 2014-11-21T17:51:08.319965+01:00 wendy kernel: [29837.512091] ---[ end trace f8fefbc2e004204e ]--- 2014-11-21T17:51:08.685138+01:00 wendy kernel: [29837.878046] usb 4-2: usb_submit_urb: -16 2014-11-21T17:51:08.685183+01:00 wendy kernel: [29837.878078] usb 4-2: usb_submit_urb: -16
the usb_submit_urb goes on and on until today, over several suspend to RAM cycles. The keyboard did still work. Until the machine finally panicked today 19:40+01:00.
After reboot, the module was loaded during boot, same procedure:
2014-11-23T19:43:06.088478+01:00 wendy kernel: [ 27.562444] usb 4-2: new full-speed USB device number 3 using uhci_hcd 2014-11-23T19:43:06.088486+01:00 wendy kernel: [ 27.698944] usb 4-2: New USB device found, idVendor=0763, idProduct=1014 2014-11-23T19:43:06.088494+01:00 wendy kernel: [ 27.698954] usb 4-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0 2014-11-23T19:43:06.088502+01:00 wendy kernel: [ 34.954224] usb 4-2: USB disconnect, device number 3
something strange happens: 2014-11-23T19:43:06.088510+01:00 wendy kernel: [ 35.914169] usb 4-2: new full-speed USB device number 4 using uhci_hcd 2014-11-23T19:43:06.088518+01:00 wendy kernel: [ 36.042935] usb 4-2: config index 0 descriptor too short (expected 9, got 2) 2014-11-23T19:43:06.088526+01:00 wendy kernel: [ 36.042944] usb 4-2: can't read configurations, error -22
...but the device appears finally: 2014-11-23T19:43:06.088549+01:00 wendy kernel: [ 36.146573] usb 4-2: new full-speed USB device number 5 using uhci_hcd 2014-11-23T19:43:06.088559+01:00 wendy kernel: [ 36.279939] usb 4-2: New USB device found, idVendor=0763, idProduct=1015 2014-11-23T19:43:06.088567+01:00 wendy kernel: [ 36.279948] usb 4-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0 2014-11-23T19:43:06.088593+01:00 wendy kernel: [ 37.406602] usbcore: registered new interface driver snd-usb-audio
then again: 2014-11-23T19:44:17.179668+01:00 wendy kernel: [ 108.594035] ------------[ cut here ]------------ 2014-11-23T19:44:17.179728+01:00 wendy kernel: [ 108.594078] WARNING: CPU: 1 PID: 0 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() 2014-11-23T19:44:17.179739+01:00 wendy kernel: [ 108.594088] URB f6bcd700 submitted while active 2014-11-23T19:44:17.179785+01:00 wendy kernel: [ 108.594094] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_hda_codec_realtek snd_hda_codec_generic gpio_ich iTCO_wdt iTCO_vendor_support snd_hda_intel snd_hda_controller snd_hda_codec ppdev snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss coretemp serio_raw pcspkr i2c_i801 snd lpc_ich mfd_core r8169 mii shpchp soundcore parport_pc parport ite_cir rc_core tpm_infineon tpm_tis tpm dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg 2014-11-23T19:44:17.179796+01:00 wendy kernel: [ 108.594249] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 3.16.6-2-desktop #1 2014-11-23T19:44:17.179805+01:00 wendy kernel: [ 108.594266] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 2014-11-23T19:44:17.179814+01:00 wendy kernel: [ 108.594275] c0984bfa f416ded4 c078deaf f416dee4 c024c884 c09a135c f416df00 00000000 2014-11-23T19:44:17.179822+01:00 wendy kernel: [ 108.594293] c0984bfa 00000153 c061ac4f c061ac4f 00000009 00000002 f6bcd700 f6bcd040 2014-11-23T19:44:17.179831+01:00 wendy kernel: [ 108.594311] f416deec c024c8d3 00000009 f416dee4 c09a135c f416df00 f416df04 c061ac4f 2014-11-23T19:44:17.179839+01:00 wendy kernel: [ 108.594329] Call Trace: 2014-11-23T19:44:17.179847+01:00 wendy kernel: [ 108.594361] [<c0205df6>] try_stack_unwind+0x156/0x170 2014-11-23T19:44:17.179855+01:00 wendy kernel: [ 108.594391] [<c020482a>] dump_trace+0x5a/0x1b0 2014-11-23T19:44:17.179863+01:00 wendy kernel: [ 108.594412] [<c0205e56>] show_trace_log_lvl+0x46/0x50 2014-11-23T19:44:17.179871+01:00 wendy kernel: [ 108.594430] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 2014-11-23T19:44:17.179879+01:00 wendy kernel: [ 108.594448] [<c0205eb7>] show_stack+0x27/0x50 2014-11-23T19:44:17.179888+01:00 wendy kernel: [ 108.594466] [<c078deaf>] dump_stack+0x45/0x65 2014-11-23T19:44:17.179896+01:00 wendy kernel: [ 108.594486] [<c024c884>] warn_slowpath_common+0x84/0xa0 2014-11-23T19:44:17.179904+01:00 wendy kernel: [ 108.594503] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 2014-11-23T19:44:17.179912+01:00 wendy kernel: [ 108.594520] [<c061ac4f>] usb_submit_urb+0x5f/0x70 2014-11-23T19:44:17.179921+01:00 wendy kernel: [ 108.594554] [<f76eb104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] 2014-11-23T19:44:17.179928+01:00 wendy kernel: [ 108.594587] [<f76eb83a>] snd_usbmidi_error_timer+0x6a/0xa0 [snd_usbmidi_lib] 2014-11-23T19:44:17.179937+01:00 wendy kernel: [ 108.594611] [<c02570c0>] call_timer_fn+0x30/0x130 2014-11-23T19:44:17.179944+01:00 wendy kernel: [ 108.594631] [<c0257442>] run_timer_softirq+0x1c2/0x260 2014-11-23T19:44:17.179953+01:00 wendy kernel: [ 108.594655] [<c0251493>] __do_softirq+0xc3/0x270 2014-11-23T19:44:17.179960+01:00 wendy kernel: [ 108.594673] [<c0204732>] do_softirq_own_stack+0x22/0x30 2014-11-23T19:44:17.179968+01:00 wendy kernel: [ 108.594690] [<c025186d>] irq_exit+0x8d/0xa0 2014-11-23T19:44:17.179976+01:00 wendy kernel: [ 108.594713] [<c0795228>] smp_apic_timer_interrupt+0x38/0x50 2014-11-23T19:44:17.179984+01:00 wendy kernel: [ 108.594732] [<c0794a3c>] apic_timer_interrupt+0x34/0x3c 2014-11-23T19:44:17.180003+01:00 wendy kernel: [ 108.594751] [<c0673d9e>] cpuidle_enter_state+0x3e/0xd0 2014-11-23T19:44:17.180011+01:00 wendy kernel: [ 108.594770] [<c028bb8d>] cpu_idle_loop+0x29d/0x3e0 2014-11-23T19:44:17.180020+01:00 wendy kernel: [ 108.594787] [<c028bd23>] cpu_startup_entry+0x53/0x60 2014-11-23T19:44:17.180028+01:00 wendy kernel: [ 108.594818] [<c0230bdf>] start_secondary+0x20f/0x2e0 2014-11-23T19:44:17.180036+01:00 wendy kernel: [ 108.594833] ---[ end trace 952a2543044934e8 ]--- 2014-11-23T19:44:17.180044+01:00 wendy kernel: [ 108.594848] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180052+01:00 wendy kernel: [ 108.594867] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180060+01:00 wendy kernel: [ 108.594877] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180067+01:00 wendy kernel: [ 108.594888] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180075+01:00 wendy kernel: [ 108.594898] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180083+01:00 wendy kernel: [ 108.594908] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.180091+01:00 wendy kernel: [ 108.594917] ------------[ cut here ]------------ 2014-11-23T19:44:17.180099+01:00 wendy kernel: [ 108.594930] WARNING: CPU: 1 PID: 0 at ../kernel/timer.c:1147 call_timer_fn+0x115/0x130() 2014-11-23T19:44:17.180107+01:00 wendy kernel: [ 108.594947] timer: snd_usbmidi_error_timer+0x0/0xa0 [snd_usbmidi_lib] preempt leak: 00000101 -> 00000102 2014-11-23T19:44:17.180117+01:00 wendy kernel: [ 108.594954] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_hda_codec_realtek snd_hda_codec_generic gpio_ich iTCO_wdt iTCO_vendor_support snd_hda_intel snd_hda_controller snd_hda_codec ppdev snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss coretemp serio_raw pcspkr i2c_i801 snd lpc_ich mfd_core r8169 mii shpchp soundcore parport_pc parport ite_cir rc_core tpm_infineon tpm_tis tpm dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg 2014-11-23T19:44:17.180126+01:00 wendy kernel: [ 108.595119] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G W 3.16.6-2-desktop #1 2014-11-23T19:44:17.180135+01:00 wendy kernel: [ 108.595129] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 2014-11-23T19:44:17.180142+01:00 wendy kernel: [ 108.595137] c0940e36 f416df28 c078deaf f416df38 c024c884 c0936590 f416df54 00000000 2014-11-23T19:44:17.180151+01:00 wendy kernel: [ 108.595156] c0940e36 0000047b c02571a5 c02571a5 00000009 f416df9c f6bcd060 00000101 2014-11-23T19:44:17.180158+01:00 wendy kernel: [ 108.595175] f416df40 c024c8d3 00000009 f416df38 c0936590 f416df54 f416df74 c02571a5 2014-11-23T19:44:17.180166+01:00 wendy kernel: [ 108.595195] Call Trace: 2014-11-23T19:44:17.180174+01:00 wendy kernel: [ 108.595221] [<c0205df6>] try_stack_unwind+0x156/0x170 2014-11-23T19:44:17.180181+01:00 wendy kernel: [ 108.595250] [<c020482a>] dump_trace+0x5a/0x1b0 2014-11-23T19:44:17.180189+01:00 wendy kernel: [ 108.595279] [<c0205e56>] show_trace_log_lvl+0x46/0x50 2014-11-23T19:44:17.180196+01:00 wendy kernel: [ 108.595298] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 2014-11-23T19:44:17.180205+01:00 wendy kernel: [ 108.595315] [<c0205eb7>] show_stack+0x27/0x50 2014-11-23T19:44:17.180212+01:00 wendy kernel: [ 108.595333] [<c078deaf>] dump_stack+0x45/0x65 2014-11-23T19:44:17.180219+01:00 wendy kernel: [ 108.595354] [<c024c884>] warn_slowpath_common+0x84/0xa0 2014-11-23T19:44:17.180227+01:00 wendy kernel: [ 108.595373] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 2014-11-23T19:44:17.180235+01:00 wendy kernel: [ 108.595391] [<c02571a5>] call_timer_fn+0x115/0x130 2014-11-23T19:44:17.180243+01:00 wendy kernel: [ 108.595411] [<c0257442>] run_timer_softirq+0x1c2/0x260 2014-11-23T19:44:17.180250+01:00 wendy kernel: [ 108.595434] [<c0251493>] __do_softirq+0xc3/0x270 2014-11-23T19:44:17.180258+01:00 wendy kernel: [ 108.595452] [<c0204732>] do_softirq_own_stack+0x22/0x30 2014-11-23T19:44:17.180266+01:00 wendy kernel: [ 108.595469] [<c025186d>] irq_exit+0x8d/0xa0 2014-11-23T19:44:17.180275+01:00 wendy kernel: [ 108.595491] [<c0795228>] smp_apic_timer_interrupt+0x38/0x50 2014-11-23T19:44:17.180282+01:00 wendy kernel: [ 108.595510] [<c0794a3c>] apic_timer_interrupt+0x34/0x3c 2014-11-23T19:44:17.180291+01:00 wendy kernel: [ 108.595532] [<c0673d9e>] cpuidle_enter_state+0x3e/0xd0 2014-11-23T19:44:17.180298+01:00 wendy kernel: [ 108.595551] [<c028bb8d>] cpu_idle_loop+0x29d/0x3e0 2014-11-23T19:44:17.180307+01:00 wendy kernel: [ 108.595570] [<c028bd23>] cpu_startup_entry+0x53/0x60 2014-11-23T19:44:17.180314+01:00 wendy kernel: [ 108.595588] [<c0230bdf>] start_secondary+0x20f/0x2e0 2014-11-23T19:44:17.180323+01:00 wendy kernel: [ 108.595604] ---[ end trace 952a2543044934e9 ]--- 2014-11-23T19:44:17.767840+01:00 wendy kernel: [ 109.183061] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.767889+01:00 wendy kernel: [ 109.183070] usb 4-2: usb_submit_urb: -16 2014-11-23T19:44:17.767899+01:00 wendy kernel: [ 109.183076] usb 4-2: usb_submit_urb: -16
.... on and on, until panic at 20:04 local time.
My daughter took a picture of the second panic (but I don't know how good the quality is and if we can see anything on it)
What did I already try? * update to 3.17.x from Kernel:stable * downgrade to 3.10.x from 13.1
Both show the same "usb_submit_urb: -16" flood. I did not try long enough to panic the box. My daughter suggested that the panic does happen when she starts playing with the special MIDI functions of the keyboard. I don't know if that's true or if the two panics today are just bad luck.
Grepping through the archived syslog seems to suggest that it happened first on March 23 2014, with 13.1 kernel 3.11.10
With 3.11.10, there is only one call trace from [ 135.889057] WARNING: CPU: 3 PID: 1756 at /home/abuild/rpmbuild/BUILD/kernel-desktop-3.11.10/linux-3.11/drivers/usb/core/urb.c:327 usb_submit_urb+0x3a4/0x3c0() [ 135.889061] URB f3f710c0 submitted while active
And the message is slightly different: [ 135.889439] ALSA midi.c:194 usb_submit_urb: -16
Going further back through the logs would suggest this started with 13.1, 12.3 (kernel 3.7) seems to have worked fine. OTOH the MIDI keyboard is only used once in a while, so this might not be true.
Anything more you need from me? (and *please* don't say "git bisect" :-))
This is a code path for the error recovery, so something went already wrong in the USB side, supposedly. In anyway, could you try the patch below? The problem after reboot isn't cured by that, though. It's the hardware issue, somehow it's screwed up. You'd need to do some hard reset. Takashi --- diff --git a/sound/usb/midi.c b/sound/usb/midi.c index d3d49525a16b..b604760cb7f0 100644 --- a/sound/usb/midi.c +++ b/sound/usb/midi.c @@ -353,11 +353,12 @@ static void snd_usbmidi_out_tasklet(unsigned long data) static void snd_usbmidi_error_timer(unsigned long data) { struct snd_usb_midi *umidi = (struct snd_usb_midi *)data; + unsigned long flags; unsigned int i, j; - spin_lock(&umidi->disc_lock); + spin_lock_irqsave(&umidi->disc_lock, flags); if (umidi->disconnected) { - spin_unlock(&umidi->disc_lock); + spin_unlock_irqrestore(&umidi->disc_lock, flags); return; } for (i = 0; i < MIDI_MAX_ENDPOINTS; ++i) { @@ -365,6 +366,8 @@ static void snd_usbmidi_error_timer(unsigned long data) if (in && in->error_resubmit) { in->error_resubmit = 0; for (j = 0; j < INPUT_URBS; ++j) { + if (atomic_read(&in->urbs[j]->use_count)) + continue; in->urbs[j]->dev = umidi->dev; snd_usbmidi_submit_urb(in->urbs[j], GFP_ATOMIC); } @@ -372,7 +375,7 @@ static void snd_usbmidi_error_timer(unsigned long data) if (umidi->endpoints[i].out) snd_usbmidi_do_output(umidi->endpoints[i].out); } - spin_unlock(&umidi->disc_lock); + spin_unlock_irqrestore(&umidi->disc_lock, flags); } /* helper function to send static data that may not DMA-able */ -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Hi Takashi, Am 28.11.2014 um 12:33 schrieb Takashi Iwai:
This is a code path for the error recovery, so something went already wrong in the USB side, supposedly. In anyway, could you try the patch below?
Yes, and it helps!
The problem after reboot isn't cured by that, though. It's the hardware issue, somehow it's screwed up. You'd need to do some hard reset.
Sometimes the device just needs a second try to initialize after it got the firmware uploaded. I don't think this is related to this problem. It sometimes happens and sometimes it just works on first try.
Takashi
--- diff --git a/sound/usb/midi.c b/sound/usb/midi.c index d3d49525a16b..b604760cb7f0 100644 --- a/sound/usb/midi.c +++ b/sound/usb/midi.c @@ -353,11 +353,12 @@ static void snd_usbmidi_out_tasklet(unsigned long data) static void snd_usbmidi_error_timer(unsigned long data) { struct snd_usb_midi *umidi = (struct snd_usb_midi *)data; + unsigned long flags; unsigned int i, j;
- spin_lock(&umidi->disc_lock); + spin_lock_irqsave(&umidi->disc_lock, flags); if (umidi->disconnected) { - spin_unlock(&umidi->disc_lock); + spin_unlock_irqrestore(&umidi->disc_lock, flags); return; } for (i = 0; i < MIDI_MAX_ENDPOINTS; ++i) { @@ -365,6 +366,8 @@ static void snd_usbmidi_error_timer(unsigned long data) if (in && in->error_resubmit) { in->error_resubmit = 0; for (j = 0; j < INPUT_URBS; ++j) { + if (atomic_read(&in->urbs[j]->use_count)) + continue; in->urbs[j]->dev = umidi->dev; snd_usbmidi_submit_urb(in->urbs[j], GFP_ATOMIC); } @@ -372,7 +375,7 @@ static void snd_usbmidi_error_timer(unsigned long data) if (umidi->endpoints[i].out) snd_usbmidi_do_output(umidi->endpoints[i].out); } - spin_unlock(&umidi->disc_lock); + spin_unlock_irqrestore(&umidi->disc_lock, flags); }
/* helper function to send static data that may not DMA-able */
No URB errors anymore and no problems. I got one last usb urb message: [ 722.200526] usbcore: deregistering interface driver snd-usb-audio [ 873.469207] usbcore: registered new interface driver snd-usb-audio [ 954.790601] usb 4-2: urb status -75 But that was after running the unpatched module (with errors already triggered), unloading the unpatched module, loading the patched module and then starting to play. It is very well possible that the hardware (or USB stack) was confused by then. After rebooting, no URB messages are seen: wendy:~ # dmesg|grep -i usb.*status wendy:~ # dmesg|grep -i urb wendy:~ # So the Patch is Tested-By: Stefan Seyfried <stefan.seyfried@googlemail.com> :-) Best regards, Stefan -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
At Sat, 06 Dec 2014 15:36:29 +0100, Stefan Seyfried wrote:
Hi Takashi,
Am 28.11.2014 um 12:33 schrieb Takashi Iwai:
This is a code path for the error recovery, so something went already wrong in the USB side, supposedly. In anyway, could you try the patch below?
Yes, and it helps!
The problem after reboot isn't cured by that, though. It's the hardware issue, somehow it's screwed up. You'd need to do some hard reset.
Sometimes the device just needs a second try to initialize after it got the firmware uploaded. I don't think this is related to this problem. It sometimes happens and sometimes it just works on first try.
Takashi
--- diff --git a/sound/usb/midi.c b/sound/usb/midi.c index d3d49525a16b..b604760cb7f0 100644 --- a/sound/usb/midi.c +++ b/sound/usb/midi.c @@ -353,11 +353,12 @@ static void snd_usbmidi_out_tasklet(unsigned long data) static void snd_usbmidi_error_timer(unsigned long data) { struct snd_usb_midi *umidi = (struct snd_usb_midi *)data; + unsigned long flags; unsigned int i, j;
- spin_lock(&umidi->disc_lock); + spin_lock_irqsave(&umidi->disc_lock, flags); if (umidi->disconnected) { - spin_unlock(&umidi->disc_lock); + spin_unlock_irqrestore(&umidi->disc_lock, flags); return; } for (i = 0; i < MIDI_MAX_ENDPOINTS; ++i) { @@ -365,6 +366,8 @@ static void snd_usbmidi_error_timer(unsigned long data) if (in && in->error_resubmit) { in->error_resubmit = 0; for (j = 0; j < INPUT_URBS; ++j) { + if (atomic_read(&in->urbs[j]->use_count)) + continue; in->urbs[j]->dev = umidi->dev; snd_usbmidi_submit_urb(in->urbs[j], GFP_ATOMIC); } @@ -372,7 +375,7 @@ static void snd_usbmidi_error_timer(unsigned long data) if (umidi->endpoints[i].out) snd_usbmidi_do_output(umidi->endpoints[i].out); } - spin_unlock(&umidi->disc_lock); + spin_unlock_irqrestore(&umidi->disc_lock, flags); }
/* helper function to send static data that may not DMA-able */
No URB errors anymore and no problems. I got one last usb urb message: [ 722.200526] usbcore: deregistering interface driver snd-usb-audio [ 873.469207] usbcore: registered new interface driver snd-usb-audio [ 954.790601] usb 4-2: urb status -75
But that was after running the unpatched module (with errors already triggered), unloading the unpatched module, loading the patched module and then starting to play. It is very well possible that the hardware (or USB stack) was confused by then.
After rebooting, no URB messages are seen:
wendy:~ # dmesg|grep -i usb.*status wendy:~ # dmesg|grep -i urb wendy:~ #
So the Patch is
Tested-By: Stefan Seyfried <stefan.seyfried@googlemail.com>
Alright, I merged to upstream and also SUSE openSUSE 13.2 and stable branches, too. thanks, Takashi -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Hi Takashi, Am 06.12.2014 um 21:46 schrieb Takashi Iwai:
Alright, I merged to upstream and also SUSE openSUSE 13.2 and stable branches, too.
Thanks, you're awesome as always :-) Also thanks from my daughter :-) Best regards, seife -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Hi Takashi, it looks like more similar bugs are somewhere hidden in the code. Today I saw this on my daughter's box, with the patched snd-usb-audio and snd-usbmidi-lib: [45117.334757] ------------[ cut here ]------------ [45117.334778] WARNING: CPU: 2 PID: 7158 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() [45117.334782] URB e7bc54c0 submitted while active [45117.334786] Modules linked in: snd_seq_midi snd_seq_midi_event snd_usb_audio(O) snd_usbmidi_lib(O) snd_rawmidi snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss snd tpm_infineon tpm_tis soundcore gpio_ich iTCO_wdt iTCO_vendor_support ppdev i2c_i801 tpm coretemp serio_raw pcspkr lpc_ich mfd_core r8169 mii shpchp parport_pc parport ite_cir rc_core dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg [45117.334903] CPU: 2 PID: 7158 Comm: aconnect Tainted: G O 3.16.6-2-desktop #1 [45117.334907] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 [45117.334911] c0984bfa db46dce4 c078deaf db46dcf4 c024c884 c09a135c db46dd10 00001bf6 [45117.334923] c0984bfa 00000153 c061ac4f c061ac4f 00000009 e7bc5f48 e7bc54c0 e7bc5f40 [45117.334935] db46dcfc c024c8d3 00000009 db46dcf4 c09a135c db46dd10 db46dd14 c061ac4f [45117.334947] Call Trace: [45117.334971] [<c0205df6>] try_stack_unwind+0x156/0x170 [45117.334991] [<c020482a>] dump_trace+0x5a/0x1b0 [45117.335001] [<c0205e56>] show_trace_log_lvl+0x46/0x50 [45117.335094] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 [45117.335132] [<c0205eb7>] show_stack+0x27/0x50 [45117.335161] [<c078deaf>] dump_stack+0x45/0x65 [45117.335184] [<c024c884>] warn_slowpath_common+0x84/0xa0 [45117.335199] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 [45117.335213] [<c061ac4f>] usb_submit_urb+0x5f/0x70 [45117.335239] [<f7adf104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] [45117.335274] [<f7adfb0e>] snd_usbmidi_input_start.part.12+0x4e/0x70 [snd_usbmidi_lib] [45117.335303] [<f7ae0a6b>] substream_open.isra.23+0x11b/0x1c0 [snd_usbmidi_lib] [45117.335341] [<f7e3cbba>] open_substream+0xda/0x170 [snd_rawmidi] [45117.335373] [<f7e3d301>] rawmidi_open_priv+0x51/0x110 [snd_rawmidi] [45117.335408] [<f7e3d45e>] snd_rawmidi_kernel_open+0x9e/0x110 [snd_rawmidi] [45117.335459] [<f7c9029a>] midisynth_subscribe+0x3a/0xf0 [snd_seq_midi] [45117.335497] [<f77d19ab>] subscribe_port.isra.1+0x6b/0xc0 [snd_seq] [45117.335578] [<f77d2529>] snd_seq_port_connect+0x159/0x2e0 [snd_seq] [45117.335655] [<f77ce3b4>] snd_seq_ioctl_subscribe_port+0xc4/0x140 [snd_seq] [45117.335703] [<f77cc8dd>] snd_seq_do_ioctl+0x9d/0xe0 [snd_seq] [45117.335740] [<c03965c2>] do_vfs_ioctl+0x2f2/0x4f0 [45117.335781] [<c0396820>] SyS_ioctl+0x60/0x90 [45117.335802] [<c07940c3>] sysenter_do_call+0x12/0x12 [45117.335836] [<b776de4c>] 0xb776de4b [45117.335846] ---[ end trace 63e1175b9ba4593d ]--- Unfortunately, the code is sufficiently complex (for my untrained eye) that I did not dare trying to patch it myself :-) Best regards, seife -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
At Mon, 22 Dec 2014 18:53:43 +0100, Stefan Seyfried wrote:
Hi Takashi,
it looks like more similar bugs are somewhere hidden in the code.
Today I saw this on my daughter's box, with the patched snd-usb-audio and snd-usbmidi-lib:
[45117.334757] ------------[ cut here ]------------ [45117.334778] WARNING: CPU: 2 PID: 7158 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() [45117.334782] URB e7bc54c0 submitted while active [45117.334786] Modules linked in: snd_seq_midi snd_seq_midi_event snd_usb_audio(O) snd_usbmidi_lib(O) snd_rawmidi snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss snd tpm_infineon tpm_tis soundcore gpio_ich iTCO_wdt iTCO_vendor_support ppdev i2c_i801 tpm coretemp serio_raw pcspkr lpc_ich mfd_core r8169 mii shpchp parport_pc parport ite_cir rc_core dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg [45117.334903] CPU: 2 PID: 7158 Comm: aconnect Tainted: G O 3.16.6-2-desktop #1 [45117.334907] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 [45117.334911] c0984bfa db46dce4 c078deaf db46dcf4 c024c884 c09a135c db46dd10 00001bf6 [45117.334923] c0984bfa 00000153 c061ac4f c061ac4f 00000009 e7bc5f48 e7bc54c0 e7bc5f40 [45117.334935] db46dcfc c024c8d3 00000009 db46dcf4 c09a135c db46dd10 db46dd14 c061ac4f [45117.334947] Call Trace: [45117.334971] [<c0205df6>] try_stack_unwind+0x156/0x170 [45117.334991] [<c020482a>] dump_trace+0x5a/0x1b0 [45117.335001] [<c0205e56>] show_trace_log_lvl+0x46/0x50 [45117.335094] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 [45117.335132] [<c0205eb7>] show_stack+0x27/0x50 [45117.335161] [<c078deaf>] dump_stack+0x45/0x65 [45117.335184] [<c024c884>] warn_slowpath_common+0x84/0xa0 [45117.335199] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 [45117.335213] [<c061ac4f>] usb_submit_urb+0x5f/0x70 [45117.335239] [<f7adf104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] [45117.335274] [<f7adfb0e>] snd_usbmidi_input_start.part.12+0x4e/0x70 [snd_usbmidi_lib] [45117.335303] [<f7ae0a6b>] substream_open.isra.23+0x11b/0x1c0 [snd_usbmidi_lib] [45117.335341] [<f7e3cbba>] open_substream+0xda/0x170 [snd_rawmidi] [45117.335373] [<f7e3d301>] rawmidi_open_priv+0x51/0x110 [snd_rawmidi] [45117.335408] [<f7e3d45e>] snd_rawmidi_kernel_open+0x9e/0x110 [snd_rawmidi] [45117.335459] [<f7c9029a>] midisynth_subscribe+0x3a/0xf0 [snd_seq_midi] [45117.335497] [<f77d19ab>] subscribe_port.isra.1+0x6b/0xc0 [snd_seq] [45117.335578] [<f77d2529>] snd_seq_port_connect+0x159/0x2e0 [snd_seq] [45117.335655] [<f77ce3b4>] snd_seq_ioctl_subscribe_port+0xc4/0x140 [snd_seq] [45117.335703] [<f77cc8dd>] snd_seq_do_ioctl+0x9d/0xe0 [snd_seq] [45117.335740] [<c03965c2>] do_vfs_ioctl+0x2f2/0x4f0 [45117.335781] [<c0396820>] SyS_ioctl+0x60/0x90 [45117.335802] [<c07940c3>] sysenter_do_call+0x12/0x12 [45117.335836] [<b776de4c>] 0xb776de4b [45117.335846] ---[ end trace 63e1175b9ba4593d ]---
Unfortunately, the code is sufficiently complex (for my untrained eye) that I did not dare trying to patch it myself :-)
Again an ad hoc fix would be something like below. Could you give it a try? Takashi diff --git a/sound/usb/midi.c b/sound/usb/midi.c index 5bfb695547f8..34cd2b43057b 100644 --- a/sound/usb/midi.c +++ b/sound/usb/midi.c @@ -2221,6 +2221,8 @@ static void snd_usbmidi_input_start_ep(struct snd_usb_midi_in_endpoint *ep) return; for (i = 0; i < INPUT_URBS; ++i) { struct urb *urb = ep->urbs[i]; + if (atomic_read(urb->use_count)) + continue; urb->dev = ep->umidi->dev; snd_usbmidi_submit_urb(urb, GFP_KERNEL); } -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Hi Takashi, Am 05.01.2015 um 11:49 schrieb Takashi Iwai:
At Mon, 22 Dec 2014 18:53:43 +0100, Stefan Seyfried wrote:
Hi Takashi,
it looks like more similar bugs are somewhere hidden in the code.
Today I saw this on my daughter's box, with the patched snd-usb-audio and snd-usbmidi-lib:
[45117.334757] ------------[ cut here ]------------ [45117.334778] WARNING: CPU: 2 PID: 7158 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() [45117.334782] URB e7bc54c0 submitted while active [45117.334786] Modules linked in: snd_seq_midi snd_seq_midi_event snd_usb_audio(O) snd_usbmidi_lib(O) snd_rawmidi snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss snd tpm_infineon tpm_tis soundcore gpio_ich iTCO_wdt iTCO_vendor_support ppdev i2c_i801 tpm coretemp serio_raw pcspkr lpc_ich mfd_core r8169 mii shpchp parport_pc parport ite_cir rc_core dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg [45117.334903] CPU: 2 PID: 7158 Comm: aconnect Tainted: G O 3.16.6-2-desktop #1 [45117.334907] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 [45117.334911] c0984bfa db46dce4 c078deaf db46dcf4 c024c884 c09a135c db46dd10 00001bf6 [45117.334923] c0984bfa 00000153 c061ac4f c061ac4f 00000009 e7bc5f48 e7bc54c0 e7bc5f40 [45117.334935] db46dcfc c024c8d3 00000009 db46dcf4 c09a135c db46dd10 db46dd14 c061ac4f [45117.334947] Call Trace: [45117.334971] [<c0205df6>] try_stack_unwind+0x156/0x170 [45117.334991] [<c020482a>] dump_trace+0x5a/0x1b0 [45117.335001] [<c0205e56>] show_trace_log_lvl+0x46/0x50 [45117.335094] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 [45117.335132] [<c0205eb7>] show_stack+0x27/0x50 [45117.335161] [<c078deaf>] dump_stack+0x45/0x65 [45117.335184] [<c024c884>] warn_slowpath_common+0x84/0xa0 [45117.335199] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 [45117.335213] [<c061ac4f>] usb_submit_urb+0x5f/0x70 [45117.335239] [<f7adf104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] [45117.335274] [<f7adfb0e>] snd_usbmidi_input_start.part.12+0x4e/0x70 [snd_usbmidi_lib] [45117.335303] [<f7ae0a6b>] substream_open.isra.23+0x11b/0x1c0 [snd_usbmidi_lib] [45117.335341] [<f7e3cbba>] open_substream+0xda/0x170 [snd_rawmidi] [45117.335373] [<f7e3d301>] rawmidi_open_priv+0x51/0x110 [snd_rawmidi] [45117.335408] [<f7e3d45e>] snd_rawmidi_kernel_open+0x9e/0x110 [snd_rawmidi] [45117.335459] [<f7c9029a>] midisynth_subscribe+0x3a/0xf0 [snd_seq_midi] [45117.335497] [<f77d19ab>] subscribe_port.isra.1+0x6b/0xc0 [snd_seq] [45117.335578] [<f77d2529>] snd_seq_port_connect+0x159/0x2e0 [snd_seq] [45117.335655] [<f77ce3b4>] snd_seq_ioctl_subscribe_port+0xc4/0x140 [snd_seq] [45117.335703] [<f77cc8dd>] snd_seq_do_ioctl+0x9d/0xe0 [snd_seq] [45117.335740] [<c03965c2>] do_vfs_ioctl+0x2f2/0x4f0 [45117.335781] [<c0396820>] SyS_ioctl+0x60/0x90 [45117.335802] [<c07940c3>] sysenter_do_call+0x12/0x12 [45117.335836] [<b776de4c>] 0xb776de4b [45117.335846] ---[ end trace 63e1175b9ba4593d ]---
Unfortunately, the code is sufficiently complex (for my untrained eye) that I did not dare trying to patch it myself :-)
Again an ad hoc fix would be something like below. Could you give it a try?
I can, but this error is nothing easily reproducible, but appeared only once until now, so I cannot reliably tell if it helps :-(
Takashi
diff --git a/sound/usb/midi.c b/sound/usb/midi.c index 5bfb695547f8..34cd2b43057b 100644 --- a/sound/usb/midi.c +++ b/sound/usb/midi.c @@ -2221,6 +2221,8 @@ static void snd_usbmidi_input_start_ep(struct snd_usb_midi_in_endpoint *ep) return; for (i = 0; i < INPUT_URBS; ++i) { struct urb *urb = ep->urbs[i]; + if (atomic_read(urb->use_count)) + continue; urb->dev = ep->umidi->dev; snd_usbmidi_submit_urb(urb, GFP_KERNEL); }
Having no real clue about the issue: wouldn't it be good to do something like this in snd_usbmidi_submit_urb()? Or to put it the other way round: will we end up putting this everywhere where snd_usbmidi_submit() is called eventually? :-) Thanks! seife -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
At Wed, 07 Jan 2015 14:12:47 +0100, Stefan Seyfried wrote:
Hi Takashi,
Am 05.01.2015 um 11:49 schrieb Takashi Iwai:
At Mon, 22 Dec 2014 18:53:43 +0100, Stefan Seyfried wrote:
Hi Takashi,
it looks like more similar bugs are somewhere hidden in the code.
Today I saw this on my daughter's box, with the patched snd-usb-audio and snd-usbmidi-lib:
[45117.334757] ------------[ cut here ]------------ [45117.334778] WARNING: CPU: 2 PID: 7158 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() [45117.334782] URB e7bc54c0 submitted while active [45117.334786] Modules linked in: snd_seq_midi snd_seq_midi_event snd_usb_audio(O) snd_usbmidi_lib(O) snd_rawmidi snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss snd tpm_infineon tpm_tis soundcore gpio_ich iTCO_wdt iTCO_vendor_support ppdev i2c_i801 tpm coretemp serio_raw pcspkr lpc_ich mfd_core r8169 mii shpchp parport_pc parport ite_cir rc_core dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg [45117.334903] CPU: 2 PID: 7158 Comm: aconnect Tainted: G O 3.16.6-2-desktop #1 [45117.334907] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 [45117.334911] c0984bfa db46dce4 c078deaf db46dcf4 c024c884 c09a135c db46dd10 00001bf6 [45117.334923] c0984bfa 00000153 c061ac4f c061ac4f 00000009 e7bc5f48 e7bc54c0 e7bc5f40 [45117.334935] db46dcfc c024c8d3 00000009 db46dcf4 c09a135c db46dd10 db46dd14 c061ac4f [45117.334947] Call Trace: [45117.334971] [<c0205df6>] try_stack_unwind+0x156/0x170 [45117.334991] [<c020482a>] dump_trace+0x5a/0x1b0 [45117.335001] [<c0205e56>] show_trace_log_lvl+0x46/0x50 [45117.335094] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 [45117.335132] [<c0205eb7>] show_stack+0x27/0x50 [45117.335161] [<c078deaf>] dump_stack+0x45/0x65 [45117.335184] [<c024c884>] warn_slowpath_common+0x84/0xa0 [45117.335199] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 [45117.335213] [<c061ac4f>] usb_submit_urb+0x5f/0x70 [45117.335239] [<f7adf104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] [45117.335274] [<f7adfb0e>] snd_usbmidi_input_start.part.12+0x4e/0x70 [snd_usbmidi_lib] [45117.335303] [<f7ae0a6b>] substream_open.isra.23+0x11b/0x1c0 [snd_usbmidi_lib] [45117.335341] [<f7e3cbba>] open_substream+0xda/0x170 [snd_rawmidi] [45117.335373] [<f7e3d301>] rawmidi_open_priv+0x51/0x110 [snd_rawmidi] [45117.335408] [<f7e3d45e>] snd_rawmidi_kernel_open+0x9e/0x110 [snd_rawmidi] [45117.335459] [<f7c9029a>] midisynth_subscribe+0x3a/0xf0 [snd_seq_midi] [45117.335497] [<f77d19ab>] subscribe_port.isra.1+0x6b/0xc0 [snd_seq] [45117.335578] [<f77d2529>] snd_seq_port_connect+0x159/0x2e0 [snd_seq] [45117.335655] [<f77ce3b4>] snd_seq_ioctl_subscribe_port+0xc4/0x140 [snd_seq] [45117.335703] [<f77cc8dd>] snd_seq_do_ioctl+0x9d/0xe0 [snd_seq] [45117.335740] [<c03965c2>] do_vfs_ioctl+0x2f2/0x4f0 [45117.335781] [<c0396820>] SyS_ioctl+0x60/0x90 [45117.335802] [<c07940c3>] sysenter_do_call+0x12/0x12 [45117.335836] [<b776de4c>] 0xb776de4b [45117.335846] ---[ end trace 63e1175b9ba4593d ]---
Unfortunately, the code is sufficiently complex (for my untrained eye) that I did not dare trying to patch it myself :-)
Again an ad hoc fix would be something like below. Could you give it a try?
I can, but this error is nothing easily reproducible, but appeared only once until now, so I cannot reliably tell if it helps :-(
Takashi
diff --git a/sound/usb/midi.c b/sound/usb/midi.c index 5bfb695547f8..34cd2b43057b 100644 --- a/sound/usb/midi.c +++ b/sound/usb/midi.c @@ -2221,6 +2221,8 @@ static void snd_usbmidi_input_start_ep(struct snd_usb_midi_in_endpoint *ep) return; for (i = 0; i < INPUT_URBS; ++i) { struct urb *urb = ep->urbs[i]; + if (atomic_read(urb->use_count)) + continue; urb->dev = ep->umidi->dev; snd_usbmidi_submit_urb(urb, GFP_KERNEL); }
Having no real clue about the issue: wouldn't it be good to do something like this in snd_usbmidi_submit_urb()? Or to put it the other way round: will we end up putting this everywhere where snd_usbmidi_submit() is called eventually? :-)
Yeah, we need a better fix. But at least we need to know whether this is the real culprit at first. Basically this race shouldn't happen in a normal situation. Possibly some error recovery path is executed asynchronously and conflicts with the normal input start/stop sequence. If so, that's the place to fix, instead of papering over the all places. Takashi -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Am 07.01.2015 um 14:20 schrieb Takashi Iwai:
At Wed, 07 Jan 2015 14:12:47 +0100, Stefan Seyfried wrote:
Having no real clue about the issue: wouldn't it be good to do something like this in snd_usbmidi_submit_urb()? Or to put it the other way round: will we end up putting this everywhere where snd_usbmidi_submit() is called eventually? :-)
Yeah, we need a better fix. But at least we need to know whether this is the real culprit at first. Basically this race shouldn't happen in a normal situation. Possibly some error recovery path is executed asynchronously and conflicts with the normal input start/stop sequence. If so, that's the place to fix, instead of papering over the all places.
Ok, I'll check the logs. Unfortunately the machine is powered down right now. It might have happened after resume from suspend to RAM (this machine is usually only suspended to RAM unless I explicitly request to reboot it after kernel updates etc), so some unusual recovery path might be involved here. Thanks, seife -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
On Mon, 2015-01-05 at 11:49 +0100, Takashi Iwai wrote:
At Mon, 22 Dec 2014 18:53:43 +0100, Stefan Seyfried wrote:
[45117.334757] ------------[ cut here ]------------ [45117.334778] WARNING: CPU: 2 PID: 7158 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() [45117.334782] URB e7bc54c0 submitted while active [45117.334786] Modules linked in: snd_seq_midi snd_seq_midi_event snd_usb_audio(O) snd_usbmidi_lib(O) snd_rawmidi snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss snd tpm_infineon tpm_tis soundcore gpio_ich iTCO_wdt iTCO_vendor_support ppdev i2c_i801 tpm coretemp serio_raw pcspkr lpc_ich mfd_core r8169 mii shpchp parport_pc parport ite_cir rc_core dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg [45117.334903] CPU: 2 PID: 7158 Comm: aconnect Tainted: G O 3.16.6-2-desktop #1 [45117.334907] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 [45117.334911] c0984bfa db46dce4 c078deaf db46dcf4 c024c884 c09a135c db46dd10 00001bf6 [45117.334923] c0984bfa 00000153 c061ac4f c061ac4f 00000009 e7bc5f48 e7bc54c0 e7bc5f40 [45117.334935] db46dcfc c024c8d3 00000009 db46dcf4 c09a135c db46dd10 db46dd14 c061ac4f [45117.334947] Call Trace: [45117.334971] [<c0205df6>] try_stack_unwind+0x156/0x170 [45117.334991] [<c020482a>] dump_trace+0x5a/0x1b0 [45117.335001] [<c0205e56>] show_trace_log_lvl+0x46/0x50 [45117.335094] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 [45117.335132] [<c0205eb7>] show_stack+0x27/0x50 [45117.335161] [<c078deaf>] dump_stack+0x45/0x65 [45117.335184] [<c024c884>] warn_slowpath_common+0x84/0xa0 [45117.335199] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 [45117.335213] [<c061ac4f>] usb_submit_urb+0x5f/0x70 [45117.335239] [<f7adf104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] [45117.335274] [<f7adfb0e>] snd_usbmidi_input_start.part.12+0x4e/0x70 [snd_usbmidi_lib] [45117.335303] [<f7ae0a6b>] substream_open.isra.23+0x11b/0x1c0 [snd_usbmidi_lib] [45117.335341] [<f7e3cbba>] open_substream+0xda/0x170 [snd_rawmidi] [45117.335373] [<f7e3d301>] rawmidi_open_priv+0x51/0x110 [snd_rawmidi] [45117.335408] [<f7e3d45e>] snd_rawmidi_kernel_open+0x9e/0x110 [snd_rawmidi] [45117.335459] [<f7c9029a>] midisynth_subscribe+0x3a/0xf0 [snd_seq_midi] [45117.335497] [<f77d19ab>] subscribe_port.isra.1+0x6b/0xc0 [snd_seq] [45117.335578] [<f77d2529>] snd_seq_port_connect+0x159/0x2e0 [snd_seq] [45117.335655] [<f77ce3b4>] snd_seq_ioctl_subscribe_port+0xc4/0x140 [snd_seq] [45117.335703] [<f77cc8dd>] snd_seq_do_ioctl+0x9d/0xe0 [snd_seq] [45117.335740] [<c03965c2>] do_vfs_ioctl+0x2f2/0x4f0 [45117.335781] [<c0396820>] SyS_ioctl+0x60/0x90 [45117.335802] [<c07940c3>] sysenter_do_call+0x12/0x12 [45117.335836] [<b776de4c>] 0xb776de4b [45117.335846] ---[ end trace 63e1175b9ba4593d ]---
Unfortunately, the code is sufficiently complex (for my untrained eye) that I did not dare trying to patch it myself :-)
Again an ad hoc fix would be something like below. Could you give it a try?
Takashi, looking at this: /* * Prepare for suspend. Typically called from the USB suspend callback. */ void snd_usbmidi_suspend(struct list_head *p) { struct snd_usb_midi *umidi; umidi = list_entry(p, struct snd_usb_midi, list); mutex_lock(&umidi->mutex); snd_usbmidi_input_stop(p); mutex_unlock(&umidi->mutex); } EXPORT_SYMBOL(snd_usbmidi_suspend); It seems to me that the error_timer needs to be deleted on suspend() just as on disconnect() What do you think? Regards Oliver -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
At Wed, 07 Jan 2015 14:59:14 +0100, Oliver Neukum wrote:
On Mon, 2015-01-05 at 11:49 +0100, Takashi Iwai wrote:
At Mon, 22 Dec 2014 18:53:43 +0100, Stefan Seyfried wrote:
[45117.334757] ------------[ cut here ]------------ [45117.334778] WARNING: CPU: 2 PID: 7158 at ../drivers/usb/core/urb.c:339 usb_submit_urb+0x5f/0x70() [45117.334782] URB e7bc54c0 submitted while active [45117.334786] Modules linked in: snd_seq_midi snd_seq_midi_event snd_usb_audio(O) snd_usbmidi_lib(O) snd_rawmidi snd_hrtimer nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss oid_registry nfsv4 dns_resolver bnep bluetooth 6lowpan_iphc rfkill fuse nfs lockd sunrpc fscache iscsi_ibft iscsi_boot_sysfs af_packet snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm_oss snd_pcm snd_seq snd_seq_device snd_timer snd_mixer_oss snd tpm_infineon tpm_tis soundcore gpio_ich iTCO_wdt iTCO_vendor_support ppdev i2c_i801 tpm coretemp serio_raw pcspkr lpc_ich mfd_core r8169 mii shpchp parport_pc parport ite_cir rc_core dm_mod sr_mod cdrom i915 i2c_algo_bit video drm_kms_helper drm thermal button processor sg [45117.334903] CPU: 2 PID: 7158 Comm: aconnect Tainted: G O 3.16.6-2-desktop #1 [45117.334907] Hardware name: FOXCONN TPS01/TPS01, BIOS 080015 03/23/2010 [45117.334911] c0984bfa db46dce4 c078deaf db46dcf4 c024c884 c09a135c db46dd10 00001bf6 [45117.334923] c0984bfa 00000153 c061ac4f c061ac4f 00000009 e7bc5f48 e7bc54c0 e7bc5f40 [45117.334935] db46dcfc c024c8d3 00000009 db46dcf4 c09a135c db46dd10 db46dd14 c061ac4f [45117.334947] Call Trace: [45117.334971] [<c0205df6>] try_stack_unwind+0x156/0x170 [45117.334991] [<c020482a>] dump_trace+0x5a/0x1b0 [45117.335001] [<c0205e56>] show_trace_log_lvl+0x46/0x50 [45117.335094] [<c02049d1>] show_stack_log_lvl+0x51/0xe0 [45117.335132] [<c0205eb7>] show_stack+0x27/0x50 [45117.335161] [<c078deaf>] dump_stack+0x45/0x65 [45117.335184] [<c024c884>] warn_slowpath_common+0x84/0xa0 [45117.335199] [<c024c8d3>] warn_slowpath_fmt+0x33/0x40 [45117.335213] [<c061ac4f>] usb_submit_urb+0x5f/0x70 [45117.335239] [<f7adf104>] snd_usbmidi_submit_urb+0x14/0x60 [snd_usbmidi_lib] [45117.335274] [<f7adfb0e>] snd_usbmidi_input_start.part.12+0x4e/0x70 [snd_usbmidi_lib] [45117.335303] [<f7ae0a6b>] substream_open.isra.23+0x11b/0x1c0 [snd_usbmidi_lib] [45117.335341] [<f7e3cbba>] open_substream+0xda/0x170 [snd_rawmidi] [45117.335373] [<f7e3d301>] rawmidi_open_priv+0x51/0x110 [snd_rawmidi] [45117.335408] [<f7e3d45e>] snd_rawmidi_kernel_open+0x9e/0x110 [snd_rawmidi] [45117.335459] [<f7c9029a>] midisynth_subscribe+0x3a/0xf0 [snd_seq_midi] [45117.335497] [<f77d19ab>] subscribe_port.isra.1+0x6b/0xc0 [snd_seq] [45117.335578] [<f77d2529>] snd_seq_port_connect+0x159/0x2e0 [snd_seq] [45117.335655] [<f77ce3b4>] snd_seq_ioctl_subscribe_port+0xc4/0x140 [snd_seq] [45117.335703] [<f77cc8dd>] snd_seq_do_ioctl+0x9d/0xe0 [snd_seq] [45117.335740] [<c03965c2>] do_vfs_ioctl+0x2f2/0x4f0 [45117.335781] [<c0396820>] SyS_ioctl+0x60/0x90 [45117.335802] [<c07940c3>] sysenter_do_call+0x12/0x12 [45117.335836] [<b776de4c>] 0xb776de4b [45117.335846] ---[ end trace 63e1175b9ba4593d ]---
Unfortunately, the code is sufficiently complex (for my untrained eye) that I did not dare trying to patch it myself :-)
Again an ad hoc fix would be something like below. Could you give it a try?
Takashi,
looking at this:
/* * Prepare for suspend. Typically called from the USB suspend callback. */ void snd_usbmidi_suspend(struct list_head *p) { struct snd_usb_midi *umidi;
umidi = list_entry(p, struct snd_usb_midi, list); mutex_lock(&umidi->mutex); snd_usbmidi_input_stop(p); mutex_unlock(&umidi->mutex); } EXPORT_SYMBOL(snd_usbmidi_suspend);
It seems to me that the error_timer needs to be deleted on suspend() just as on disconnect() What do you think?
Yes, a good catch. Seife's explained that it's likely related with suspend, so this can be the cause. Worth to try. Takashi --- diff --git a/sound/usb/midi.c b/sound/usb/midi.c index 5bfb695547f8..54ffa4cc8142 100644 --- a/sound/usb/midi.c +++ b/sound/usb/midi.c @@ -2253,6 +2253,7 @@ void snd_usbmidi_suspend(struct list_head *p) umidi = list_entry(p, struct snd_usb_midi, list); mutex_lock(&umidi->mutex); snd_usbmidi_input_stop(p); + del_timer_sync(&umidi->error_timer); mutex_unlock(&umidi->mutex); } EXPORT_SYMBOL(snd_usbmidi_suspend); -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
Hi Takashi, first: I have seen this only once, so not seeing it with a patched kernel does not necessarily mean it is fixed :-( Am 07.01.2015 um 15:15 schrieb Takashi Iwai:
At Wed, 07 Jan 2015 14:59:14 +0100, Oliver Neukum wrote:
Takashi,
looking at this:
/* * Prepare for suspend. Typically called from the USB suspend callback. */ void snd_usbmidi_suspend(struct list_head *p) { struct snd_usb_midi *umidi;
umidi = list_entry(p, struct snd_usb_midi, list); mutex_lock(&umidi->mutex); snd_usbmidi_input_stop(p); mutex_unlock(&umidi->mutex); } EXPORT_SYMBOL(snd_usbmidi_suspend);
It seems to me that the error_timer needs to be deleted on suspend() just as on disconnect() What do you think?
Yes, a good catch. Seife's explained that it's likely related with suspend, so this can be the cause. Worth to try.
Takashi
--- diff --git a/sound/usb/midi.c b/sound/usb/midi.c index 5bfb695547f8..54ffa4cc8142 100644 --- a/sound/usb/midi.c +++ b/sound/usb/midi.c @@ -2253,6 +2253,7 @@ void snd_usbmidi_suspend(struct list_head *p) umidi = list_entry(p, struct snd_usb_midi, list); mutex_lock(&umidi->mutex); snd_usbmidi_input_stop(p); + del_timer_sync(&umidi->error_timer); mutex_unlock(&umidi->mutex); } EXPORT_SYMBOL(snd_usbmidi_suspend);
I tried both patches, and the error did not pop up, but as explained above, it hit only once before, so it probably is a not easily hit race condition. But the one case where it happened, it was directly after resume: 2014-12-22T13:12:16.880531+01:00 wendy kernel: [30485.859188] PM: resume of devices complete after 1811.973 msecs 2014-12-22T13:12:16.880542+01:00 wendy kernel: [30485.859532] PM: Finishing wakeup. 2014-12-22T13:12:16.882258+01:00 wendy kernel: [30485.859537] Restarting tasks ... done. 2014-12-22T16:35:21.282216+01:00 wendy kernel: [42670.273069] usb 4-2: new full-speed USB device number 3 using uhci_hcd [...] [... USB devices being re-detected ... ] but the bug only hit at a later time: 2014-12-22T17:16:08.343405+01:00 wendy kernel: [45117.334782] URB e7bc54c0 submitted while active So 33 minutes after resume. Thanks, seife -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-kernel+owner@opensuse.org
participants (6)
-
doiggl＠velocitynet.com.au -
Oliver Neukum -
Stefan Seyfried -
Takashi Iwai -
toganm＠opensuse.org -
Torsten Duwe