Date: Fri, 19 Nov 1999 05:06:47 +0100 (CET) From: Marc van Woerkom <van.woerkom@netcologne.de> To: freebsd-isdn@freebsd.org Subject: Infinite loop (sppp/lcp) Message-ID: <199911190406.FAA13704@oranje.my.domain>
next in thread | raw e-mail | index | archive | help
Dear ISDN people,
from last Thursday on I was suddenly no longer able to
connect to my ISP via ISDN and the i4b package from a mid
October 4.0-current.
Dang!
This was very strange, because I had not changed the system at
all for two weeks.
So I first thought about a problem with my hardware or the phone
company, NetCologne, which is also my ISP.
But they told me that they changed nothing at all.
Hmm. So I took a look at the last milestones/drastic changes in
src/UPGRADE and wasted the weekend applying combinatorics on the
isdnd configuration file and building at least 6 older -current
snapshot from CVS (it is a time like that, when I feel deep
respect for the complexity of i4b and what a mirrored FreeBSD
CVS repository is worth)
Because I badly needed the Internet access back, I decided to
fix this, despite lack of knowledge in that field.
The sppp stuff featured in the i4b FAQ, the sppp man page and
the sources to sppp are not comprehendable without having
read the ppp RFC 1661. It was my luck that I had it on some
ancient Linux CD-ROM.
I was able to understand that output from
ifconfig isp0 debug
tcpdump -i isp0
isdntrace
to a large degree now. And found that I got stuck in
loop at the sppp layer, in the lcp phase.
Nov 19 03:09:42 oranje /kernel: isp0: lcp input(ack-sent): <conf-req id=0x5 len=26 03-04-c0-23-05-06-fc-ca-1c-ce-11-04-05-f4-13-08-01-73-74-61-63-6b>
Nov 19 03:09:42 oranje /kernel: isp0: lcp parse opts: auth-proto magic lcp/0x11 lcp/0x13
Nov 19 03:09:42 oranje /kernel: isp0: lcp parse opt values: auth-proto magic 0xfcca1cce lcp/0x11 [NetCologne: ignore 0x11] lcp/0x13 [NetCologne: ignore 0x13] send conf-ack
Nov 19 03:09:42 oranje /kernel: isp0: lcp output <conf-ack id=0x5 len=26 03-04-c0-23-05-06-fc-ca-1c-ce-11-04-05-f4-13-08-01-73-74-61-63-6b>
Nov 19 03:09:44 oranje /kernel: isp0: lcp input(ack-sent): <conf-req id=0x6 len=26 03-04-c0-23-05-06-fc-ca-1c-ce-11-04-05-f4-13-08-01-73-74-61-63-6b>
Nov 19 03:09:44 oranje /kernel: isp0: lcp parse opts: auth-proto magic lcp/0x11 lcp/0x13
Nov 19 03:09:44 oranje /kernel: isp0: lcp parse opt values: auth-proto magic 0xfcca1cce lcp/0x11 [NetCologne: ignore 0x11] lcp/0x13 [NetCologne: ignore 0x13] send conf-ack
Nov 19 03:09:44 oranje /kernel: isp0: lcp output <conf-ack id=0x6 len=26 03-04-c0-23-05-06-fc-ca-1c-ce-11-04-05-f4-13-08-01-73-74-61-63-6b>
Shortly after I recognized this, I got the idea to weed
to the old messages from this mailing list I had on
my system and indeed found a couple of mails describing
the same problem. Especially the one from another
NetCologne user was helpful, because it assured me that
it was not my hardware.
I called him later (hi! :) and he gave me the tip to
use an older i4b version (0.71).
Via CVS I was able to see what i4b version was
integerated when in -current. However 0.71 corresponds
to a -current version that I deemed to old to be useful.
So I had no other choice than to hack the sppp driver.
This finally let's me write this to you folks at an
insane time.. but I am happy it works now again.
My solution for all fellow sufferers is the patch below.
The reasoning behind it goes like this:
- I assume that the peer:conf-req <-> me:conf-ack
infinite loop is caused because a conf-ack from peer is
not reaching my sppp layer
- This is based on looking at the lcp dump of a successful
NetCologne ppp connect, posted here and a look of ppp's
finite state automaton defined in RFC 1661:
| State
| 6 7 8 9
Events| Req-Sent Ack-Rcvd Ack-Sent Opened
------+-----------------------------------------
Up | - - - -
Down | 1 1 1 tld/1
Open | 6 7 8 9r
Close|irc,str/4 irc,str/4 irc,str/4 tld,irc,str/4
|
TO+ | scr/6 scr/6 scr/8 -
TO- | tlf/3p tlf/3p tlf/3p -
|
RCR+ | sca/8 sca,tlu/9 sca/8 tld,scr,sca/8
RCR- | scn/6 scn/7 scn/6 tld,scr,scn/6
RCA | irc/7 scr/6x irc,tlu/9 tld,scr/6x
RCN |irc,scr/6 scr/6x irc,scr/8 tld,scr/6x
|
RTR | sta/6 sta/6 sta/6 tld,zrc,sta/5
RTA | 6 6 8 tld,scr/6
|
RUC | scj/6 scj/7 scj/8 scj/9
RXJ+ | 6 6 8 9
RXJ- | tlf/3 tlf/3 tlf/3 tld,irc,str/5
|
RXR | 6 7 8 ser/9
Imagine the automaton at the peer. He must have
gotten my RCA (rcvd conf-ack) while being in state 6
after bombing me with conf-reqs.
So he should simply reset his timer (irc) and move
on to state 7, waiting for an acceptable conf-req
from me (sca), signaling the link is up (tlu)
and going into state 9.
But it does not. For some reason it does answer
every of my conf-acks with the same stupid conf-req.
My explanation is that the sppp layer has some
distorted input.
However, it must be a very deep glitch in i4b,
at some lower layer, if I am right because the isdntrace
of the B-channel data I did corresponded exactly to the
data the sppp driver saw.
- These strange messages in the isdnd log:
19.11.1999 03:15:18 DBG sendm_connect_req: ctrl = 0, chan = -1
19.11.1999 03:15:18 DBG decr_free_channels: ctrl 0, now 1 chan free
19.11.1999 03:15:18 CHD 00008 NetCologne dialing out from 2769007 to 9174510
19.11.1999 03:15:18 DBG set_channel_busy: controller [0] channel B1 set to BUSY!
-> 19.11.1999 03:15:18 CHD 00008 NetCologne outgoing call proceeding (ctl 0, ch 0)
-> 19.11.1999 03:15:19 DBG set_channel_busy: controller [0] channel B1 already busy!
19.11.1999 03:15:19 CHD 00008 NetCologne outgoing call active (ctl 0, ch 0, isp0)
Or is it normal that 'B1 already busy' message?
Could some glitch here result in some lost or duplicate data frames in the higher
i4b levels?
So I assumed everything is well, and that I got his ack and he got me ack
and simply force a tlu with the patch.
Not nice, maybe even stupid, but it put me back into business:
Nov 19 03:28:29 oranje /kernel: isp0: lcp input(ack-sent): <conf-req id=0x5 len=26 03-04-c0-23-05-06-fc-db-4f-9d-11-04-05-f4-13-08-01-73-74-61-63-6b>
Nov 19 03:28:29 oranje /kernel: isp0: lcp parse opts: auth-proto magic lcp/0x11 lcp/0x13
Nov 19 03:28:29 oranje /kernel: isp0: lcp parse opt values: auth-proto magic 0xfcdb4f9d lcp/0x11 [NetCologne: ignore 0x11] lcp/0x13 [NetCologne: ignore 0x13] send conf-ack
Nov 19 03:28:29 oranje /kernel: isp0: lcp output <conf-ack id=0x5 len=26 03-04-c0-23-05-06-fc-db-4f-9d-11-04-05-f4-13-08-01-73-74-61-63-6b>
Nov 19 03:28:29 oranje /kernel: fall through NC>
Nov 19 03:28:29 oranje /kernel:
Nov 19 03:28:29 oranje /kernel: {opened}
Nov 19 03:28:29 oranje /kernel: isp0: lcp tlu
Nov 19 03:28:29 oranje /kernel: isp0: phase authenticate
..
Nov 19 03:28:31 oranje /kernel: isp0: pap success
Nov 19 03:28:31 oranje /kernel: isp0: phase network
Nov 19 03:28:31 oranje /kernel: isp0: ipcp open(initial)
Gotcha! :-)
Good night,
Marc
I am referring to:
$FreeBSD: src/sys/net/if_spppsubr.c,v 1.57 1999/10/29 17:57:42 joerg Exp $
--- if_spppsubr.c.orig Wed Nov 17 01:45:26 1999
+++ if_spppsubr.c Fri Nov 19 03:20:44 1999
@@ -1296,7 +1296,6 @@
(cp->tld)(sp);
(cp->scr)(sp);
/* fall through... */
- case STATE_ACK_SENT:
case STATE_REQ_SENT:
sppp_cp_change_state(cp, sp, rv?
STATE_ACK_SENT: STATE_REQ_SENT);
@@ -1307,6 +1306,9 @@
sppp_cp_change_state(cp, sp, rv?
STATE_ACK_SENT: STATE_REQ_SENT);
break;
+ case STATE_ACK_SENT:
+ printf("<fall through NC>\n");
+
case STATE_ACK_RCVD:
if (rv) {
sppp_cp_change_state(cp, sp, STATE_OPENED);
@@ -1787,6 +1789,9 @@
{
sp->state[cp->protoidx] = newstate;
+ printf("\n{%s}\n",
+ sppp_state_name(sp->state[cp->protoidx]));
+
UNTIMEOUT(cp->TO, (void *)sp, sp->ch[cp->protoidx]);
switch (newstate) {
case STATE_INITIAL:
@@ -1989,6 +1994,12 @@
*/
sp->pp_flags |= PP_NEEDAUTH;
continue;
+
+ /* Hack MvW */
+ case 0x11:
+ case 0x13:
+ continue;
+
default:
/* Others not supported. */
if (debug)
@@ -2102,6 +2113,15 @@
p[4] = CHAP_MD5;
break;
}
+ continue;
+ case 0x11:
+ if (debug)
+ addlog("[NetCologne: ignore 0x11] ");
+ continue;
+
+ case 0x13:
+ if (debug)
+ addlog("[NetCologne: ignore 0x13] ");
continue;
}
/* Add the option to nak'ed list. */
To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-isdn" in the body of the message
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?199911190406.FAA13704>