From owner-freebsd-bugs Tue Feb 11 03:10:05 1997 Return-Path: Received: (from root@localhost) by freefall.freebsd.org (8.8.5/8.8.5) id DAA15108 for bugs-outgoing; Tue, 11 Feb 1997 03:10:05 -0800 (PST) Received: (from gnats@localhost) by freefall.freebsd.org (8.8.5/8.8.5) id DAA15092; Tue, 11 Feb 1997 03:10:02 -0800 (PST) Resent-Date: Tue, 11 Feb 1997 03:10:02 -0800 (PST) Resent-Message-Id: <199702111110.DAA15092@freefall.freebsd.org> Resent-From: gnats (GNATS Management) Resent-To: freebsd-bugs Resent-Reply-To: FreeBSD-gnats@freefall.FreeBSD.org, pst@Shockwave.COM Received: from precipice.shockwave.com (ppp-206-170-5-68.rdcy01.pacbell.net [206.170.5.68]) by freefall.freebsd.org (8.8.5/8.8.5) with ESMTP id DAA14973 for ; Tue, 11 Feb 1997 03:07:19 -0800 (PST) Received: (from pst@localhost) by precipice.shockwave.com (8.8.4/8.7.3) id DAA00516; Tue, 11 Feb 1997 03:04:46 -0800 (PST) Message-Id: <199702111104.DAA00516@precipice.shockwave.com> Date: Tue, 11 Feb 1997 03:04:46 -0800 (PST) From: Paul Traina Reply-To: pst@Shockwave.COM To: FreeBSD-gnats-submit@freebsd.org X-Send-Pr-Version: 3.2 Subject: bin/2711: iij-ppp 'background' mode fails in LCP setup Sender: owner-bugs@freebsd.org X-Loop: FreeBSD.org Precedence: bulk >Number: 2711 >Category: bin >Synopsis: iij-ppp 'background' mode fails in LCP setup >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: open >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Tue Feb 11 03:10:01 PST 1997 >Last-Modified: >Originator: Paul Traina >Organization: Juniper Networks >Release: FreeBSD 3.0-CURRENT i386 >Environment: -current as of last week iij user mode ppp daemon 3COM Impact IQ ISDN TA (irrelevant to discussion) >Description: I was playing about with IIJ ppp this evening (not to be confused with my other bug report on kernel mode PPP + pppd), and got it working quite well with my new ISDN TA. However, when I tried to use background mode, it dialed the link, but then failed to receive any responses from the "modem" during PPP LCP bringup. First, here's a normal trace (sanitized to hide the guilty): 02-11 02:17:20 [776] Using interface: tun0 02-11 02:17:20 [776] Expecting 02-11 02:17:20 [776] sending: ATE1Q0S80=1S84=1 02-11 02:17:20 [776] Expecting OK-AT-OK 02-11 02:17:20 [776] Wait for (5): OK --> OK 02-11 02:17:20 [776] Chat: ATE1Q0S80=1S84=1 02-11 02:17:20 [776] Chat: OK 02-11 02:17:20 [776] Phone: 1415XXXXXXX 02-11 02:17:20 [776] sending: ATD1415XXXXXXX 02-11 02:17:20 [776] Expecting CONNECT 02-11 02:17:20 [776] Wait for (40): CONNECT --> CONNECT 02-11 02:17:20 [776] Chat: 02-11 02:17:22 [776] Chat: ATD1415XXXXXXX 02-11 02:17:22 [776] Chat: CONNECT 02-11 02:17:22 [776] *Connected! 02-11 02:17:22 [776] LCP: state change Initial --> Closed 02-11 02:17:22 [776] LCP: SendConfigReq 02-11 02:17:22 [776] ACFCOMP 02-11 02:17:22 [776] PROTOCOMP 02-11 02:17:22 [776] ACCMAP [6] 00000000 02-11 02:17:22 [776] MRU [4] 1500 02-11 02:17:22 [776] MAGICNUM [6] 37b46888 02-11 02:17:22 [776] LCP: state change Closed --> Req-Sent 02-11 02:17:22 [776] PPP Started. 02-11 02:17:22 [776] LCP: Received Configure Reject (1) state = Req-Sent (6) 02-11 02:17:22 [776] LCP: RecvConfigRej. 02-11 02:17:22 [776] ACFCOMP 02-11 02:17:22 [776] PROTOCOMP 02-11 02:17:22 [776] LCP: SendConfigReq 02-11 02:17:22 [776] ACCMAP [6] 00000000 02-11 02:17:22 [776] MRU [4] 1500 02-11 02:17:22 [776] MAGICNUM [6] 37b46888 02-11 02:17:25 [776] LCP: SendConfigReq 02-11 02:17:25 [776] ACCMAP [6] 00000000 02-11 02:17:25 [776] MRU [4] 1500 02-11 02:17:25 [776] MAGICNUM [6] 37b46888 02-11 02:17:25 [776] LCP: Received Configure Ack (3) state = Req-Sent (6) 02-11 02:17:25 [776] LCP: state change Req-Sent --> Ack-Rcvd 02-11 02:17:25 [776] LCP: Received Configure Request (2) state = Ack-Rcvd (7) 02-11 02:17:25 [776] AUTHPROTO proto = c023 02-11 02:17:25 [776] ACCMAP 00000000 02-11 02:17:25 [776] LCP: SendConfigAck(Ack-Rcvd) 02-11 02:17:25 [776] AUTHPROTO proto = c023 02-11 02:17:25 [776] ACCMAP 00000000 02-11 02:17:25 [776] LCP: state change Ack-Rcvd --> Opend 02-11 02:17:25 [776] LCP: LayerUp Now here's the exact same config, except pppd was invoked with the -background flag. It successfully dials the phone, and then goes deaf on the LCP connect, just retransmitting, not seeing any response from the remote side (this COULD certainly be because our LCP output is corrupt, but I didn't dig through the hex debug info). 02-11 02:40:14 [1653] Using interface: tun0 02-11 02:40:14 [1653] Expecting 02-11 02:40:14 [1653] sending: ATE1Q0S80=1S84=1 02-11 02:40:14 [1653] Expecting OK-AT-OK 02-11 02:40:14 [1653] Wait for (5): OK --> OK 02-11 02:40:14 [1653] Chat: ATE1Q0S80=1S84=1 02-11 02:40:14 [1653] Chat: OK 02-11 02:40:15 [1653] Phone: 1415XXXXXXX 02-11 02:40:15 [1653] sending: ATD1415XXXXXXX 02-11 02:40:15 [1653] Expecting CONNECT 02-11 02:40:15 [1653] Wait for (40): CONNECT --> CONNECT 02-11 02:40:15 [1653] Chat: 02-11 02:40:16 [1653] Chat: ATD1415XXXXXXX 02-11 02:40:16 [1653] Chat: CONNECT 02-11 02:40:16 [1653] *Connected! 02-11 02:40:16 [1653] LCP: state change Initial --> Closed 02-11 02:40:16 [1653] LCP: SendConfigReq 02-11 02:40:16 [1653] ACFCOMP 02-11 02:40:16 [1653] PROTOCOMP 02-11 02:40:16 [1653] ACCMAP [6] 00000000 02-11 02:40:16 [1653] MRU [4] 1500 02-11 02:40:16 [1653] MAGICNUM [6] dd0d77e4 02-11 02:40:16 [1653] LCP: state change Closed --> Req-Sent 02-11 02:40:16 [1658] PPP Started. 02-11 02:40:16 [1658] LCP: Received Configure Reject (1) state = Req-Sent (6) 02-11 02:40:16 [1658] LCP: RecvConfigRej. 02-11 02:40:16 [1658] ACFCOMP 02-11 02:40:16 [1658] PROTOCOMP 02-11 02:40:16 [1658] LCP: SendConfigReq 02-11 02:40:16 [1658] ACCMAP [6] 00000000 02-11 02:40:16 [1658] MRU [4] 1500 02-11 02:40:16 [1658] MAGICNUM [6] dd0d77e4 02-11 02:40:19 [1653] LCP: SendConfigReq 02-11 02:40:19 [1653] ACFCOMP 02-11 02:40:19 [1653] PROTOCOMP 02-11 02:40:19 [1653] ACCMAP [6] 00000000 02-11 02:40:19 [1653] MRU [4] 1500 02-11 02:40:19 [1653] MAGICNUM [6] dd0d77e4 02-11 02:40:22 [1653] LCP: SendConfigReq 02-11 02:40:22 [1653] ACFCOMP 02-11 02:40:22 [1653] PROTOCOMP 02-11 02:40:22 [1653] ACCMAP [6] 00000000 02-11 02:40:22 [1653] MRU [4] 1500 02-11 02:40:22 [1653] MAGICNUM [6] dd0d77e4 02-11 02:40:25 [1653] LCP: SendConfigReq 02-11 02:40:25 [1653] ACFCOMP 02-11 02:40:25 [1653] PROTOCOMP 02-11 02:40:25 [1653] ACCMAP [6] 00000000 02-11 02:40:25 [1653] MRU [4] 1500 02-11 02:40:25 [1653] MAGICNUM [6] dd0d77e4 02-11 02:40:28 [1653] LCP: SendConfigReq 02-11 02:40:28 [1653] ACFCOMP 02-11 02:40:28 [1653] PROTOCOMP 02-11 02:40:28 [1653] ACCMAP [6] 00000000 02-11 02:40:28 [1653] MRU [4] 1500 02-11 02:40:28 [1653] MAGICNUM [6] dd0d77e4 02-11 02:40:31 [1653] LCP: state change Req-Sent --> Stopped 02-11 02:40:31 [1653] LCP: LayerFinish 02-11 02:40:32 [1653] Disconnected! 02-11 02:40:32 [1653] Connect time: 16 secs 02-11 02:40:32 [1653] Phase: Dead 02-11 02:40:32 [1653] LCP: LayerStart 02-11 02:40:32 [1653] Phase: Establish 02-11 02:40:32 [1653] LCP: state change Stopped --> Starting 02-11 02:40:32 [1653] Phase: Dead 02-11 02:40:33 [1658] Signal 2, terminate. 02-11 02:40:33 [1658] LCP: SendTerminateReq. 02-11 02:40:33 [1658] LCP: state change Req-Sent --> Closing 02-11 02:40:34 [1658] Disconnected! 02-11 02:40:34 [1658] Connect time: 18 secs 02-11 02:40:34 [1658] Phase: Dead >How-To-Repeat: Take a working ppp config (including a valid dial command), and try running ppp in -background, as in ppp -background my-remote-guy >Fix: >Audit-Trail: >Unformatted: