Subject: pkg/25037: user ppp from pkgsrc doesn't connect to isdnd
To: None <gnats-bugs@gnats.NetBSD.org>
From: Hanspeter Roth <hampi@rootshell.be>
List: pkgsrc-bugs
Date: 04/03/2004 17:08:52
>Number:         25037
>Category:       pkg
>Synopsis:       user ppp from pkgsrc doesn't connect to isdnd
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    pkg-manager
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sat Apr 03 15:10:00 UTC 2004
>Closed-Date:
>Last-Modified:
>Originator:     Hanspeter Roth
>Release:        NetBSD 1.6ZK
>Organization:
>Environment:
	
	
System: NetBSD snoopy.here 1.6ZK NetBSD 1.6ZK (SDN1) #1: Fri Mar 19 14:35:05 CET 2004 hampi@snoopy.here:/usr/src/sys/arch/i386/compile/SDN1 i386
Architecture: i386
Machine: i386
>Description:
	The ppp from pkgsrc doesn't connect to isdnd. It claims:
	Warning: deflink: tcsetattr: Failed configuring device
	The ppp from awfulhak connects to isdnd. However I was not able to
	setup channel bundling.

	ppp.conf is:

default:
 set socket /var/run/pppctl ""
 set log Phase Chat LCP IPCP CCP tun command
 set device /dev/isdnbchan0 /dev/isdnbchan1

 set filter alive  0 deny udp dst eq 137
 set filter alive  1 deny udp dst eq 138
 set filter alive  2 deny udp dst eq 139
 set filter alive  3 deny tcp dst eq 137
 set filter alive  4 deny tcp dst eq 80
 set filter alive  5 deny 50
 set filter alive  6 permit MYADDR 0/0
 set filter alive  7 permit 0/0 MYADDR tcp estab
 set filter alive  8 deny 0/0 MYADDR icmp       # Ping to us from outside
 set filter alive  9 deny 0/0 0/0

    set filter dial 0 deny tcp finrst              # Badly closed TCP channels
    set filter dial 1 permit 0 0

 set log local +Chat Connect IPCP LCP Phase
 allow user u

bluewin:
 set cd 20
 set phone 10
 set login
 set authname name
 set authkey key
 set timeout 178
 set ifaddr 10.0.0.1/0 10.0.0.2/0 255.255.255.252 0.0.0.0
 add default HISADDR
 set mode auto


Normalized log from pkgsrc ppp looks like:
=== begin pkgsrc

ppp: Phase: Using interface: tun0 
ppp: Phase: deflink: Created in closed state 
ppp: Phase: Listening at local socket /var/run/pppctl. 
ppp: tun0: Command: default: set device /dev/isdnbchan0 /dev/isdnbchan1 
ppp: tun0: Command: default: set filter alive 0 deny udp dst eq 137 
ppp: tun0: Command: default: set filter alive 1 deny udp dst eq 138 
ppp: tun0: Command: default: set filter alive 2 deny udp dst eq 139 
ppp: tun0: Command: default: set filter alive 3 deny tcp dst eq 137 
ppp: tun0: Command: default: set filter alive 4 deny tcp dst eq 80 
ppp: tun0: Command: default: set filter alive 5 deny 50 
ppp: tun0: Warning: Parse: address/mask is expected. 
ppp: tun0: Command: default: set filter alive 6 permit MYADDR 0/0 
ppp: tun0: Command: default: set filter alive 7 permit 0/0 MYADDR tcp estab 
ppp: tun0: Command: default: set filter alive 8 deny 0/0 MYADDR icmp 
ppp: tun0: Command: default: set filter alive 9 deny 0/0 0/0 
ppp: tun0: Command: default: set filter dial 0 deny tcp finrst 
ppp: tun0: Command: default: set filter dial 1 permit 0 0 
ppp: tun0: Command: default: set log local +Chat Connect IPCP LCP Phase 
ppp: tun0: Command: bluewin: set cd 20 
ppp: tun0: Command: bluewin: set phone 10
ppp: tun0: Command: bluewin: set login 
ppp: tun0: Command: bluewin: set authname 
ppp: tun0: Command: bluewin: set authkey 
ppp: tun0: Command: bluewin: set timeout 178 
ppp: tun0: Command: bluewin: set ifaddr 10.0.0.1/0 10.0.0.2/0 255.255.255.252 0.0.0.0 
ppp: tun0: Command: bluewin: add default HISADDR 
ppp: tun0: Command: bluewin: set mode auto 

ppp: tun0: Phase: PPP Started (auto mode). 
ppp: tun0: Phase: Connected to local client. 
ppp: tun0: Command: /var/run/pppctl: dial 
ppp: tun0: Phase: bundle: Establish 
ppp: tun0: Phase: deflink: closed -> opening 
ppp: tun0: Warning: deflink: tcsetattr: Failed configuring device 
ppp: tun0: Phase: deflink: Connected! 
ppp: tun0: Phase: deflink: opening -> dial 
ppp: tun0: Chat: deflink: Dial attempt 1 of 1 
ppp: tun0: Phase: deflink: dial -> carrier 
ppp: tun0: Command: /var/run/pppctl: quit 
ppp: tun0: Phase: /var/run/pppctl: Client connection dropped. 
ppp: tun0: Phase: deflink: /dev/isdnbchan0 doesn't support CD 
ppp: tun0: Phase: deflink: carrier -> login 
ppp: tun0: Phase: deflink: login -> lcp 
ppp: tun0: LCP: FSM: Using "deflink" as a transport 
ppp: tun0: LCP: deflink: State change Initial --> Closed 
ppp: tun0: LCP: deflink: State change Closed --> Stopped 
ppp: tun0: LCP: deflink: LayerStart 
ppp: tun0: LCP: deflink: SendConfigReq(1) state = Stopped 
ppp: tun0: LCP:  ACFCOMP[2] 
ppp: tun0: LCP:  PROTOCOMP[2] 
ppp: tun0: LCP:  ACCMAP[6] 0x00000000 
ppp: tun0: LCP:  MRU[4] 1500 
ppp: tun0: LCP:  MAGICNUM[6] 0x293ed81b 
ppp: tun0: LCP: deflink: State change Stopped --> Req-Sent 
ppp: tun0: LCP: deflink: SendConfigReq(1) state = Req-Sent 
ppp: tun0: LCP:  ACFCOMP[2] 
ppp: tun0: LCP:  PROTOCOMP[2] 
ppp: tun0: LCP:  ACCMAP[6] 0x00000000 
ppp: tun0: LCP:  MRU[4] 1500 
ppp: tun0: LCP:  MAGICNUM[6] 0x293ed81b 
ppp: tun0: LCP: deflink: SendConfigReq(1) state = Req-Sent 
ppp: tun0: LCP:  ACFCOMP[2] 
ppp: tun0: LCP:  PROTOCOMP[2] 
ppp: tun0: LCP:  ACCMAP[6] 0x00000000 
ppp: tun0: LCP:  MRU[4] 1500 
ppp: tun0: LCP:  MAGICNUM[6] 0x293ed81b 
ppp: tun0: LCP: deflink: SendConfigReq(1) state = Req-Sent 
ppp: tun0: LCP:  ACFCOMP[2] 
ppp: tun0: LCP:  PROTOCOMP[2] 
ppp: tun0: LCP:  ACCMAP[6] 0x00000000 
ppp: tun0: LCP:  MRU[4] 1500 
ppp: tun0: LCP:  MAGICNUM[6] 0x293ed81b 
ppp: tun0: LCP: deflink: SendConfigReq(1) state = Req-Sent 
ppp: tun0: LCP:  ACFCOMP[2] 
ppp: tun0: LCP:  PROTOCOMP[2] 
ppp: tun0: LCP:  ACCMAP[6] 0x00000000 
ppp: tun0: LCP:  MRU[4] 1500 
ppp: tun0: LCP:  MAGICNUM[6] 0x293ed81b 
ppp: tun0: LCP: deflink: LayerFinish 
ppp: tun0: LCP: deflink: State change Req-Sent --> Stopped 
ppp: tun0: LCP: deflink: State change Stopped --> Closed 
ppp: tun0: LCP: deflink: State change Closed --> Initial 
ppp: tun0: Phase: deflink: Disconnected! 
ppp: tun0: Phase: deflink: lcp -> logout 
ppp: tun0: Phase: deflink: logout -> hangup 
ppp: tun0: Phase: deflink: Disconnected! 
ppp: tun0: Warning: deflink: tcsetattr: Unable to restore device settings 
ppp: tun0: Phase: deflink: Connect time: 37 secs: 0 octets in, 270 octets out 
ppp: tun0: Phase: deflink: : 0 packets in, 5 packets out 
ppp: tun0: Phase:  total 7 bytes/sec, peak 21 bytes/sec on Sat Apr  3 15:54:14 2004 
ppp: tun0: Phase: deflink: hangup -> closed 
ppp: tun0: Phase: bundle: Dead 
ppp: tun0: Phase: Signal 15, terminate. 
ppp: tun0: Phase: PPP Terminated (normal). 

=== end pkgsrc


Normalized log from awfulhak looks like this:
=== begin awfulhak

ppp: Phase: Using interface: tun0 
ppp: Phase: deflink: Created in closed state 
ppp: Phase: Listening at local socket /var/run/pppctl. 
ppp: tun0: Command: default: set device /dev/isdnbchan0 /dev/isdnbchan1 
ppp: tun0: Command: default: set filter alive 0 deny udp dst eq 137 
ppp: tun0: Command: default: set filter alive 1 deny udp dst eq 138 
ppp: tun0: Command: default: set filter alive 2 deny udp dst eq 139 
ppp: tun0: Command: default: set filter alive 3 deny tcp dst eq 137 
ppp: tun0: Command: default: set filter alive 4 deny tcp dst eq 80 
ppp: tun0: Command: default: set filter alive 5 deny 50 
ppp: tun0: Warning: Parse: Protocol or address pair expected 
ppp: tun0: Command: default: set filter alive 6 permit MYADDR 0/0 
ppp: tun0: Command: default: set filter alive 7 permit 0/0 MYADDR tcp estab 
ppp: tun0: Command: default: set filter alive 8 deny 0/0 MYADDR icmp 
ppp: tun0: Command: default: set filter alive 9 deny 0/0 0/0 
ppp: tun0: Command: default: set filter dial 0 deny tcp finrst 
ppp: tun0: Command: default: set filter dial 1 permit 0 0 
ppp: tun0: Command: default: set log local +Chat Connect IPCP LCP Phase 
ppp: tun0: Command: bluewin: set cd 20 
ppp: tun0: Command: bluewin: set phone 10
ppp: tun0: Command: bluewin: set login 
ppp: tun0: Command: bluewin: set authname 
ppp: tun0: Command: bluewin: set authkey 
ppp: tun0: Command: bluewin: set timeout 178 
ppp: tun0: Command: bluewin: set ifaddr 10.0.0.1/0 10.0.0.2/0 255.255.255.252 0.0.0.0 
ppp: tun0: Command: bluewin: add default HISADDR 

ppp: tun0: Phase: PPP Started (auto mode). 
ppp: tun0: Phase: Connected to local client. 
ppp: tun0: Command: /var/run/pppctl: dial 
ppp: tun0: Phase: bundle: Establish 
ppp: tun0: Phase: deflink: closed -> opening 
ppp: tun0: Chat: Phone: 10
ppp: tun0: Warning: Async device setting ignored for ``i4b'' device 
ppp: tun0: Phase: deflink: Connected! 
ppp: tun0: Phase: deflink: opening -> dial 
ppp: tun0: Chat: deflink: Dial attempt 1 of 1 
ppp: tun0: Phase: deflink: dial -> carrier 
ppp: tun0: Phase: deflink: /dev/isdnbchan0: CD detected 
ppp: tun0: Phase: deflink: carrier -> login 
ppp: tun0: Phase: deflink: login -> lcp 
ppp: tun0: LCP: FSM: Using "deflink" as a transport 
ppp: tun0: LCP: deflink: State change Initial --> Closed 
ppp: tun0: LCP: deflink: State change Closed --> Stopped 
ppp: tun0: LCP: deflink: LayerStart 
ppp: tun0: LCP: deflink: SendConfigReq(1) state = Stopped 
ppp: tun0: LCP:  MRU[4] 1500 
ppp: tun0: LCP:  MAGICNUM[6] 0x415b239d 
ppp: tun0: LCP: deflink: State change Stopped --> Req-Sent 
ppp: tun0: LCP: deflink: RecvConfigReq(149) state = Req-Sent 
ppp: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05) 
ppp: tun0: LCP:  MAGICNUM[6] 0x574abb4b 
ppp: tun0: LCP:  MRRU[4] 1524 
ppp: tun0: LCP:  ENDDISC[11] Local Addr: tbwmlppp 
ppp: tun0: LCP: deflink: SendConfigRej(149) state = Req-Sent 
ppp: tun0: LCP:  MRRU[4] 1524 
ppp: tun0: LCP: deflink: RecvConfigAck(1) state = Req-Sent 
ppp: tun0: LCP:  MRU[4] 1500 
ppp: tun0: LCP:  MAGICNUM[6] 0x415b239d 
ppp: tun0: LCP: deflink: State change Req-Sent --> Ack-Rcvd 
ppp: tun0: LCP: deflink: RecvConfigReq(150) state = Ack-Rcvd 
ppp: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05) 
ppp: tun0: LCP:  MAGICNUM[6] 0x574abb4b 
ppp: tun0: LCP:  ENDDISC[11] Local Addr: tbwmlppp 
ppp: tun0: LCP: deflink: SendConfigAck(150) state = Ack-Rcvd 
ppp: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05) 
ppp: tun0: LCP:  MAGICNUM[6] 0x574abb4b 
ppp: tun0: LCP:  ENDDISC[11] Local Addr: tbwmlppp 
ppp: tun0: LCP: deflink: State change Ack-Rcvd --> Opened 
ppp: tun0: LCP: deflink: LayerUp 
ppp: tun0: Phase: bundle: Authenticate 
ppp: tun0: Phase: deflink: his = CHAP 0x05, mine = none 
ppp: tun0: Phase: Chap Input: CHALLENGE (16 bytes from tbwmlppp) 
ppp: tun0: Phase: Chap Output: RESPONSE (gchristi) 
ppp: tun0: Phase: Chap Input: SUCCESS 
ppp: tun0: IPCP: Using trigger address 0.0.0.0 
ppp: tun0: CCP: FSM: Using "deflink" as a transport 
ppp: tun0: CCP: deflink: State change Initial --> Closed 
ppp: tun0: CCP: deflink: LayerStart. 
ppp: tun0: CCP: deflink: SendConfigReq(1) state = Closed 
ppp: tun0: CCP:  DEFLATE[4] win 15 
ppp: tun0: CCP:  PRED1[2]  
ppp: tun0: CCP: deflink: State change Closed --> Req-Sent 
ppp: tun0: Phase: deflink: lcp -> open 
ppp: tun0: Phase: bundle: Network 
ppp: tun0: IPCP: FSM: Using "deflink" as a transport 
ppp: tun0: IPCP: deflink: State change Initial --> Closed 
ppp: tun0: IPCP: deflink: LayerStart. 
ppp: tun0: IPCP: deflink: SendConfigReq(1) state = Closed 
ppp: tun0: IPCP:  IPADDR[6] 0.0.0.0 
ppp: tun0: IPCP: deflink: RecvConfigReq(46) state = Req-Sent 
ppp: tun0: IPCP:  COMPPROTO[6] 16 VJ slots without slot compression 
ppp: tun0: IPCP:  IPADDR[6] 0.0.0.1 
ppp: tun0: IPCP: deflink: SendConfigAck(46) state = Req-Sent 
ppp: tun0: IPCP:  COMPPROTO[6] 16 VJ slots without slot compression 
ppp: tun0: IPCP:  IPADDR[6] 0.0.0.1 
ppp: tun0: IPCP: deflink: State change Req-Sent --> Ack-Sent 
ppp: tun0: CCP: deflink: RecvConfigReq(41) state = Req-Sent 
ppp: tun0: CCP:  MPPE[6]  
ppp: tun0: CCP: deflink: SendConfigRej(41) state = Req-Sent 
ppp: tun0: CCP:  MPPE[6]  
ppp: tun0: CCP: deflink: RecvConfigRej(1) state = Req-Sent 
ppp: tun0: CCP:  DEFLATE[4] win 15 
ppp: tun0: CCP: deflink: SendConfigReq(2) state = Req-Sent 
ppp: tun0: CCP:  PRED1[2]  
ppp: tun0: IPCP: deflink: RecvConfigNak(1) state = Ack-Sent 
ppp: tun0: IPCP:  IPADDR[6] 0.0.0.2 
ppp: tun0: IPCP:  IPADDR[6] changing address: 0.0.0.0  --> 0.0.0.2 
ppp: tun0: IPCP: deflink: SendConfigReq(2) state = Ack-Sent 
ppp: tun0: IPCP:  IPADDR[6] 0.0.0.2 
ppp: tun0: IPCP:  COMPPROTO[6] 16 VJ slots with slot compression 
ppp: tun0: CCP: deflink: RecvConfigReq(42) state = Req-Sent 
ppp: tun0: CCP:  LZS-DCP[6]  
ppp: tun0: CCP: deflink: SendConfigRej(42) state = Req-Sent 
ppp: tun0: CCP:  LZS-DCP[6]  
ppp: tun0: CCP: deflink: RecvConfigAck(2) state = Req-Sent 
ppp: tun0: CCP:  PRED1[2]  
ppp: tun0: CCP: deflink: State change Req-Sent --> Ack-Rcvd 
ppp: tun0: IPCP: deflink: RecvConfigAck(2) state = Ack-Sent 
ppp: tun0: IPCP:  IPADDR[6] 0.0.0.2 
ppp: tun0: IPCP:  COMPPROTO[6] 16 VJ slots with slot compression 
ppp: tun0: IPCP: deflink: State change Ack-Sent --> Opened 
ppp: tun0: IPCP: deflink: LayerUp. 
ppp: tun0: IPCP: myaddr 0.0.0.2 hisaddr = 0.0.0.1 
ppp: tun0: Warning: Add! route failed: 0.0.0.0: errno: Invalid argument 
ppp: tun0: Command: MYADDR: delete! default 
ppp: tun0: Command: MYADDR: add! default HISADDR 
ppp: tun0: Command: MYADDR: !bg nslookup MYADDR 
ppp: tun0: Command: MYADDR: !bg nslookup HISADDR 
ppp: tun0: Command: MYADDR: !bg /root/bin/ntponce 
ppp: tun0: Command: MYADDR: !bg /root/etc/linkupsound 
ppp: tun0: Command: MYADDR: !bg /usr/sbin/sendmail -q 
ppp: tun0: Warning: 0.0.0.0: Change route failed: errno: Invalid argument 
ppp: tun0: CCP: deflink: RecvConfigReq(43) state = Ack-Rcvd 
ppp: tun0: CCP:  STAC[5]  
ppp: tun0: CCP: deflink: SendConfigRej(43) state = Ack-Rcvd 
ppp: tun0: CCP:  STAC[5]  
ppp: tun0: CCP: deflink: RecvConfigReq(44) state = Ack-Rcvd 
ppp: tun0: CCP:  STAC[5]  
ppp: tun0: CCP: deflink: SendConfigRej(44) state = Ack-Rcvd 
ppp: tun0: CCP:  STAC[5]  
ppp: tun0: CCP: deflink: RecvConfigReq(45) state = Ack-Rcvd 
ppp: tun0: CCP:  PRED1[2]  
ppp: tun0: CCP: deflink: SendConfigAck(45) state = Ack-Rcvd 
ppp: tun0: CCP:  PRED1[2]  
ppp: tun0: CCP: deflink: State change Ack-Rcvd --> Opened 
ppp: tun0: CCP: deflink: LayerUp. 
ppp: tun0: CCP: Predictor1: Input channel reset 
ppp: tun0: CCP: Predictor1: Output channel reset 
ppp: tun0: CCP: deflink: Out = PRED1[1], In = PRED1[1] 
ppp: tun0: Warning: 0.0.0.0: Change route failed: errno: Invalid argument 
ppp: tun0: Command: /var/run/pppctl: quit 
ppp: tun0: Phase: /var/run/pppctl: Client connection dropped. 
ppp: tun0: Phase: Connected to local client. 
ppp: tun0: Command: /var/run/pppctl: quit 
ppp: tun0: Phase: /var/run/pppctl: Client connection dropped. 
ppp: tun0: Phase: Connected to local client. 
ppp: tun0: Command: /var/run/pppctl: close 
ppp: tun0: IPCP: deflink: LayerDown: 0.0.0.2 
ppp: tun0: Command: MYADDR: delete! default 
ppp: tun0: Command: MYADDR: set ifaddr 10.0.0.1/0 10.0.0.2/0 255.255.255.0 0.0.0.0 
ppp: tun0: Command: MYADDR: add! default HISADDR 
ppp: tun0: Command: MYADDR: !bg /root/etc/linkdownsound 
ppp: tun0: IPCP: Using trigger address 0.0.0.0 
ppp: tun0: IPCP: deflink: SendTerminateReq(3) state = Opened 
ppp: tun0: IPCP: deflink: State change Opened --> Closing 
ppp: tun0: Command: /var/run/pppctl: quit 
ppp: tun0: Phase: /var/run/pppctl: Client connection dropped. 
ppp: tun0: IPCP: deflink: RecvTerminateAck(3) state = Closing 
ppp: tun0: IPCP: deflink: LayerFinish. 
ppp: tun0: IPCP: Connect time: 17 secs: 2866 octets in, 1118 octets out 
ppp: tun0: IPCP: 18 packets in, 17 packets out 
ppp: tun0: IPCP:  total 234 bytes/sec, peak 725 bytes/sec on Sat Apr  3 16:00:13 2004 
ppp: tun0: IPCP: deflink: State change Closing --> Closed 
ppp: tun0: Phase: bundle: Terminate 
ppp: tun0: CCP: deflink: LayerDown. 
ppp: tun0: CCP: deflink: State change Opened --> Starting 
ppp: tun0: CCP: deflink: LayerFinish. 
ppp: tun0: CCP: deflink: State change Starting --> Initial 
ppp: tun0: LCP: deflink: LayerDown 
ppp: tun0: LCP: deflink: SendTerminateReq(2) state = Opened 
ppp: tun0: LCP: deflink: State change Opened --> Closing 
ppp: tun0: Phase: deflink: open -> lcp 
ppp: tun0: Warning: 0.0.0.0: Change route failed: errno: Invalid argument 
ppp: tun0: LCP: deflink: RecvTerminateAck(2) state = Closing 
ppp: tun0: LCP: deflink: LayerFinish 
ppp: tun0: LCP: deflink: State change Closing --> Closed 
ppp: tun0: LCP: deflink: State change Closed --> Initial 
ppp: tun0: Phase: deflink: Disconnected! 
ppp: tun0: Phase: deflink: lcp -> logout 
ppp: tun0: Phase: deflink: logout -> hangup 
ppp: tun0: Phase: deflink: Disconnected! 
ppp: tun0: Phase: deflink: Connect time: 19 secs: 2541 octets in, 1161 octets out 
ppp: tun0: Phase: deflink: 35 packets in, 33 packets out 
ppp: tun0: Phase:  total 194 bytes/sec, peak 576 bytes/sec on Sat Apr  3 16:00:13 2004 
ppp: tun0: Phase: deflink: hangup -> closed 
ppp: tun0: Phase: bundle: Dead 

=== end awfulhak

>How-To-Repeat:
	Start one or the other ppp with `-auto entry', use '
	pppctl /var/run/pppctl' and issue 'dial'.
>Fix:
	The ppp from awfulhak connects to isdnd. However I was not able to
	setup channel bundling.
>Release-Note:
>Audit-Trail:
>Unformatted: