Hi,
I configured my speedtouch usb under a FreeBSD 4.6 computer 3 months
ago. Bu I discovered that it didn't work well when I have a heavy
traffic on the DSL connection. I noticed it with visio conference et I
am able to reproduce error message and disconnection by filling the
connection with traffic.
I find this in the ppp.log:
===========================
connection:
----------------------------------------------------
Jan 6 23:22:18 tataraba ppp[3266]: Phase: deflink: HUPing 3268
Jan 6 23:22:18 tataraba ppp[3266]: Phase: deflink: hangup -> closed
Jan 6 23:22:18 tataraba ppp[3266]: Phase: bundle: Dead
Jan 6 23:22:18 tataraba ppp[3266]: Phase: PPP Terminated (normal).
Jan 6 23:26:12 tataraba ppp[3333]: Phase: Using interface: tun0
Jan 6 23:26:12 tataraba ppp[3333]: Phase: deflink: Created in closed
state
Jan 6 23:26:12 tataraba ppp[3334]: Phase: PPP Started (background
mode).
Jan 6 23:26:12 tataraba ppp[3334]: Phase: bundle: Establish
Jan 6 23:26:12 tataraba ppp[3334]: Phase: deflink: closed -> opening
Jan 6 23:26:12 tataraba ppp[3334]: Phase: deflink: Connected!
Jan 6 23:26:12 tataraba ppp[3334]: Phase: deflink: opening -> dial
Jan 6 23:26:12 tataraba ppp[3334]: Phase: deflink: dial -> carrier
Jan 6 23:26:12 tataraba ppp[3334]: Phase: deflink: carrier -> login
Jan 6 23:26:12 tataraba ppp[3334]: Phase: deflink: login -> lcp
Jan 6 23:26:13 tataraba ppp[3334]: Phase: bundle: Authenticate
Jan 6 23:26:13 tataraba ppp[3334]: Phase: deflink: his = CHAP 0x05,
mine = none
Jan 6 23:26:13 tataraba ppp[3334]: Phase: Chap Input: CHALLENGE (16
bytes from BSVZY101)
Jan 6 23:26:13 tataraba ppp[3334]: Phase: Chap Output: RESPONSE
(<adsl-login>)
Jan 6 23:26:15 tataraba ppp[3334]: Phase: Chap Input: SUCCESS
Jan 6 23:26:15 tataraba ppp[3334]: Phase: deflink: lcp -> open
Jan 6 23:26:15 tataraba ppp[3334]: Phase: bundle: Network
Jan 6 23:26:15 tataraba ppp[3334]: Phase: Unknown protocol 0x8057
(unrecognised protocol)
Jan 6 23:26:16 tataraba ppp[3333]: Phase: Parent: PPP enabled
Jan 6 23:27:15 tataraba ppp[3334]: Phase: deflink: HDLC errors -> FCS:
0, ADDR: 0, COMD: 0, PROTO: 1
----------------------------------------------------
and for the deconection:
----------------------------------------------------
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: ** Too many ECHO LQR
packets lost **
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: open -> lcp
Jan 7 00:08:44 tataraba ppp[3334]: Phase: bundle: Terminate
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: Disconnected!
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: lcp -> logout
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: Disconnected!
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: logout -> hangup
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: Connect time: 2552
secs: 22493154 octets in, 13655717 octets out
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: : 24559 packets in,
27070 packets out
Jan 7 00:08:44 tataraba ppp[3334]: Phase: total 14164 bytes/sec, peak
91070 bytes/sec on Tue Jan 6 23:57:03 2004
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: HUPing 3336
Jan 7 00:08:44 tataraba ppp[3334]: Phase: deflink: hangup -> closed
Jan 7 00:08:44 tataraba ppp[3334]: Phase: bundle: Dead
Jan 7 00:08:44 tataraba ppp[3334]: Phase: PPP Terminated (normal).
----------------------------------------------------
I found on internet forums and newsgroup that LQR errors can be caused
by pppoa2 errors. LQR packats get lost because the connection or the
modem is in space. It has been told that people will eventually found
ENOBUFS errors in pppoa2.log, and that this error is due to
unappropriate kernel values (too little infact).
So I take a look at pppoa2.log and I found this:
================================================
during connection:
-----------------------------------------------------------
Jan 6 23:26:12 tataraba pppoa2[3336]: Starting PPPoA2 ( merged version
includes new ATM/AAL5 stack ) 1.2-beta3
Jan 6 23:26:12 tataraba pppoa2[3336]: I'm the parent process, I
handle the endpoint 0x07
Jan 6 23:26:12 tataraba pppoa2[3336]: pty descriptors : fdin=3, fdout=4
Jan 6 23:26:12 tataraba pppoa2[3336]: Increasing SNDBUF from 2048 to
65536
Jan 6 23:26:12 tataraba pppoa2[3336]: Increasing RCVBUF from 4096 to
65536
Jan 6 23:26:12 tataraba pppoa2[3336]: host --> pppoa2 --> modem stream
ready
Jan 6 23:26:12 tataraba pppoa2[3337]: I'm the children process, I
handle the endpoint 0x87
Jan 6 23:26:12 tataraba pppoa2[3337]: modem --> pppoa2 --> host stream
ready
-----------------------------------------------------------
and I found these errors (when I start loading the connection):
-----------------------------------------------------------
Jan 6 23:57:04 tataraba pppoa2[3337]: write_dest: 1 ENOBUFS errors
Jan 6 23:57:08 tataraba pppoa2[3337]: write_dest: 2 ENOBUFS errors
Jan 6 23:57:08 tataraba pppoa2[3337]: write_dest: 3 ENOBUFS errors
Jan 6 23:57:08 tataraba pppoa2[3337]: write_dest: 4 ENOBUFS errors
Jan 6 23:57:10 tataraba pppoa2[3337]: write_dest: 5 ENOBUFS errors
Jan 6 23:57:10 tataraba pppoa2[3337]: write_dest: 6 ENOBUFS errors
Jan 6 23:57:11 tataraba pppoa2[3337]: write_dest: 7 ENOBUFS errors
Jan 6 23:57:11 tataraba pppoa2[3337]: write_dest: 8 ENOBUFS errors
Jan 6 23:57:11 tataraba pppoa2[3337]: write_dest: 9 ENOBUFS errors
Jan 6 23:57:45 tataraba pppoa2[3337]: write_dest: 100 ENOBUFS errors
Jan 6 23:58:23 tataraba pppoa2[3337]: Junk bytes....
Jan 6 23:58:23 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 6 23:59:03 tataraba pppoa2[3337]: Junk bytes....
Jan 6 23:59:03 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 6 23:59:57 tataraba pppoa2[3337]: Junk bytes....
Jan 6 23:59:57 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:00:43 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3650)/VCI(514)
(OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3655)/VCI(9842) (OAM?) PTI=0x07
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3650)/VCI(514)
(OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3654)/VCI(38422) (OAM?) PTI=0x07
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3650)/VCI(966)
(OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3651)/VCI(49910) (OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3655)/VCI(9814) (OAM?) PTI=0x03
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3650)/VCI(514)
(OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3654)/VCI(38422) (OAM?) PTI=0x07
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3650)/VCI(514)
(OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3655)/VCI(14162) (OAM?) PTI=0x07
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3650)/VCI(514)
(OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3650)/VCI(9186) (OAM?) PTI=0x07
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3650)/VCI(514)
(OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3650)/VCI(62402) (OAM?) PTI=0x07
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3655)/VCI(930)
(OAM?) PTI=0x07
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3654)/VCI(22243) (OAM?) PTI=0x06
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong VPI(3650)/VCI(514)
(OAM?) PTI=0x00
Jan 7 00:00:43 tataraba pppoa2[3337]: Cell had wrong
VPI(3746)/VCI(9186) (OAM?) PTI=0x07
Jan 7 00:01:28 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:01:28 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:02:25 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:02:25 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:02:42 tataraba pppoa2[3337]: write_dest: 200 ENOBUFS errors
Jan 7 00:02:54 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:02:54 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:02:54 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:02:54 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:03:47 tataraba pppoa2[3337]: write_dest: 300 ENOBUFS errors
Jan 7 00:04:06 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:04:06 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:04:16 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:04:16 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:04:53 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:04:53 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:05:05 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:05:05 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:05:13 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:05:13 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:05:30 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:05:30 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:06:41 tataraba pppoa2[3337]: write_dest: 400 ENOBUFS errors
Jan 7 00:06:41 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:06:41 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:06:44 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:06:44 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:07:50 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:07:50 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:08:03 tataraba pppoa2[3337]: Junk bytes....
Jan 7 00:08:03 tataraba pppoa2[3337]: CRC error in an AAL5 frame
Jan 7 00:08:44 tataraba pppoa2[3336]: Killed by a signal 1
-----------------------------------------------------------
>From what I've learned with google, thoses error are due to a lack of
mbuf or nmbclusters and packets get lost, ppp doesn't get back his LQR
packet so it closed pppoa2 with signal 1.
I tried to change my kernel values. But the problem his always the same.
My actual values are:
---------------------
kern.ipc.nmbclusters: 32768
kern.ipc.nmbufs: 65536
kern.ipc.maxsockbuf: 262144
kern.ipc.maxsockets: 32768
MAXUSERS = 128
It's strange because netstat -m (during ENOBUFS errors) give me this:
---------------------------------------------------------------------
871/1392/65536 mbufs in use (current/peak/max):
583 mbufs allocated to data
288 mbufs allocated to socket names and addresses
141/268/32768 mbuf clusters in use (current/peak/max)
884 Kbytes allocated to network (1% of mb_map in use)
0 requests for memory denied
0 requests for memory delayed
0 calls to protocol drain routines
It's strange because my nmbufs value in my kernel configuration is
NMBUFS=16384. pppoa2 seems to increase the value.
And I don't know what the pppoa2 errors means, those like "Cell had
wrong VPI" or "junk bytes".
I'm confused.
Is there a solution ?
Are my NMBUFS value too weak ?
Does this come from ppp or the driver that eat too much kernel ressources ?
--
Roulio
Liste de diffusion modem ALCATEL SpeedTouch USB
Pour se d�sinscrire : mailto:[EMAIL PROTECTED]