speedtch driver, 2.6.14.2

speedtch driver, 2.6.14.2

[Alistair John Strachan]

Hi Duncan,

I recently switched from the userspace speedtouch driver to the in-kernel one. 
However, on my rev 4.0 Speedtouch 330, I periodically get the message:

ATM dev 0: error -110 fetching device status

I suspect the source of this "error" is the warning message from speedtch:435:

	ret = speedtch_read_status(instance);
	if (ret < 0) {
		atm_warn(usbatm, "error %d fetching device status\n", ret);
		instance->poll_delay = min(2 * instance->poll_delay, MAX_POLL_DELAY);
		return;
	}

Tell me if I'm wrong, but I suspect speedtch_check_status() is called 
periodically to check line status. It may be the case that my modem does not 
like having its status read when it is sending/receiving data (which it is 
constantly doing).

Unfortunately the message eventually fills the dmesg ring buffer. My current 
workaround is to remove the atm_warn() call; everything works fine, but I'm 
concerned that the modem will not automatically reconnect if the connection 
drops as a result of the failure from speedtch_read_status().

Any suggestions for debugging this further? From a quick google I've noticed a 
recent Fedora bugzilla entry mentioning this same problem.

-- 
Cheers,
Alistair.

'No sense being pessimistic, it probably wouldn't work anyway.'
Third year Computer Science undergraduate.
1F2 55 South Clerk Street, Edinburgh, UK.

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

Hi Alistair,

> I recently switched from the userspace speedtouch driver to the in-kernel one. 
> However, on my rev 4.0 Speedtouch 330, I periodically get the message:
> 
> ATM dev 0: error -110 fetching device status

-110 means that it timed out.

> I suspect the source of this "error" is the warning message from speedtch:435:
> 
> 	ret = speedtch_read_status(instance);
> 	if (ret < 0) {
> 		atm_warn(usbatm, "error %d fetching device status\n", ret);
> 		instance->poll_delay = min(2 * instance->poll_delay, MAX_POLL_DELAY);
> 		return;
> 	}
> 
> Tell me if I'm wrong, but I suspect speedtch_check_status() is called 
> periodically to check line status. It may be the case that my modem does not 
> like having its status read when it is sending/receiving data (which it is 
> constantly doing).

Well, I have the same modem, and mine doesn't seem to mind!  So something is
strange.

> Unfortunately the message eventually fills the dmesg ring buffer. My current 
> workaround is to remove the atm_warn() call; everything works fine, but I'm 
> concerned that the modem will not automatically reconnect if the connection 
> drops as a result of the failure from speedtch_read_status().

You can test it by unplugging the phone line, then replugging it.

> Any suggestions for debugging this further? From a quick google I've noticed a 
> recent Fedora bugzilla entry mentioning this same problem.

I'll think about it.

All the best,

Duncan.

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

> I recently switched from the userspace speedtouch driver to the in-kernel one. 
> However, on my rev 4.0 Speedtouch 330, I periodically get the message:
> 
> ATM dev 0: error -110 fetching device status

By the way, did you use to monitor the line using modem_run?  Did it work
(and of course: did you get any error messages?).

Ciao,

D.

Re: speedtch driver, 2.6.14.2

[Alistair John Strachan]

On Thursday 24 November 2005 17:01, Duncan Sands wrote:
> > I recently switched from the userspace speedtouch driver to the in-kernel
> > one. However, on my rev 4.0 Speedtouch 330, I periodically get the
> > message:
> >
> > ATM dev 0: error -110 fetching device status
>
> By the way, did you use to monitor the line using modem_run?  Did it work
> (and of course: did you get any error messages?).

I don't use modem_run any more, but when I did (with the userspace driver), I 
would not get any errors whatsoever. It didn't reconnect automatically, 
however.

I'll try enabling USB_DEBUG next time I upgrade that machine's kernel. 
Unfortunately I don't have access to it at the moment (but will within the 
week).

Thanks for the help so far!

-- 
Cheers,
Alistair.

'No sense being pessimistic, it probably wouldn't work anyway.'
Third year Computer Science undergraduate.
1F2 55 South Clerk Street, Edinburgh, UK.

Re: speedtch driver, 2.6.14.2

[Krzysztof Halasa]

Alistair John Strachan <s0348365@sms.ed.ac.uk> writes:

> However, on my rev 4.0 Speedtouch 330, I periodically get the message:
>
> ATM dev 0: error -110 fetching device status

Same here.

defiant:~$ dmesg | grep 'ATM dev 0: error -110 fetching device status' | wc -l
55
defiant:~$ uptime
 23:55:40 up 15 days, 23:34,  6 users,  load average: 0.05, 0.06, 0.06

It works fine, though.
-- 
Krzysztof Halasa

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

On Sunday 27 November 2005 23:58, Krzysztof Halasa wrote:
> Alistair John Strachan <s0348365@sms.ed.ac.uk> writes:
> 
> > However, on my rev 4.0 Speedtouch 330, I periodically get the message:
> >
> > ATM dev 0: error -110 fetching device status
> 
> Same here.
> 
> defiant:~$ dmesg | grep 'ATM dev 0: error -110 fetching device status' | wc -l
> 55
> defiant:~$ uptime
>  23:55:40 up 15 days, 23:34,  6 users,  load average: 0.05, 0.06, 0.06
> 
> It works fine, though.

If you unplug the phone line and plug it back in again, does the line
resynchronize?  Does the driver detect that the line is back up?

Thanks,

D.

Re: speedtch driver, 2.6.14.2

[Krzysztof Halasa]

Duncan Sands <duncan.sands@free.fr> writes:

> If you unplug the phone line and plug it back in again, does the line
> resynchronize?  Does the driver detect that the line is back up?

Sure.
-- 
Krzysztof Halasa

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

> > If you unplug the phone line and plug it back in again, does the line
> > resynchronize?  Does the driver detect that the line is back up?
> 
> Sure.

If you turn on CONFIG_USB_DEBUG, enough info should turn up to be able
to work out which urbs are failing.  That would be helpful.

Ciao,

D.

Re: speedtch driver, 2.6.14.2

[Krzysztof Halasa]

Duncan Sands <duncan.sands@free.fr> writes:

> If you turn on CONFIG_USB_DEBUG, enough info should turn up to be able
> to work out which urbs are failing.  That would be helpful.

dmesg | egrep -i 'usb|atm|speedt' attached.

Firmware? Didn't know I have options :-)
I think it's version 3.012, I got it with ADSL subscriber package
and extracted using (probably) the firmware extractor (the hacked
modem_run). I can verify this if you want.

   935 Nov 27  2004 speedtch-1.bin.4.00
775545 Nov 27  2004 speedtch-2.bin.4.00

MD5:
0503efe8d7efc0fe10e7593cecdb8fb8  speedtch-1.bin.4.00
79300e856fbef976c99fe339be8ba238  speedtch-2.bin.4.00

defiant:/lib/firmware$ cat /proc/bus/usb/devices |grep -B 1 TH
P:  Vendor=06b9 ProdID=4061 Rev= 4.00
S:  Manufacturer=THOMSON


15:54:29 USB Universal Host Controller Interface driver v2.3
15:54:31 uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1
15:54:31 usb usb1: default language 0x0409
15:54:31 usb usb1: new device strings: Mfr=3, Product=2, SerialNumber=1
15:54:31 usb usb1: Product: UHCI Host Controller
15:54:31 usb usb1: Manufacturer: Linux 2.6.14 uhci_hcd
15:54:31 usb usb1: SerialNumber: 0000:00:07.2
15:54:31 usb usb1: hotplug
15:54:31 usb usb1: adding 1-0:1.0 (config #1, interface 0)
15:54:31 usb 1-0:1.0: hotplug
15:54:31 hub 1-0:1.0: usb_probe_interface
15:54:31 hub 1-0:1.0: usb_probe_interface - got id
15:54:31 hub 1-0:1.0: USB hub found
15:54:31 hub 1-0:1.0: no power switching (usb 1.0)
15:54:32 usb 1-1: new full speed USB device using uhci_hcd and address 2
15:54:32 usb 1-1: ep0 maxpacket = 8
15:54:32 usb 1-1: default language 0x0409
15:54:32 usb 1-1: new device strings: Mfr=1, Product=2, SerialNumber=3
15:54:32 usb 1-1: Product: Speed Touch 330
15:54:32 usb 1-1: Manufacturer: THOMSON
15:54:32 usb 1-1: SerialNumber: 000E501A7727
15:54:32 usb 1-1: hotplug
15:54:32 usb 1-1: adding 1-1:1.0 (config #1, interface 0)
15:54:32 usb 1-1:1.0: hotplug
15:54:32 usb 1-1: adding 1-1:1.1 (config #1, interface 1)
15:54:32 usb 1-1:1.1: hotplug
15:54:32 usb 1-1: adding 1-1:1.2 (config #1, interface 2)
15:54:32 usb 1-1:1.2: hotplug
15:54:32 Initializing USB Mass Storage driver...
15:54:33 usbcore: registered new driver usb-storage
15:54:33 USB Mass Storage support registered.
15:54:33 usbatm.c: usbatm_usb_init: driver version 1.9
15:54:33 speedtch.c: speedtch_usb_init: driver version 1.9
15:54:33 speedtch 1-1:1.0: usb_probe_interface
15:54:33 speedtch 1-1:1.0: usb_probe_interface - got id
15:54:33 speedtch 1-1:1.0: usbatm_usb_probe: trying driver speedtch with
         vendor=0x6b9, product=0x4061, ifnum 0
15:54:33 usb 1-1: modprobe timed out on ep0in len=0/1
15:54:33 usb 1-1: reset full speed USB device using uhci_hcd and address 2
15:54:33 usb 1-1: ep0 maxpacket = 8
15:54:33 usbcore: registered new driver speedtch
15:54:33 speedtch 1-1:1.0: found stage 1 firmware speedtch-1.bin.4.00
15:54:33 speedtch 1-1:1.0: found stage 2 firmware speedtch-2.bin.4.00
15:54:34 ATM dev 0: speedtch_atm_start entered
15:54:34 ATM dev 0: speedtch_start_synchro entered
15:54:34 ATM dev 0: speedtch_start_synchro: modem prodded. 2 bytes returned: 00
00
15:54:34 /usr/src/linux-2.6/drivers/usb/atm/usbatm.c: usbatm_get_instance
15:54:34 ATM dev 0: speedtch_check_status entered
15:54:34 ATM dev 0: speedtch_check_status: line state 10
15:54:34 ATM dev 0: ADSL line is synchronising
15:54:34 ATM dev 0: usbatm_atm_open: vpi 0, vci 35
15:54:34 ATM dev 0: usbatm_atm_open: allocated vcc data 0xc7e03be0
15:54:34 ATM dev 0: speedtch_check_status entered
15:54:34 ATM dev 0: speedtch_check_status: line state 10
15:54:34 ATM dev 0: speedtch_check_status entered
15:54:34 ATM dev 0: speedtch_check_status: line state 10
15:54:34 ATM dev 0: speedtch_check_status entered
15:54:34 ATM dev 0: speedtch_check_status: line state 20
15:54:34 ATM dev 0: ADSL line is up (320 kb/s down | 160 kb/s up)
15:54:34 ATM dev 0: speedtch_check_status entered
15:54:34 ATM dev 0: speedtch_check_status: line state 20
15:54:35 ATM dev 0: speedtch_check_status entered
15:54:35 ATM dev 0: speedtch_check_status: line state 20
15:54:40 ATM dev 0: speedtch_check_status entered
15:54:40 ATM dev 0: speedtch_check_status: line state 20

(and so on)

17:03:10 ATM dev 0: speedtch_check_status entered
17:03:10 ATM dev 0: speedtch_check_status: line state 20
17:03:15 ATM dev 0: speedtch_check_status entered
17:03:17 usb 1-1: events/0 timed out on ep0in len=0/4
17:03:17 ATM dev 0: speedtch_read_status: MSG D failed
17:03:17 ATM dev 0: error -110 fetching device status
17:03:20 ATM dev 0: speedtch_check_status entered
17:03:20 ATM dev 0: speedtch_check_status: line state 20
-- 
Krzysztof Halasa

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

Hi Krzysztof, the firmware seems fine.

> 17:03:15 ATM dev 0: speedtch_check_status entered
> 17:03:17 usb 1-1: events/0 timed out on ep0in len=0/4
> 17:03:17 ATM dev 0: speedtch_read_status: MSG D failed
> 17:03:17 ATM dev 0: error -110 fetching device status

Is it always MSG D that fails?  Is failure of this message
correlated with anything else, eg: heavy network use?

Thanks,

Duncan.

Re: speedtch driver, 2.6.14.2

[Krzysztof Halasa]

Hi,

Duncan Sands <duncan.sands@free.fr> writes:

>> 17:03:15 ATM dev 0: speedtch_check_status entered
>> 17:03:17 usb 1-1: events/0 timed out on ep0in len=0/4
>> 17:03:17 ATM dev 0: speedtch_read_status: MSG D failed
>> 17:03:17 ATM dev 0: error -110 fetching device status
>
> Is it always MSG D that fails?

I think so. Since yesterday I have 7 identical MSG D faults and nothing
else.

>  Is failure of this message
> correlated with anything else, eg: heavy network use?

I don't think so. The ADSL was mostly idle last 24 hrs. Only inbound SMTP
mail and the Windows viruses etc. trying to attack something.

I can perform a test with inactive PPP (=no any flow) but I think it will
show up the same.

BTW: it's an old notebook PC, i440BX (PIIX4) based:

00:00.0 Host bridge: Intel 440BX/ZX/DX - 82443BX/ZX/DX Host bridge (rev 03)
00:01.0 PCI bridge: Intel 440BX/ZX/DX - 82443BX/ZX/DX AGP bridge (rev 03)
00:07.0 ISA bridge: Intel 82371AB/EB/MB PIIX4 ISA (rev 02)
00:07.1 IDE interface: Intel 82371AB/EB/MB PIIX4 IDE (rev 01)
00:07.2 USB Controller: Intel 82371AB/EB/MB PIIX4 USB (rev 01)
00:07.3 Bridge: Intel 82371AB/EB/MB PIIX4 ACPI (rev 03)
00:0a.0 CardBus bridge: Texas Instruments PCI1225 (rev 01)
00:0a.1 CardBus bridge: Texas Instruments PCI1225 (rev 01)
00:0d.0 ESS Technology ES1983S Maestro-3i PCI Audio Accelerator
00:0d.1 ESS Technology ES1983S Maestro-3i PCI Modem Accelerator
01:00.0 VGA: Silicon Motion, Inc. SM720 Lynx3DM (rev b1)
02:00.0 Ethernet: DECchip 21142/43 (rev 41)
-- 
Krzysztof Halasa

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

> ... Since yesterday I have 7 identical MSG D faults and nothing
> else.

Does increasing the value of CTRL_TIMEOUT help?

D.

Re: speedtch driver, 2.6.14.2

[Krzysztof Halasa]

Duncan Sands <duncan.sands@free.fr> writes:

>> ... Since yesterday I have 7 identical MSG D faults and nothing
>> else.
>
> Does increasing the value of CTRL_TIMEOUT help?

I've increased it to 4 seconds, no change. It looks like the response
(or request) is lost somewhere.

The answer is always the same second:

Dec  1 15:20:32 defiant kernel: ATM dev 0: speedtch_check_status entered
Dec  1 15:20:32 defiant kernel: ATM dev 0: speedtch_check_status: line state 20
Dec  1 15:20:37 defiant kernel: ATM dev 0: speedtch_check_status entered
Dec  1 15:20:37 defiant kernel: ATM dev 0: speedtch_check_status: line state 20
Dec  1 15:20:42 defiant kernel: ATM dev 0: speedtch_check_status entered
Dec  1 15:20:42 defiant kernel: ATM dev 0: speedtch_check_status: line state 20

... or it doesn't come at all:

Dec  1 15:20:47 defiant kernel: ATM dev 0: speedtch_check_status entered
Dec  1 15:20:51 defiant kernel: usb 1-1: events/0 timed out on ep0in len=0/4
Dec  1 15:20:51 defiant kernel: ATM dev 0: speedtch_read_status: MSG D failed
Dec  1 15:20:51 defiant kernel: ATM dev 0: error -110 fetching device status

Do the speedtouches have some means (firmware) for debugging or logging?
We would need to see what does the ADSL receive and what does it think
about it.
-- 
Krzysztof Halasa

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

> Do the speedtouches have some means (firmware) for debugging or logging?
> We would need to see what does the ADSL receive and what does it think
> about it.

I don't even have any specs...

D.

Re: speedtch driver, 2.6.14.2

[Krzysztof Halasa]

Duncan Sands <duncan.sands@free.fr> writes:

>> Do the speedtouches have some means (firmware) for debugging or logging?
>> We would need to see what does the ADSL receive and what does it think
>> about it.
>
> I don't even have any specs...

"strings" on the fw binary shows there is some debugger (SACHEM-LT and
possibly more things). It probably needs some terminal interface,
there might be some diagnostic port (usually TTL-level RS232) on board
or (in this case almost certainly) it's created over USB.

It would require some amount of work, not sure if it's worth it.
-- 
Krzysztof Halasa

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

Hi Krzysztof,

> Dec  1 15:20:47 defiant kernel: ATM dev 0: speedtch_check_status entered
> Dec  1 15:20:51 defiant kernel: usb 1-1: events/0 timed out on ep0in len=0/4
> Dec  1 15:20:51 defiant kernel: ATM dev 0: speedtch_read_status: MSG D failed
> Dec  1 15:20:51 defiant kernel: ATM dev 0: error -110 fetching device status

by an amazing coincidence, exactly the same thing happened to me yesterday.  I
had plugged and unplugged the phone line several times during the day, so maybe
I will be able to reproduce it at will.

Ciao,

Duncan.

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

Which firmware are you using?

D.

Re: speedtch driver, 2.6.14.2

[Duncan Sands]

> I recently switched from the userspace speedtouch driver to the in-kernel one. 
> However, on my rev 4.0 Speedtouch 330, I periodically get the message:
> 
> ATM dev 0: error -110 fetching device status

Is this correlated with disk activity (heavy use of the pci bus)?

Thanks,

Duncan.

Re: speedtch driver, 2.6.14.2

[Andrew Walrond]

On Friday 13 January 2006 12:15, Duncan Sands wrote:
> > I recently switched from the userspace speedtouch driver to the in-kernel
> > one. However, on my rev 4.0 Speedtouch 330, I periodically get the
> > message:
> >
> > ATM dev 0: error -110 fetching device status

Me too.

log-2005-12-08-08:39:10:Dec  5 04:34:34 [kernel] ATM dev 0: error -110 
fetching device status
log-2005-12-31-24:59:59:Dec 14 18:17:59 [kernel] ATM dev 0: error -110 
fetching device status
current:Jan 12 11:32:33 [kernel] ATM dev 0: error -110 fetching device status

So it happens every two/three weeks. I have to reboot to get the ADSL line 
back up.

>
> Is this correlated with disk activity (heavy use of the pci bus)?
>

Not here. This is an essentially idle mail server, using ADSL as backup net 
connection.

$ uptime
 13:26:09 up 17:08,  0 users,  load average: 0.01, 0.01, 0.00

$ uname -a
Linux pelagius.h-e-r-e-s-y.com 2.6.14.2 #1 SMP PREEMPT Sat Nov 12 21:01:17 GMT 
2005 i686 unknown unknown GNU/Linux

I guess people running desktops rarely notice the problem, since they are 
likely to power cycle more frequently than the error occurs. For long lived 
servers, its quite a nuisance.

Let me know if I can do anything to help track this down. I'm happy to run an 
instrumented kernel if that would help.

Andrew Walrond

Re: speedtch driver, 2.6.14.2

[Alistair John Strachan]

On Friday 13 January 2006 12:15, Duncan Sands wrote:
> > I recently switched from the userspace speedtouch driver to the in-kernel
> > one. However, on my rev 4.0 Speedtouch 330, I periodically get the
> > message:
> >
> > ATM dev 0: error -110 fetching device status
>
> Is this correlated with disk activity (heavy use of the pci bus)?

No, the machine is completely idle. However I switched to the CVS driver (it 
does not work in isochronous mode still), and in bulk-mode it gives me a new 
set of messages:

ATM dev 0: speedtch_read_status: MSG E failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG F failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG F failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG D failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG D failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG D failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG B failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG B failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG B failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG F failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG F failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG B failed
ATM dev 0: error -110 fetching device status
ATM dev 0: speedtch_read_status: MSG F failed
ATM dev 0: error -110 fetching device status

This seems to happen less often than with the kernel driver, however.

-- 
Cheers,
Alistair.

'No sense being pessimistic, it probably wouldn't work anyway.'
Third year Computer Science undergraduate.
1F2 55 South Clerk Street, Edinburgh, UK.