Clie / USB Timing Problem



Hi all, 

before staring with the problem: This is long. Sorry, but I tried to
include as much information as possible, i.e. all I have for now. It's
about USB timing problems, dealing with the relevant modules and more
related to the usb-subsystem than to pilot-link or gnome-pilot, but I
assume those of you who developed the pilot-link stuff and all that know
a lot about the USB-stuff as well and might derive from my explanations
below that it is _not_ a problem of pilot-link as others on USB-Related
lists might propose. So here I go:

Some of you might remember that I repeatedly reported about "timing
issues" when trying to sync my Sony Clie SJ30 with evolution. Well, this
is not evolution or gnome-pilot specific as I learned today. Here is
what I have so far:

1) pilot-link's version numbers give me headache, but that's not the
core problem, Anyway:
--
[1850] moi carryme:~ $ pilot-xfer --version
   .--.
   | (c) Copyright 1996-2003, pilot-link team   |
   |   Join the pilot-link lists to help out.   |
   `--'
   This is pilot-xfer, from pilot-link version 0.11.7

   Build target..: i686-pc-linux-gnu
   Build date....: Feb  9 2003 17:26:03

   pilot-link 0.11.7 is covered under the GPL/LGPL
   See the file COPYING under docs for more info.

   Please use -h for more detailed options.
--
This says it is version 0.11.7. This is the first thing I don't
understand. The manpage says in its last line:

--
(c) FSF 1996-2003      pilot-link - 0.11.8          pilot-xfer(1)
Manual page pilot-xfer(1) line 222/252 (END)
--
So according to this it should be 0.11.8.

I installed it from Jamie's packages together with gnome-pilot,
evolution and so on:
--
[1850] moi carryme:~ $ apt-cache policy pilot-link
pilot-link:
  Installed: 0.11.8-4jds1
  Candidate: 0.11.8-4jds1
  Version Table:
*** 0.11.8-4jds1 0
        500 http://ftp.acc.umu.se gnome2.2/ Packages
        100 /var/lib/dpkg/status
     0.9.5.0-8 0
        500 http://ftp.de.debian.org stable/main Packages
--

Okay, now you'll point me at the possibility that there are manually
installed versions on my system. NO!:
--
[1849][root carryme:/]$ updatedb
[1850][root carryme:/]$ locate pilot-xfer
/usr/bin/pilot-xfer
/usr/share/man/man1/pilot-xfer.1.gz
[1850][root carryme:/]$

--
So, there is definitely only _one_ pilot-xfer binary on my box, and that
one claims to be 0.11.7 though Jamie's packages claim to be 0.11.8.
STRANGE. But that is not the timing problem I was talking about. See
below.

2) Kernel: 2.4.20, build from stock kernel.org sources, several times,
working flawlessly, having USB support as modules:
--
[1852][root carryme:/]$ lsmod
Module                  Size  Used by    Not tainted
[...unrelated...]
visor                   8556   0 
usbserial              16508   0  [visor]
keybdev                 1728   0  (unused)
mousedev                3768   1 
hid                    18564   0  (unused)
input                   3296   0  [keybdev mousedev hid]
usb-uhci               21196   0  (unused)
usbcore                61696   1  [visor usbserial hid usb-uhci]
[...unrelated...]
[1856][root carryme:/]$ 
--

Okay, this is all stuff that more or less uses the USB subsystem, and
here the problems start: I'm using usb-uhci since (a) someone once
mentioned it is the standard driver and should be preferred against uhci
(JE-alternative) and (b) vmware requires that one and won't work with
the latter. 
Now, when using usb-uhci I _sometimes_ can connect to my clie (be it in
gnome-pilot running gpilotd or, after killing gpilotd, using
pilot-xfer), apparently when I hit hotsync on the clie and then, a
second or something later start pilot-xfer on the laptop. To make this
clear: I _do_ know and understand that I have to hit hotsync first and
afterwards start pilot-xfer. OK!? 
Using the alternative uhci module, I get connected _every_ _single_
_time_, no matter how long I wait between pressing hotsync and executing
pilot-xfer.
I have recently installed woody on my big machine and that one has a
SIS-Chipset, using the usb-ohci module. On that machine I get connected
every single time, too.

So, apparently the problem I was chasing from time to time over the last
year or so arises from the usb-uhci code. There is something I noticed
in the kernel log when connecting the clie, but you don't have to read
the following output now, I'll come back to it a little later and point
you at the strange lines. 
With usb-uhci I get in /var/log/messages:
--
Nov 25 19:06:40 carryme kernel: hub.c: new USB device 00:07.2-2,
assigned address 5
Nov 25 19:06:40 carryme kernel: Manufacturer: Palm, Inc.
Nov 25 19:06:40 carryme kernel: Product: Palm Handheld
Nov 25 19:06:40 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter detected
Nov 25 19:06:40 carryme kernel: visor.c: Handspring Visor / Palm 4.0 /
Clié 4.x: Number of ports: 2
Nov 25 19:06:40 carryme kernel: visor.c: Handspring Visor / Palm 4.0 /
Clié 4.x: port 1, is for Generic use and is bound to ttyUSB0
Nov 25 19:06:40 carryme kernel: visor.c: Handspring Visor / Palm 4.0 /
Clié 4.x: port 2, is for HotSync use and is bound to ttyUSB1
Nov 25 19:06:40 carryme kernel: usb-uhci.c: interrupt, status 2, frame#
1137
Nov 25 19:06:43 carryme kernel: usb_control/bulk_msg: timeout
Nov 25 19:06:46 carryme kernel: usb_control/bulk_msg: timeout
Nov 25 19:06:46 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter now attached to ttyUSB0 (or usb/tts/0 for devfs)
Nov 25 19:06:46 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter now attached to ttyUSB1 (or usb/tts/1 for devfs)
Nov 25 19:06:54 carryme kernel: usb-uhci.c: interrupt, status 2, frame#
838
Nov 25 19:06:57 carryme kernel: usb_control/bulk_msg: timeout
Nov 25 19:06:58 carryme kernel: usb.c: USB disconnect on device
00:07.2-2 address 5
Nov 25 19:06:58 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter now disconnected from ttyUSB0
Nov 25 19:06:58 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter now disconnected from ttyUSB1

--
Starting pilot-xfer at any time during the appearance of these messages,
it results in saying:

--
[1852] moi carryme:~ $ pilot-xfer -p /dev/ttyUSB1 -l

   Listening to port: /dev/ttyUSB1

   Please press the HotSync button now... 
--
So, no connection possible 99% of my tries. in 01% of my tries it seems
I have the right timing in my fingers to fire up pilot-xfer in the right
moment. STRANGE. THIS IS MY PROBLEM.

Okay, next I try the alternative uhci module. First, I unload visor,
usbserial and then usb-uhci in that order. Second, I modprobe uhci,
usbserial, visor back into kernel again in that order. Finally, I press
hotsync on the clie and get the following in var/log/messages:

--
-- MARK --
Nov 25 19:21:20 carryme kernel: hub.c: new USB device 00:07.2-2,
assigned address 4
Nov 25 19:21:20 carryme kernel: Manufacturer: Palm, Inc.
Nov 25 19:21:20 carryme kernel: Product: Palm Handheld
Nov 25 19:21:20 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter detected
Nov 25 19:21:20 carryme kernel: visor.c: Handspring Visor / Palm 4.0 /
Clié 4.x: Number of ports: 2
Nov 25 19:21:20 carryme kernel: visor.c: Handspring Visor / Palm 4.0 /
Clié 4.x: port 1, is for Generic use and is bound to ttyUSB0
Nov 25 19:21:20 carryme kernel: visor.c: Handspring Visor / Palm 4.0 /
Clié 4.x: port 2, is for HotSync use and is bound to ttyUSB1
Nov 25 19:21:20 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter now attached to ttyUSB0 (or usb/tts/0 for devfs)
Nov 25 19:21:20 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter now attached to ttyUSB1 (or usb/tts/1 for devfs)
Nov 25 19:21:30 carryme kernel: usb.c: USB disconnect on device
00:07.2-2 address 4
Nov 25 19:21:30 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter now disconnected from ttyUSB0
Nov 25 19:21:30 carryme kernel: usbserial.c: Handspring Visor / Palm 4.0
/ Clié 4.x converter now disconnected from ttyUSB1
--

With the uhci module, the pilot-xfer listing command runs no matter how
long I wait before executing it after those lines saying "... attached
to ttyUSB1..." appear in the log. 
As mentioned above, here we return to the usb-uhci output. What makes me
wonder are three additional lines found in /var/log/messages when using
usb-uhci, they are:

--
Nov 25 19:06:40 carryme kernel: usb-uhci.c: interrupt, status 2, frame#
1137
Nov 25 19:06:43 carryme kernel: usb_control/bulk_msg: timeout
Nov 25 19:06:46 carryme kernel: usb_control/bulk_msg: timeout
--

These lines appear twice in that log (see above for the entire log in
the usb-uhci case), just after visor.c has bound to USB1 and just after
usbserial.c has bound to USB1. 

So, here I ask the USB-experts out there: What does that timeout message
mean? Could it be a problem with a lousy USB-Chipset? lspci gives:
--
00:07.2 USB Controller: Intel Corp. 82371AB PIIX4 USB (rev 01)
--
Which belongs to the 440ZX in this HP Omnibook XE3 (PIIIM-700):

--
00:00.0 Host bridge: Intel Corp. 440BX/ZX - 82443BX/ZX Host bridge (rev
03)
00:01.0 PCI bridge: Intel Corp. 440BX/ZX - 82443BX/ZX AGP bridge (rev
03)
--

I found many posts via google dealing with those timeout messages, but
nowhere was an answer that would lead to anything. Hope here someone has
some tips what to try next.

Regards 
Lars



-- 
LarsWeissflog
L rs-W dot DE





[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]