USB timeout

Guy Harper guy at gtv8.org
Wed Dec 5 20:06:55 GMT 2001


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




More information about the Ukfreebsd mailing list