USB timeout

[Mark Hughes]

This would be BT Openworld messing about. Mine worked fine for months, then
a few weeks ago (see
http://www.digitalspy.co.uk/displayarticle.php?id=4282) everything was
knocked out for a while on ALL ADSL lines. Since then it's been kinda...
patchy - and every so often it does this rapid connect/disconnect thing. It
sorts itself out usually after a while though... If your's hasn't sorted
itself out, then I may be wrong :D

Hope this helps,
Mark

----- Original Message -----
From: "Guy Harper" <guy at gtv8.org>
To: "FreeBSD UK User Group" <freebsd-users at uk.freebsd.org>
Sent: Wednesday, December 05, 2001 8:06 PM
Subject: USB timeout


> Hi,
>
> Been having issues using the Alcatel pppoa driver for BT Openworld USB
> modem.
>
> Trawling through the logs, it seems the issue boils down to:
>
> (from pppoa.log)
>
> < pid=505 > [Fri Nov 16 16:01:07 2001] Error reading from usb
> Reason: Operation timed out
>
> Complete transcript of each connection:
>
> PPPoA2 version 15082001
> Log started on Fri Nov 16 16:01:05 2001
>
> * pid=504 * : I'm the parent   process, I handle the endpoint 0x07
> < pid=504 > [Fri Nov 16 16:01:05 2001] pty descriptors : fdin=3, fdout=4
> < pid=504 > [Fri Nov 16 16:01:05 2001] Increasing SNDBUF from 2048 to
65536
> < pid=504 > [Fri Nov 16 16:01:05 2001] Increasing RCVBUF from 4096 to
65536
> * pid=505 * : I'm the children process, I handle the endpoint 0x87
> < pid=505 > [Fri Nov 16 16:01:07 2001] Error reading from usb
> Reason: Operation timed out
>
>
> This happens approximately every two seconds. As such, I see rather a
> lot of packet loss across the line.
>
> I'm a little short of ideas, having looked in /etc/usbd.conf and found
> no time out parameters to play with. The BIOS contains no such
> configurable options. I've tried to ensure that the ppp device is kept
> busy throughout, without any success either.
>
> As you can see below, the machine connects and authenticates without
> issues, but sadly it's short lived...
>
>
> Any help would be **hugely** appreciated.
>
>
> ppp.log has this to report:
>
> Nov 16 16:01:05 tss ppp[249]: tun0: Phase: bundle: Establish
> Nov 16 16:01:05 tss ppp[249]: tun0: Phase: deflink: closed -> opening
> Nov 16 16:01:05 tss ppp[249]: tun0: Phase: deflink: Connected!
> Nov 16 16:01:05 tss ppp[249]: tun0: Phase: deflink: opening -> dial
> Nov 16 16:01:05 tss ppp[249]: tun0: Chat: deflink: Dial attempt 1 of
10000
> Nov 16 16:01:05 tss ppp[249]: tun0: Phase: deflink: dial -> carrier
> Nov 16 16:01:05 tss ppp[249]: tun0: Phase: deflink: carrier -> login
> Nov 16 16:01:05 tss ppp[249]: tun0: Phase: deflink: login -> lcp
> Nov 16 16:01:06 tss ppp[249]: tun0: Phase: bundle: Authenticate
> Nov 16 16:01:06 tss ppp[249]: tun0: Phase: deflink: his = CHAP 0x05, mine
= none
>
> Nov 16 16:01:06 tss ppp[249]: tun0: Phase: Chap Input: CHALLENGE (16
> bytes from BTHG304_HG2.Bletchley)
> Nov 16 16:01:06 tss ppp[249]: tun0: Phase: Chap Output: RESPONSE
> (xxxxxx at hg23.btclick.com)
> Nov 16 16:01:06 tss ppp[249]: tun0: Phase: Chap Input: SUCCESS
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: Using trigger address 0.0.0.0
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP: FSM: Using "deflink" as a
> transport
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP: deflink: State change Initial
> --> Closed
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP: deflink: LayerStart.
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP: MPPE: Not usable without CHAP81
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP: deflink: SendConfigReq(1) state
> = Closed
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP:  DEFLATE[4] win 15
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP:  PRED1[2]
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP: deflink: State change Closed
> --> Req-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: Phase: deflink: lcp -> open
> Nov 16 16:01:06 tss ppp[249]: tun0: Phase: bundle: Network
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: FSM: Using "deflink" as a
transport
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: State change Initial
> --> Closed
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: LayerStart.
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: SendConfigReq(178)
> state = Closed
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  IPADDR[6]  0.0.0.0
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  COMPPROTO[6]  16 VJ slots
> with slot compression
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  PRIDNS[6]  213.120.62.103
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  SECDNS[6]  213.120.62.104
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: State change Closed
> --> Req-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: RecvConfigReq(76)
> state = Req-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  IPADDR[6]  217.32.62.73
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: SendConfigAck(76)
> state = Req-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  IPADDR[6]  217.32.62.73
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: State change Req-Sent
> --> Ack-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: CCP: deflink: State change Req-Sent
> --> Stopped
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: RecvConfigRej(178)
> state = Ack-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  COMPPROTO[6]  16 VJ slots
> with slot compression
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: SendConfigReq(179)
> state = Ack-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  IPADDR[6]  0.0.0.0
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  PRIDNS[6]  213.120.62.103
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  SECDNS[6]  213.120.62.104
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: RecvConfigNak(179)
> state = Ack-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  IPADDR[6]  217.34.239.158
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  IPADDR[6]  changing address:
> 0.0.0.0 --> 217.34.239.158
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: SendConfigReq(180)
> state = Ack-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  IPADDR[6]  217.34.239.158
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  PRIDNS[6]  213.120.62.103
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP:  SECDNS[6]  213.120.62.104
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: RecvConfigAck(180)
> state = Ack-Sent
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: State change Ack-Sent
> --> Opened
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: deflink: LayerUp.
> Nov 16 16:01:06 tss ppp[249]: tun0: IPCP: myaddr 217.34.239.158 hisaddr
> = 217.32.62.73
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: read (0): Connection
> reset by peer
> Nov 16 16:01:08 tss ppp[249]: tun0: CCP: deflink: State change Stopped
> --> Closed
> Nov 16 16:01:08 tss ppp[249]: tun0: CCP: deflink: State change Closed
> --> Initial
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: open -> lcp
> Nov 16 16:01:08 tss ppp[249]: tun0: IPCP: deflink: LayerDown:
> 217.34.239.158
> Nov 16 16:01:08 tss ppp[249]: tun0: IPCP: Using trigger address 0.0.0.0
> Nov 16 16:01:08 tss ppp[249]: tun0: IPCP: deflink: State change Opened
> --> Start ing
> Nov 16 16:01:08 tss ppp[249]: tun0: IPCP: deflink: LayerFinish.
> Nov 16 16:01:08 tss ppp[249]: tun0: IPCP: Connect time: 2 secs: 0 octets
> in, 368 octets out
> Nov 16 16:01:08 tss ppp[249]: tun0: IPCP: : 93 packets in, 213 packets
out
> Nov 16 16:01:08 tss ppp[249]: tun0: IPCP:  total 184 bytes/sec, peak 184
> bytes/sec on Fri Nov 16 16:01:08 2001
> Nov 16 16:01:08 tss ppp[249]: tun0: IPCP: deflink: State change Starting
> --> Initial
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: bundle: Terminate
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: Disconnected!
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: lcp -> logout
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: Disconnected!
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: logout -> hangup
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: Connect time: 3
> secs: 297 octets in, 895 octets out
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: : 1213 packets in,
> 1397 packets out
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase:  total 397 bytes/sec, peak
> 397 bytes/sec on Fri Nov 16 16:01:08 2001
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: HUPing 504
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: deflink: hangup -> closed
> Nov 16 16:01:08 tss ppp[249]: tun0: Phase: bundle: Dead
>
>
>
>
> rgds,
> --
> ./guy.h
>
> ------ FreeBSD UK Users' Group  -  Mailing List ------
> http://listserver.uk.freebsd.org/mailman/listinfo/freebsd-users
>