Subject: Re: ISDN Config Problem
To: Martin Husemann <martin@duskware.de>
From: Richard Ibbotson <richard@sheflug.co.uk>
List: port-i386
Date: 06/15/2004 21:26:58
Martin

> Ok - could you try again with the ppp interface in debug mode?
>   ifconfig ippp0 debug 
> should do that (if you are using ippp0)


The debug message that you can see below suggests carrier loss.  
Although, how that could happen on a British Telecom ISDN line whilst 
running some updates which are each about 2MB to 10Mb in size I've no 
idea.  I think myself that the "carrier loss" mentioned in the logs 
means something else.

Have a read of the logs below and let me know what you think it might 
be...


Jun 15 21:09:27 debroglie /netbsd: ippp0: lcp open(initial)
Jun 15 21:09:27 debroglie /netbsd: ippp0: phase establish
Jun 15 21:09:27 debroglie isdnd[105]: CHD 00182 i4b rate 60 sec/unit 
(conf)
Jun 15 21:09:27 debroglie isdnd[105]: CHD 00182 i4b dialing out from 
xxxxxxxx to xxxxxxxxx
Jun 15 21:09:28 debroglie isdnd[105]: CHD 00182 i4b outgoing call 
proceeding (ctl 0, ch 0)
Jun 15 21:09:28 debroglie /netbsd: ippp0: Up event
Jun 15 21:09:28 debroglie /netbsd: ippp0: lcp up(starting)
Jun 15 21:09:28 debroglie /netbsd: ippp0: lcp output <conf-req id=0x8c 
len=10 05-06-56-f3-2f-43>
Jun 15 21:09:28 debroglie isdnd[105]: CHD 00182 i4b outgoing call 
active (ctl 0, ch 0, ippp0)
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp TO(req-sent) rst_counter 
= 10
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp output <conf-req id=0x8d 
len=10 05-06-56-f3-2f-43>
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp input(req-sent): 
<conf-req id=0x1 len=28 
03-05-c2-23-05-05-06-c2-45-b6-98-11-04-05-f4-13-09-01-42-54-4d-44-49-50>
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp parse opts: auth-proto 
magic 0x11 [rej] 0x13 [rej] send conf-rej
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp output <conf-rej id=0x1 
len=17 11-04-05-f4-13-09-01-42-54-4d-44-49-50>
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp input(req-sent): 
<conf-ack id=0x8d len=10 05-06-56-f3-2f-43>
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp input(ack-rcvd): 
<conf-req id=0x2 len=15 03-05-c2-23-05-05-06-c2-45-b6-98>
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp parse opts: auth-proto 
magic
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp parse opt values:  
auth-proto magic 0xc245b698 send conf-ack
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp output <conf-ack id=0x2 
len=15 03-05-c2-23-05-05-06-c2-45-b6-98>
Jun 15 21:09:29 debroglie /netbsd: ippp0: lcp tlu
Jun 15 21:09:29 debroglie /netbsd: ippp0: phase authenticate
Jun 15 21:09:29 debroglie /netbsd: ippp0: chap input <challenge id=0x1 
len=27 name=BTMDIP value-size=16 value= 
cd-5b-6f-ad-e0-41-8f-89-e0-c0-32-b2-af-9f-91-c0>
Jun 15 21:09:29 debroglie /netbsd: ippp0: chap output <response id=0x1 
len=29 
10-4f-a1-63-9e-17-fa-2b-61-0c-86-d8-77-fc-ef-8b-c9-31-30-30-30-35-32-38-34>
Jun 15 21:09:30 debroglie /netbsd: ippp0: chap success
Jun 15 21:09:30 debroglie /netbsd: ippp0: phase network
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp open(initial)
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipv6cp open(closed)
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipv6cp output <conf-req 
id=0xcd len=14 01-0a-02-10-a7-ff-fe-02-6f-2e>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp up(starting)
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp output <conf-req 
id=0x67 len=10 03-06-00-00-00-00>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp input(req-sent): 
<conf-req id=0x1 len=16 02-06-00-2d-0f-00-03-06-c2-f7-2f-04>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp parse opts: compression 
[rej] address send conf-rej
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp output <conf-rej id=0x1 
len=10 02-06-00-2d-0f-00>
Jun 15 21:09:30 debroglie /netbsd: ippp0: lcp input(opened): 
<proto-rej id=0x1 len=20 
80-57-01-cd-00-0e-01-0a-02-10-a7-ff-fe-02-6f-2e>
Jun 15 21:09:30 debroglie /netbsd: ippp0: lcp: RXJ+ (proto-rej) for 
proto 0x8057 (ipv6cp/req-sent)
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipv6cp close(req-sent)
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipv6cp output <term-req 
id=0xce len=4>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp input(req-sent): 
<conf-nak id=0x67 len=10 03-06-c2-f7-28-ea>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp nak opts: address 
[wantaddr 194.247.40.234] [agree]
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp output <conf-req 
id=0x68 len=10 03-06-c2-f7-28-ea>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp input(req-sent): 
<conf-req id=0x2 len=10 03-06-c2-f7-2f-04>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp parse opts: address
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp parse opt values:  
address 0.0.0.1 [ack] send conf-ack
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp output <conf-ack id=0x2 
len=10 03-06-c2-f7-2f-04>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp input(ack-sent): 
<conf-ack id=0x68 len=10 03-06-c2-f7-28-ea>
Jun 15 21:09:30 debroglie /netbsd: ippp0: ipcp tlu
Jun 15 21:09:31 debroglie /netbsd: ippp0: lcp input(opened): <echo-req 
id=0x1 len=12 c2-45-b6-98-56-f3-2f-43>
Jun 15 21:09:31 debroglie /netbsd: ippp0: got lcp echo req, sending 
echo rep
Jun 15 21:09:31 debroglie /netbsd: ippp0: lcp output <echo-reply 
id=0x1 len=12 56-f3-2f-43-56-f3-2f-43>
Jun 15 21:09:31 debroglie /netbsd: ippp0: ipv6cp TO(closing) 
rst_counter = 2
Jun 15 21:09:31 debroglie /netbsd: ippp0: ipv6cp output <term-req 
id=0xcf len=4>
Jun 15 21:09:32 debroglie /netbsd: ippp0: ipv6cp TO(closing) 
rst_counter = 1
Jun 15 21:09:32 debroglie /netbsd: ippp0: ipv6cp output <term-req 
id=0xd0 len=4>
Jun 15 21:09:33 debroglie /netbsd: ippp0: ipv6cp TO(closing) 
rst_counter = 0
Jun 15 21:10:12 debroglie /netbsd: ippp0: lcp input(opened): <echo-req 
id=0x2 len=12 c2-45-b6-98-56-f3-2f-43>
Jun 15 21:10:12 debroglie /netbsd: ippp0: got lcp echo req, sending 
echo rep
Jun 15 21:10:12 debroglie /netbsd: ippp0: lcp output <echo-reply 
id=0x2 len=12 56-f3-2f-43-56-f3-2f-43>
Jun 15 21:10:22 debroglie /netbsd: ippp0: lcp input(opened): <echo-req 
id=0x3 len=12 c2-45-b6-98-56-f3-2f-43>
Jun 15 21:10:22 debroglie /netbsd: ippp0: got lcp echo req, sending 
echo rep
Jun 15 21:10:22 debroglie /netbsd: ippp0: lcp output <echo-reply 
id=0x3 len=12 56-f3-2f-43-56-f3-2f-43>
Jun 15 21:10:29 debroglie /netbsd: ippp0: lcp down(opened)
Jun 15 21:10:29 debroglie /netbsd: ippp0: phase terminate
Jun 15 21:10:29 debroglie /netbsd: ippp0: ipcp down(opened)
Jun 15 21:10:29 debroglie /netbsd: ippp0: ipcp close(starting)
Jun 15 21:10:29 debroglie /netbsd: ippp0: Down event (carrier loss)
Jun 15 21:10:29 debroglie /netbsd: ippp0: lcp close(starting)
Jun 15 21:10:29 debroglie /netbsd: ippp0: phase dead
Jun 15 21:10:29 debroglie isdnd[105]: CHD 00182 i4b outgoing call 
disconnected (local)
Jun 15 21:10:29 debroglie isdnd[105]: CHD 00182 i4b cause 0: normal 
call clearing (I4B)
Jun 15 21:10:29 debroglie isdnd[105]: CHD 00182 i4b charging: 1 units, 
61 seconds
Jun 15 21:10:29 debroglie isdnd[105]: CHD 00182 i4b accounting: in 
36421, out 17934
Jun 15 21:10:42 debroglie /netbsd: ippp0: lcp open(initial)
Jun 15 21:10:42 debroglie /netbsd: ippp0: phase establish
Jun 15 21:10:42 debroglie isdnd[105]: CHD 00183 i4b rate 60 sec/unit 
(conf)
Jun 15 21:10:42 debroglie isdnd[105]: CHD 00183 i4b dialing out from 
xxxx xxxxx to xxxxx xxx





Richard