Lost without a Sync

in

For anybody who cares, here are the kernel messages I'm seeing. Here are the messages when the phone is inserted and sync button depressed.

(Hit the "switch to printable" link at the bottom of the page to remove the sidebar for easier reading.)

Jul 16 13:13:52 wiener kernel: [17179682.372000] usb 3-2: new full speed USB device using uhci_hcd and address 2
Jul 16 13:13:52 wiener kernel: [17179682.644000] usbcore: registered new driver usbserial
Jul 16 13:13:52 wiener kernel: [17179682.644000] drivers/usb/serial/usb-serial.c: USB Serial support registered for generic
Jul 16 13:13:52 wiener kernel: [17179682.648000] usbcore: registered new driver usbserial_generic
Jul 16 13:13:52 wiener kernel: [17179682.648000] drivers/usb/serial/usb-serial.c: USB Serial Driver core
Jul 16 13:13:52 wiener kernel: [17179682.648000] drivers/usb/serial/usb-serial.c: USB Serial support registered for Handspring Visor / Palm OS
Jul 16 13:13:52 wiener kernel: [17179682.648000] drivers/usb/serial/usb-serial.c: USB Serial support registered for Sony Clie 3.5
Jul 16 13:13:52 wiener kernel: [17179682.648000] drivers/usb/serial/usb-serial.c: USB Serial support registered for Sony Clie 5.0
Jul 16 13:13:52 wiener kernel: [17179682.660000] visor 3-2:1.0: Handspring Visor / Palm OS converter detected
Jul 16 13:13:52 wiener kernel: [17179682.660000] usb 3-2: Handspring Visor / Palm OS converter now attached to ttyUSB0
Jul 16 13:13:52 wiener kernel: [17179682.660000] usb 3-2: Handspring Visor / Palm OS converter now attached to ttyUSB1
Jul 16 13:13:52 wiener kernel: [17179682.668000] visor 3-2:1.1: Handspring Visor / Palm OS converter detected
Jul 16 13:13:52 wiener kernel: [17179682.668000] usb 3-2: Handspring Visor / Palm OS converter now attached to ttyUSB2
Jul 16 13:13:52 wiener kernel: [17179682.668000] usb 3-2: Handspring Visor / Palm OS converter now attached to ttyUSB3
Jul 16 13:13:52 wiener kernel: [17179682.668000] usbcore: registered new driver visor
Jul 16 13:13:52 wiener kernel: [17179682.668000] drivers/usb/serial/visor.c: USB HandSpring Visor / Palm OS driver
Jul 16 13:13:52 wiener kernel: [17179682.676000] usbcore: registered new driver cdc_acm
Jul 16 13:13:52 wiener kernel: [17179682.676000] drivers/usb/class/cdc-acm.c: v0.23:USB Abstract Control Model driver for USB modems and ISDN adapters

I think that all looks alright.

At this point, I can run dlpsh -p /dev/ttyUSB1 (the dlpsh command is part of the pilot-link package) and talk to the device. The kpilot-daemon, however, never sees the device. And then when I remove it from the cradle, there is a driver module crash. Sometimes, the PS/2 keyboard locks up.

Here are those messages:

Jul 16 13:14:37 wiener kernel: [17179726.484000] usb 3-2: USB disconnect, address 2
Jul 16 13:14:37 wiener kernel: [17179726.484000] ------------[ cut here ]------------
Jul 16 13:14:37 wiener kernel: [17179726.484000] PREEMPT 
Jul 16 13:14:37 wiener kernel: [17179726.484000] Modules linked in: cdc_acm visor usbserial rfcomm l2cap bluetooth ppdev i915 drm ipv6 speedstep_lib cpufreq_userspace cpufreq_stats freq_table cpufreq_powersave cpufreq_ondemand cpufreq_conservative video tc1100_wmi sony_acpi pcc_acpi hotkey dev_acpi container button acpi_sbs battery ac i2c_acpi_ec i2c_core af_packet dm_mod md_mod lp tsdev e100 mii snd_intel8x0 snd_ac97_codec snd_ac97_bus snd_pcm_oss snd_mixer_oss hw_random shpchp pci_hotplug psmouse snd_pcm snd_timer serio_raw floppy parport_pc parport snd soundcore snd_page_alloc pcspkr rtc intel_agp agpgart evdev ext3 jbd ide_generic ehci_hcd uhci_hcd usbcore ide_cd cdrom ide_disk piix generic thermal processor fan capability commoncap vga16fb vgastate fbcon tileblit font bitblit softcursor
Jul 16 13:14:37 wiener kernel: [17179726.484000] CPU:    0
Jul 16 13:14:37 wiener kernel: [17179726.484000] EIP:    0060:[queue_work+83/96]    Not tainted VLI
Jul 16 13:14:37 wiener kernel: [17179726.484000] EFLAGS: 00010286   (2.6.15-26-386) 
Jul 16 13:14:37 wiener kernel: [17179726.484000] EIP is at queue_work+0x53/0x60
Jul 16 13:14:37 wiener kernel: [17179726.484000] eax: d3d04944   ebx: 00000000   ecx: df758e80   edx: d3d04940
Jul 16 13:14:37 wiener kernel: [17179726.484000] esi: d917e340   edi: d917e340   ebp: db719614   esp: de077e6c
Jul 16 13:14:37 wiener kernel: [17179726.484000] ds: 007b   es: 007b   ss: 0068
Jul 16 13:14:37 wiener kernel: [17179726.484000] Process khubd (pid: 1853, threadinfo=de076000 task=df373550)
Jul 16 13:14:37 wiener kernel: [17179726.484000] Stack: 00000000 e05161b4 d3d04000 db719600 e03f6360 e03f6380 db719614 e00c6116 
Jul 16 13:14:37 wiener kernel: [17179726.484000]        db719600 db71967c db719614 c02446f1 db719614 db719614 d9ce3068 00000000 
Jul 16 13:14:37 wiener kernel: [17179726.484000]        c0244747 db719614 db719614 c0243f51 db719614 db71965c e00e4ce0 db719614 
Jul 16 13:14:37 wiener kernel: [17179726.484000] Call Trace:
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+537838004/1069368320] usb_serial_disconnect+0x54/0xd0 [usbserial]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+533315862/1069368320] usb_unbind_interface+0x36/0x80 [usbcore]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [__device_release_driver+81/144] __device_release_driver+0x51/0x90
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [device_release_driver+23/48] device_release_driver+0x17/0x30
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [bus_remove_device+81/128] bus_remove_device+0x51/0x80
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [device_del+57/128] device_del+0x39/0x80
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+533349809/1069368320] usb_disable_device+0xd1/0x130 [usbcore]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+533325859/1069368320] usb_disconnect+0x93/0x130 [usbcore]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+533331243/1069368320] hub_port_connect_change+0x5b/0x450 [usbcore]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+533320438/1069368320] clear_port_feature+0x36/0x40 [usbcore]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+533332987/1069368320] hub_events+0x2db/0x460 [usbcore]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+533333376/1069368320] hub_thread+0x0/0x100 [usbcore]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [pg0+533333397/1069368320] hub_thread+0x15/0x100 [usbcore]
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [autoremove_wake_function+0/64] autoremove_wake_function+0x0/0x40
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [kthread+147/160] kthread+0x93/0xa0
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [kthread+0/160] kthread+0x0/0xa0
Jul 16 13:14:37 wiener kernel: [17179726.484000]  [kernel_thread_helper+5/16] kernel_thread_helper+0x5/0x10
Jul 16 13:14:37 wiener kernel: [17179726.484000] Code: 75 20 89 d8 5b c3 89 f6 8d 42 04 3b 42 04 75 1b 52 8b 01 50 e8 4f ff ff ff bb 01 00 00 00 59 58 eb cf e8 21 fe 1b 00 89 d8 5b c3 <0f> 0b 6d 00 40 04 30 c0 eb db 8d 76 00 8b 44 24 04 50 8b 40 14 
Jul 16 13:14:37 wiener kernel: [17179726.484000]  <6>note: khubd[1853] exited with preempt_count 1

By the way, those tests are running on wiener, my Pentium 4 2.8GHz testbed system. The fact that I see the same behavior as I saw on chinacat let me to the conclusion it's a software, not hardware, issue.

7/20 Update: I built a 2.6.17 kernel but that didn't solve the problem. My workaround was to install the old Ubuntu version (Hoary 5.10) on my test machine, NFS mount my home directory from chinacat, and do a sync there. That's clearly not a solution, but that gives some breathing room to get this problem sorted out.

Comments

Comments have been closed for this entry.

re: Lost without a Sync

hey chip,

i recently purchased a treo 700p and also had some issues syncing, under 2.6.14 and even under the latest 2.6.17.4. since i only use the raw pilot-link tools and not kpilot or any of the other frontends, i can work around them by giving the appropriate delay (it would appear that trying to talk to /dev/ttyUSB1 before about 5 seconds has passed since the pressing of the hotsync button on the phone means the operation is doomed to failure; more than about 8 seconds and it is differently, but still totally doomed).

i don't experience the crashes, but i am also not using the CLIE drivers, just the palm/visor ones; once i'm not syncing anymore it's as though i'm unplugged instantly, too.

hope the new kernel helps!

re: Lost without a Sync

With 2.6.15 I could at least talk to the phone with dlpsh. With 2.6.17 I don't get the same kind of kernel module crash, but I am getting keyboard lockups.