Bug#537085: linux-image-2.6-amd64: garmin_gps module stopped working
Package: linux-image-2.6-amd64
Version: 2.6.29-5
Severity: normal
Tags: upstream
The garmin_gps module stopped working for connecting to Garmin 60Cx device
with gpsbabel. Since rebooting to kernel 2.6.25 makes it work without any
other changes to the system, I conclude it's driver problem rather than
gpsbabel problem.
The symptoms are, that when I run gpsbabel, either upload or download, with
2.6.29 or newer kernel, it locks up (stays in D state) and is not killable.
The Garmin MapSource running in Wine seemed not affected though, at least for
upload.
First known-bad version 2.6.29
Last known-good version 2.6.25
Note, that I already have newer kernel -- 2.6.30+20 -- installed (and the
dmesg output below is from that version). I am reporting against previous
version because I first noticed the problem there. Below you will find
relevant content of dmesg.
I am quickly posting this now in the hope that the trace below gives some
hint to somebody. Otherwise I will try bisecting it, but it will take me some
time to learn sane process for installing the non-Debian kernels here.
-- System Information:
Debian Release: squeeze/sid
APT prefers unstable
APT policy: (500, 'unstable'), (500, 'testing'), (500, 'stable'), (100, 'experimental')
Architecture: amd64 (x86_64)
Kernel: Linux 2.6.30-1-amd64 (SMP w/2 CPU cores)
Locale: LANG=C, LC_CTYPE=cs_CZ.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Versions of packages linux-image-2.6-amd64 depends on:
ii linux-image-2.6.30-1-amd64 2.6.30-2 Linux 2.6.30 image on AMD64
linux-image-2.6-amd64 recommends no packages.
linux-image-2.6-amd64 suggests no packages.
Other packages related to the problem:
ii gpsbabel 1.3.6-3 GPS file conversion plus transfer to/from GPS units
-- no debconf information
Here is the device connection -- looks the same as on older kernels that
worked, though:
[ 72.718994] usb 3-2: new full speed USB device using ohci_hcd and address 3
[ 72.885994] usb 3-2: New USB device found, idVendor=091e, idProduct=0003
[ 72.885999] usb 3-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 72.886089] usb 3-2: configuration #1 chosen from 1 choice
[ 73.043061] usbcore: registered new interface driver usbserial
[ 73.043079] USB Serial support registered for generic
[ 73.043117] usbcore: registered new interface driver usbserial_generic
[ 73.043119] usbserial: USB Serial Driver core
[ 73.171972] USB Serial support registered for Garmin GPS usb/tty
[ 73.171994] garmin_gps 3-2:1.0: Garmin GPS usb/tty converter detected
[ 73.172080] usb 3-2: Garmin GPS usb/tty converter now attached to ttyUSB0
[ 73.172094] usbcore: registered new interface driver garmin_gps
[ 73.172096] garmin_gps: v0.31:garmin gps driver
Here is (there were in fact no other messages between) a message that the
gpsbabel process is blocked:
[ 240.448850] INFO: task gpsbabel:4174 blocked for more than 120 seconds.
[ 240.448854] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 240.448856] gpsbabel D ffff88000103c0c0 0 4174 4164
[ 240.448861] ffff88007ccfa830 0000000000000082 0000000000000000 ffff8800683d7540
[ 240.448865] 0000000000000001 00000000000120c0 000000000000e250 ffff8800681f4b30
[ 240.448868] ffff8800681f4e20 00000001000003c0 ffff88007fbaf2b0 0000000000000246
[ 240.448872] Call Trace:
[ 240.448882] [<ffffffff804b3fc5>] ? __mutex_lock_common+0x10f/0x17f
[ 240.448887] [<ffffffff8030cc71>] ? release_sysfs_dirent+0x66/0x7f
[ 240.448891] [<ffffffff804b3e34>] ? mutex_lock+0x12/0x28
[ 240.448894] [<ffffffff803e0380>] ? usb_disable_endpoint+0x4f/0x68
[ 240.448904] [<ffffffffa0644b2e>] ? usb_serial_disconnect+0x50/0x10a [usbserial]
[ 240.448908] [<ffffffff803e2c54>] ? usb_unbind_interface+0x5b/0xe1
[ 240.448912] [<ffffffff803d1d20>] ? __device_release_driver+0x77/0x9e
[ 240.448915] [<ffffffff803d1dff>] ? device_release_driver+0x1e/0x2a
[ 240.448918] [<ffffffff803e2e64>] ? usb_driver_release_interface+0x3e/0x98
[ 240.448921] [<ffffffff803e2f3e>] ? usb_forced_unbind_intf+0x17/0x1d
[ 240.448925] [<ffffffff803db779>] ? usb_reset_device+0x7d/0x118
[ 240.448929] [<ffffffff802546ee>] ? autoremove_wake_function+0x0/0x2e
[ 240.448935] [<ffffffffa064fc0e>] ? garmin_close+0x12d/0x181 [garmin_gps]
[ 240.448940] [<ffffffffa0644a20>] ? serial_close+0x99/0x157 [usbserial]
[ 240.448945] [<ffffffff803b1ed7>] ? tty_release_dev+0x193/0x47f
[ 240.448949] [<ffffffff803b648c>] ? tty_ldisc_deref+0x59/0x6b
[ 240.448953] [<ffffffff802cbd82>] ? vfs_ioctl+0x21/0x6c
[ 240.448956] [<ffffffff803b21d4>] ? tty_release+0x11/0x1a
[ 240.448959] [<ffffffff802c18de>] ? __fput+0xc6/0x16e
[ 240.448962] [<ffffffff802beef6>] ? filp_close+0x5b/0x62
[ 240.448965] [<ffffffff802bef91>] ? sys_close+0x94/0xcd
[ 240.448969] [<ffffffff8020fa42>] ? system_call_fastpath+0x16/0x1b
The message repeats every 120 seconds and looks exactly the same (except for
the timestamp, so I won't repeat it here).
Last, I have tried SysRq+w and here is what appeared in dmesg after that:
[ 844.750098] SysRq : Show Blocked State
[ 844.750161] task PC stack pid father
[ 844.750257] gpsbabel D ffff88000103c0c0 0 4174 4164
[ 844.750342] ffff88007ccfa830 0000000000000082 0000000000000000 ffff8800683d7540
[ 844.750450] 0000000000000001 00000000000120c0 000000000000e250 ffff8800681f4b30
[ 844.750558] ffff8800681f4e20 00000001000003c0 ffff88007fbaf2b0 0000000000000246
[ 844.750666] Call Trace:
[ 844.750706] [<ffffffff804b3fc5>] ? __mutex_lock_common+0x10f/0x17f
[ 844.750791] [<ffffffff8030cc71>] ? release_sysfs_dirent+0x66/0x7f
[ 844.750872] [<ffffffff804b3e34>] ? mutex_lock+0x12/0x28
[ 844.750942] [<ffffffff803e0380>] ? usb_disable_endpoint+0x4f/0x68
[ 844.751029] [<ffffffffa0644b2e>] ? usb_serial_disconnect+0x50/0x10a [usbserial]
[ 844.751126] [<ffffffff803e2c54>] ? usb_unbind_interface+0x5b/0xe1
[ 844.751207] [<ffffffff803d1d20>] ? __device_release_driver+0x77/0x9e
[ 844.751292] [<ffffffff803d1dff>] ? device_release_driver+0x1e/0x2a
[ 844.751373] [<ffffffff803e2e64>] ? usb_driver_release_interface+0x3e/0x98
[ 844.751463] [<ffffffff803e2f3e>] ? usb_forced_unbind_intf+0x17/0x1d
[ 844.751547] [<ffffffff803db779>] ? usb_reset_device+0x7d/0x118
[ 844.751625] [<ffffffff802546ee>] ? autoremove_wake_function+0x0/0x2e
[ 844.751712] [<ffffffffa064fc0e>] ? garmin_close+0x12d/0x181 [garmin_gps]
[ 844.751803] [<ffffffffa0644a20>] ? serial_close+0x99/0x157 [usbserial]
[ 844.751891] [<ffffffff803b1ed7>] ? tty_release_dev+0x193/0x47f
[ 844.751969] [<ffffffff803b648c>] ? tty_ldisc_deref+0x59/0x6b
[ 844.752046] [<ffffffff802cbd82>] ? vfs_ioctl+0x21/0x6c
[ 844.752115] [<ffffffff803b21d4>] ? tty_release+0x11/0x1a
[ 844.752186] [<ffffffff802c18de>] ? __fput+0xc6/0x16e
[ 844.752253] [<ffffffff802beef6>] ? filp_close+0x5b/0x62
[ 844.752323] [<ffffffff802bef91>] ? sys_close+0x94/0xcd
[ 844.752394] [<ffffffff8020fa42>] ? system_call_fastpath+0x16/0x1b
[ 844.752477] Sched Debug Version: v0.09, 2.6.30-1-amd64 #1
[ 844.754084] now at 844752.680447 msecs
[ 844.754084] .jiffies : 4295103483
[ 844.754084] .sysctl_sched_latency : 40.000000
[ 844.754084] .sysctl_sched_min_granularity : 8.000000
[ 844.754084] .sysctl_sched_wakeup_granularity : 10.000000
[ 844.754084] .sysctl_sched_child_runs_first : 0.000001
[ 844.754084] .sysctl_sched_features : 113917
[ 844.754084]
[ 844.754084] cpu#0, 2505.471 MHz
[ 844.754084] .nr_running : 0
[ 844.754084] .load : 0
[ 844.754084] .nr_switches : 198082
[ 844.754084] .nr_load_updates : 41286
[ 844.754084] .nr_uninterruptible : 558
[ 844.754084] .next_balance : 4295.103470
[ 844.754084] .curr->pid : 0
[ 844.754084] .clock : 844750.108655
[ 844.754084] .cpu_load[0] : 0
[ 844.754084] .cpu_load[1] : 0
[ 844.754084] .cpu_load[2] : 0
[ 844.754084] .cpu_load[3] : 0
[ 844.754084] .cpu_load[4] : 0
[ 844.754084]
[ 844.754084] cfs_rq[0]:/
[ 844.754084] .exec_clock : 0.000000
[ 844.754084] .MIN_vruntime : 0.000001
[ 844.754084] .min_vruntime : 55070.855847
[ 844.754084] .max_vruntime : 0.000001
[ 844.754084] .spread : 0.000000
[ 844.754084] .spread0 : 0.000000
[ 844.754084] .nr_running : 0
[ 844.754084] .load : 0
[ 844.754084] .nr_spread_over : 0
[ 844.754084] .shares : 0
[ 844.754084]
[ 844.754084] rt_rq[0]:
[ 844.754084] .rt_nr_running : 0
[ 844.754084] .rt_throttled : 0
[ 844.754084] .rt_time : 0.000000
[ 844.754084] .rt_runtime : 950.000000
[ 844.754084]
[ 844.754084] runnable tasks:
[ 844.754084] task PID tree-key switches prio exec-runtime sum-exec sum-sleep
[ 844.754084] ----------------------------------------------------------------------------------------------------------
[ 844.754084]
[ 844.754084] cpu#1, 2505.471 MHz
[ 844.754084] .nr_running : 1
[ 844.754084] .load : 3121
[ 844.754084] .nr_switches : 191487
[ 844.754084] .nr_load_updates : 37817
[ 844.754084] .nr_uninterruptible : -557
[ 844.754084] .next_balance : 4295.103469
[ 844.754084] .curr->pid : 0
[ 844.754084] .clock : 844750.092358
[ 844.754084] .cpu_load[0] : 0
[ 844.754084] .cpu_load[1] : 0
[ 844.754084] .cpu_load[2] : 0
[ 844.754084] .cpu_load[3] : 5
[ 844.754084] .cpu_load[4] : 13
[ 844.754084]
[ 844.754084] cfs_rq[1]:/
[ 844.754084] .exec_clock : 0.000000
[ 844.754084] .MIN_vruntime : 42718.431673
[ 844.754084] .min_vruntime : 42758.233779
[ 844.754084] .max_vruntime : 42718.431673
[ 844.754084] .spread : 0.000000
[ 844.754084] .spread0 : -12312.622068
[ 844.754084] .nr_running : 1
[ 844.754084] .load : 3121
[ 844.754084] .nr_spread_over : 0
[ 844.754084] .shares : 0
[ 844.754084]
[ 844.754084] rt_rq[1]:
[ 844.754084] .rt_nr_running : 0
[ 844.754084] .rt_throttled : 0
[ 844.754084] .rt_time : 0.000000
[ 844.754084] .rt_runtime : 950.000000
[ 844.754084]
[ 844.754084] runnable tasks:
[ 844.754084] task PID tree-key switches prio exec-runtime sum-exec sum-sleep
[ 844.754084] ----------------------------------------------------------------------------------------------------------
[ 844.754084] events/1 10 42718.431673 3578 115 0 0 0.000000 0.000000 0.000000 /
[ 844.754084]
--
Jan 'Bulb' Hudec <bulb@ucw.cz>
Reply to: