Bugzilla Bug 153798

I sent a kill -HUP to the pppd and get this:

Nov  2 06:00:01 pluto pppd[5898]: Hangup (SIGHUP)
Nov  2 06:00:01 pluto pppd[5898]: Connect time 708.1 minutes.
Nov  2 06:00:01 pluto pppd[5898]: Sent 352728688 bytes, received 1300190774
bytes.
Nov  2 06:00:01 pluto pppd[5898]: Connection terminated.
Nov  2 06:00:02 pluto pppd[5898]: write: Bad file descriptor (9)
Nov  2 06:00:02 pluto pppd[5898]: PPP session is 6687
Nov  2 06:00:02 pluto pppd[5898]: Using interface ppp0
Nov  2 06:00:02 pluto pppd[5898]: Connect: ppp0 <--> eth1
Nov  2 06:00:06 pluto pppd[5898]: PAP authentication succeeded
Nov  2 06:00:06 pluto pppd[5898]: peer from calling number xx:xx:xx:xx:xx:xx
authorized
Nov  2 06:00:06 pluto pppd[5898]: local  IP address xxx.xxx.xxx.xxx
Nov  2 06:00:06 pluto pppd[5898]: remote IP address xxx.xxx.xxx.xxx
Nov  2 06:00:07 pluto pppd[5898]: Child process /etc/ppp/ip-up (pid 22822)
terminated with signal 15

Since I don't have set "usepeerdns" I assume, the second if statement takes too
long to execute and terminates (see comment "second if statement" in ip-up). I
put all my stuff in ip-up.local. But if ip-up.local would have made problems,
then wouldn't the log read: 

Child process /etc/ppp/ip-up.local (pid ....) terminated with signal 15   ?

I already set modules_ppp0=( "!iwconfig" "!wpa_supplicant" "iproute2" "pppd" )
to speed up pppd-restarts. (see attached net.ppp0 below)

I am using the latest stable baselayout and pppd:

sys-apps/baselayout-1.12.5-r2
net-dialup/ppp-2.4.3-r16


My pppd settings are set accordingly to the new baselayout.

What I am not sure and what is not documented in net.example or baselayout: 

Is it necessary to configure the interface ppp0 is linked against as a "null"
device as I did in /etc/conf.d/net.eth1 ?

(following: /etc/ppp/ip-up, listing of /etc/conf.d/net*, /etc/conf.d/net.ppp0,
/etc/conf.d/net.eth1, info about kill -HUP pppd)

********** /etc/ppp/ip-up **********

#!/bin/bash

# this is a script which is executed after connecting the ppp interface.

# look at man pppd for details

# the followings parameters are available:
# $1 = interface-name
# $2 = tty-device
# $3 = speed
# $4 = local-IP-address
# $5 = remote-IP-address
# $6 = ipparam

if [ "$USEPEERDNS" ]; then

        if [ -x /sbin/resolvconf ]; then
                conf="# Generated by ppp for $1\n"
                [ -n "$DNS1" ] && conf="${conf}nameserver $DNS1\n"
                [ -n "$DNS2" ] && conf="${conf}nameserver $DNS2\n"
                echo -e "$conf" | resolvconf -a "$1"
        else
                # add the server supplied DNS entries to /etc/resolv.conf
                # (taken from debian's 0000usepeerdns)

                # follow any symlink to find the real file
                REALRESOLVCONF=$(readlink --canonicalize /etc/resolv.conf)

                if [ "$REALRESOLVCONF" != "/etc/ppp/resolv.conf" ]; then

                        # merge the new nameservers with the other options from
the old configuration
                        {
                        grep --invert-match '^nameserver[[:space:]]'
$REALRESOLVCONF
                        cat /etc/ppp/resolv.conf
                        } > $REALRESOLVCONF.tmp

                        # backup the old configuration and install the new one
                        cp -dpP $REALRESOLVCONF $REALRESOLVCONF.pppd-backup
                        mv $REALRESOLVCONF.tmp $REALRESOLVCONF

                        # correct permissions
                        chmod 0644 /etc/resolv.conf
                        chown root:root /etc/resolv.conf
                fi
        fi

fi


# second if statement 
if [ -x /etc/init.d/net.$1 ]; then
        if ! /etc/init.d/net.$1 --quiet status ; then
                export IN_BACKGROUND="true"
                /etc/init.d/net.$1 --quiet start
        fi
fi

[ -f /etc/ppp/ip-up.local ] && . /etc/ppp/ip-up.local "$@"

********** `ls -la /etc/conf.d/net*` **********

-rw-r--r-- 1 root root   599 2006-10-08 01:23 /etc/conf.d/net.eth0
-rw-r--r-- 1 root root   193 2006-10-08 23:21 /etc/conf.d/net.eth1
-rw-r--r-- 1 root root 32410 2006-10-03 19:09 /etc/conf.d/net.example
-rw-r--r-- 1 root root  1909 2006-10-13 17:55 /etc/conf.d/net.ppp0

********** /etc/conf.d/net.ppp0 **********

###
# ppp0 = PPPoE (ADSL)
### 

config_ppp0=( "ppp" )
link_ppp0="eth1"
plugins_ppp0=( "pppoe" )
ifplugd_ppp0="--delay-down=1"
modules_ppp0=( "!iwconfig" "!wpa_supplicant" "iproute2" "pppd" )

# PPP requires at least a username. You can optionally set a password here too
# If you don't, then it will use the password specified in /etc/ppp/*-secrets
# against the specified username
username_ppp0='username'
#password_ppp0='password'

pppd_ppp0=(

    "hide-password"         # Exclude the password string from the log
    "persist"               # Do not exit after a connection is terminated
    "maxfail 0"             # if you don't specify maxfail then we assume 0
#   "debug"                 # Enables syslog debugging
    "ktune"                 # Enables pppd to alter kernel settings as
appropriate
    "noauth"                # Do not require the peer to authenticate itself

    "noipdefault"           # Get IP from peer
    "defaultroute"          # Make this PPP interface the default route

    "ipcp-accept-remote"    # Accept the peers idea of remote address
    "ipcp-accept-local"     # Accept the peers idea of local address

    "lcp-echo-interval 15"  # Send a LCP echo every 15 seconds
    "lcp-echo-failure 4"    # Make peer dead after 4 consective echo-requests
    "holdoff 0"             # Wait n seconds after link dies before re-starting

    "noaccomp"              # Disable Address/Control compression
    "nopcomp"               # Disable protocol field compression negotiation
    "novj"                  # Disable Van Jacobson style TCP/IP header
compression
    "novjccomp"             # Disable the connection-ID compression in ^^^
    "nobsdcomp"             # Disable BSD-Compress compression
    "nodeflate"             # Disable Deflate compression
    "noccp"                 # Disable CCP (Compression Control Protocol)
negotiation.

)

********** /etc/conf.d/net.eth1 **********

###
# eth1 - Null
### 

config_eth1=( "null" )
ifplugd_eth1="--delay-down=1"

********** man pppd **********

If the first pppd receives a SIGHUP signal, it will terminate its link but not
the bundle.

**********

Oops, I've made a mistake in wait-children patch.

The wait_children function contained 2 mistakes:
  - child should be killed only on SIGTERM, not on SIGHUP (use asked_for_quit
instead kill_link)
  - it didn't remove the timeout after the watched child has ended, which
forced subsequent children to end prematurely.

Fixed in ppp-2.4.4-r3, which, with God's help, will be marked as stable after a
month.

Okay, now I get:

Nov  3 13:08:01 pluto pppd[15861]: Child process /etc/ppp/ip-down (pid 17302)
terminated with signal 15

It seems, the bug is in ip-down, too.

Please attach a complete log.

Which log do you need?

pppd's log of course!
From the moment you started with /etc/init.d/net.ppp0 start to the moment.
And make sure you restarted net.ppp0 _after_ you updated to ppp-2.4.4-r3.

Of course I restarted net.ppp0.

After sending kill -HUP to pppd the log looks like:

Nov  3 13:07:56 pluto pppd[15861]: Connection terminated.
Nov  3 13:08:01 pluto pppd[15861]: PPP session is 5068
Nov  3 13:08:01 pluto pppd[15861]: Using interface ppp0
Nov  3 13:08:01 pluto pppd[15861]: Connect: ppp0 <--> eth1
Nov  3 13:08:01 pluto pppd[15861]: Child process /etc/ppp/ip-down (pid 17302)
terminated with signal 15
Nov  3 13:08:02 pluto pppd[15861]: PAP authentication succeeded
Nov  3 13:08:02 pluto pppd[15861]: peer from calling number xx:xx:xx:xx:xx:xx
authorized
Nov  3 13:08:02 pluto pppd[15861]: local  IP address xxx.xxx.xxx.xxx
Nov  3 13:08:02 pluto pppd[15861]: remote IP address xxx.xxx.xxx.xxx

The ip-up error disappeared. But the ip-down error is still present.

Dude, can you understand what I say? Please attach the COMPLETE pppd log, from
the net.ppp0 start to the moment you consider the alleged bug manifested its
presence.

there you go:

Nov  3 10:59:37 pluto pppd[5898]: Hangup (SIGHUP)
Nov  3 10:59:37 pluto pppd[5898]: Connect time 299.5 minutes.
Nov  3 10:59:37 pluto pppd[5898]: Sent 99654525 bytes, received 21051067 bytes.
Nov  3 10:59:37 pluto pppd[5898]: Connection terminated.
Nov  3 10:59:38 pluto pppd[5898]: write: Bad file descriptor (9)
Nov  3 10:59:43 pluto pppd[5898]: PPP session is 2911
Nov  3 10:59:43 pluto pppd[5898]: Using interface ppp0
Nov  3 10:59:43 pluto pppd[5898]: Connect: ppp0 <--> eth1
Nov  3 10:59:43 pluto pppd[5898]: PAP authentication succeeded
Nov  3 10:59:43 pluto pppd[5898]: peer from calling number xx:xx:xx:xx:xx:xx
authorized
Nov  3 10:59:43 pluto pppd[5898]: local  IP address xxx.xxx.xxx.xxx
Nov  3 10:59:43 pluto pppd[5898]: remote IP address xxx.xxx.xxx.xxx
Nov  3 13:01:41 pluto pppd[5898]: Terminating on signal 15
Nov  3 13:01:41 pluto pppd[5898]: Connect time 122.0 minutes.
Nov  3 13:01:41 pluto pppd[5898]: Sent 41020815 bytes, received 19124733 bytes.
Nov  3 13:01:41 pluto pppd[5898]: Connection terminated.
Nov  3 13:01:43 pluto pppd[5898]: Exit.

restart with net.ppp0 with ppp-2.4.4-r3

Nov  3 13:01:48 pluto pppd[15860]: Plugin rp-pppoe.so loaded.
Nov  3 13:01:48 pluto pppd[15860]: RP-PPPoE plugin version 3.3 compiled against
pppd 2.4.4
Nov  3 13:01:48 pluto pppd[15861]: pppd 2.4.4 started by root, uid 0
Nov  3 13:01:48 pluto pppd[15861]: PPP session is 3648
Nov  3 13:01:48 pluto pppd[15861]: Using interface ppp0
Nov  3 13:01:48 pluto pppd[15861]: Connect: ppp0 <--> eth1
Nov  3 13:01:49 pluto pppd[15861]: PAP authentication succeeded
Nov  3 13:01:49 pluto pppd[15861]: peer from calling number xx:xx:xx:xx:xx:xx
authorized
Nov  3 13:01:49 pluto pppd[15861]: local  IP address xxx.xxx.xxx.xxx
Nov  3 13:01:49 pluto pppd[15861]: remote IP address xxx.xxx.xxx.xxx

sending kill -HUP to pppd:

Nov  3 13:07:56 pluto pppd[15861]: Hangup (SIGHUP)
Nov  3 13:07:56 pluto pppd[15861]: Connect time 6.2 minutes.
Nov  3 13:07:56 pluto pppd[15861]: Sent 1866619 bytes, received 1271798 bytes.
Nov  3 13:07:56 pluto pppd[15861]: Connection terminated.
Nov  3 13:08:01 pluto pppd[15861]: PPP session is 5068
Nov  3 13:08:01 pluto pppd[15861]: Using interface ppp0
Nov  3 13:08:01 pluto pppd[15861]: Connect: ppp0 <--> eth1
Nov  3 13:08:01 pluto pppd[15861]: Child process /etc/ppp/ip-down (pid 17302)
terminated with signal 15
Nov  3 13:08:02 pluto pppd[15861]: PAP authentication succeeded
Nov  3 13:08:02 pluto pppd[15861]: peer from calling number xx:xx:xx:xx:xx:xx
authorized
Nov  3 13:08:02 pluto pppd[15861]: local  IP address xxx.xxx.xxx.xxx
Nov  3 13:08:02 pluto pppd[15861]: remote IP address xxx.xxx.xxx.xxx

Okay, seems I need to tell you what I want in steps:
1) Add debug to pppd_ppp0
2) Make sure you log everything in your /var/log/messages (even the debug
level)
3) Run /etc/init.d/net.ppp0 restart
4) Make a mental note about the start time of the log
5) The moment you see the problem, run grep pppd /var/log/messages > pppd.log
6) Delete pppd.log lines logged before step 4 
7) Use our fine "Create a New Attachment" to submit the log
Is it clear now?

Okay, understood.

I use /var/log/ppp.log defined by syslog-ng already.

So why didn't you tell me to run ppp in debug before ;)

Will take some time since atm I can't exit pppd.

Btw, does not appear if in ip-down the code is commented:

#if [ -x /etc/init.d/net.$1 ]; then
#        if /etc/init.d/net.$1 --quiet status ; then
#                export IN_BACKGROUND="true"
#                /etc/init.d/net.$1 --quiet stop
#        fi
#fi

Sorry, it took so long, here is the log you requested:

Nov  3 19:21:33 pluto pppd[15861]: Exit.

restarted /etc/init.d/net.ppp0 with debug:

Nov  3 19:21:38 pluto pppd[6888]: Plugin rp-pppoe.so loaded.
Nov  3 19:21:38 pluto pppd[6888]: RP-PPPoE plugin version 3.3 compiled against
pppd 2.4.4
Nov  3 19:21:38 pluto pppd[6889]: pppd 2.4.4 started by root, uid 0
Nov  3 19:21:38 pluto pppd[6889]: PADS: Service-Name: ''
Nov  3 19:21:38 pluto pppd[6889]: PPP session is 4034
Nov  3 19:21:38 pluto pppd[6889]: using channel 11
Nov  3 19:21:38 pluto pppd[6889]: Using interface ppp0
Nov  3 19:21:38 pluto pppd[6889]: Connect: ppp0 <--> eth1
Nov  3 19:21:38 pluto pppd[6889]: sent [LCP ConfReq id=0x1 <mru 1492> <magic
0x66639575>]
Nov  3 19:21:38 pluto pppd[6889]: rcvd [LCP ConfReq id=0x8e <mru 1492> <auth
pap> <magic 0x738e9ef1>]
Nov  3 19:21:38 pluto pppd[6889]: sent [LCP ConfAck id=0x8e <mru 1492> <auth
pap> <magic 0x738e9ef1>]
Nov  3 19:21:38 pluto pppd[6889]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic
0x66639575>]
Nov  3 19:21:38 pluto pppd[6889]: sent [LCP EchoReq id=0x0 magic=0x66639575]
Nov  3 19:21:38 pluto pppd[6889]: sent [PAP AuthReq id=0x1 user="<hidden>"
password=<hidden>]
Nov  3 19:21:38 pluto pppd[6889]: rcvd [LCP EchoRep id=0x0 magic=0x738e9ef1]
Nov  3 19:21:38 pluto pppd[6889]: rcvd [PAP AuthAck id=0x1 ""]
Nov  3 19:21:38 pluto pppd[6889]: PAP authentication succeeded
Nov  3 19:21:38 pluto pppd[6889]: peer from calling number xx:xx:xx:xx:xx:xx
authorized
Nov  3 19:21:38 pluto pppd[6889]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0>]
Nov  3 19:21:38 pluto pppd[6889]: rcvd [IPCP ConfNak id=0x1 <addr
xxx.xxx.xxx.28>]
Nov  3 19:21:38 pluto pppd[6889]: sent [IPCP ConfReq id=0x2 <addr
xxx.xxx.xxx.28>]
Nov  3 19:21:38 pluto pppd[6889]: rcvd [IPCP ConfAck id=0x2 <addr
xxx.xxx.xxx.28>]
Nov  3 19:21:38 pluto pppd[6889]: rcvd [IPCP ConfReq id=0x29 <addr
xxx.xxx.xxx.78>]
Nov  3 19:21:38 pluto pppd[6889]: sent [IPCP ConfAck id=0x29 <addr
xxx.xxx.xxx.78>]
Nov  3 19:21:38 pluto pppd[6889]: local  IP address xxx.xxx.xxx.28
Nov  3 19:21:38 pluto pppd[6889]: remote IP address xxx.xxx.xxx.78
Nov  3 19:21:38 pluto pppd[6889]: Script /etc/ppp/ip-up started (pid 6931)
Nov  3 19:21:59 pluto pppd[6889]: Script /etc/ppp/ip-up finished (pid 6931),
status = 0x0

sending kill -HUP to pppd:

Nov  3 19:22:39 pluto pppd[6889]: Hangup (SIGHUP)
Nov  3 19:22:39 pluto pppd[6889]: Connect time 1.1 minutes.
Nov  3 19:22:39 pluto pppd[6889]: Sent 111406 bytes, received 80365 bytes.
Nov  3 19:22:39 pluto pppd[6889]: Script /etc/ppp/ip-down started (pid 7826)
Nov  3 19:22:39 pluto pppd[6889]: sent [LCP TermReq id=0x2 "User request"]
Nov  3 19:22:39 pluto pppd[6889]: rcvd [LCP TermAck id=0x2]
Nov  3 19:22:39 pluto pppd[6889]: Connection terminated.
Nov  3 19:22:39 pluto pppd[6889]: Waiting for 1 child processes...
Nov  3 19:22:39 pluto pppd[6889]:   script /etc/ppp/ip-down, pid 7826
Nov  3 19:22:44 pluto pppd[6889]: sending SIGTERM to process 7826
Nov  3 19:22:45 pluto pppd[6889]: PADS: Service-Name: ''
Nov  3 19:22:45 pluto pppd[6889]: PPP session is 4249
Nov  3 19:22:45 pluto pppd[6889]: using channel 12
Nov  3 19:22:45 pluto pppd[6889]: Using interface ppp0
Nov  3 19:22:45 pluto pppd[6889]: Connect: ppp0 <--> eth1
Nov  3 19:22:45 pluto pppd[6889]: sent [LCP ConfReq id=0x3 <mru 1492> <magic
0x967fdcf9>]
Nov  3 19:22:45 pluto pppd[6889]: Child process /etc/ppp/ip-down (pid 7826)
terminated with signal 15
Nov  3 19:22:45 pluto pppd[6889]: rcvd [LCP ConfReq id=0xfd <mru 1492> <auth
pap> <magic 0x4f09cbba>]
Nov  3 19:22:45 pluto pppd[6889]: sent [LCP ConfAck id=0xfd <mru 1492> <auth
pap> <magic 0x4f09cbba>]
Nov  3 19:22:45 pluto pppd[6889]: rcvd [LCP ConfAck id=0x3 <mru 1492> <magic
0x967fdcf9>]
Nov  3 19:22:45 pluto pppd[6889]: sent [LCP EchoReq id=0x0 magic=0x967fdcf9]
Nov  3 19:22:45 pluto pppd[6889]: sent [PAP AuthReq id=0x2 user="<hidden>"
password=<hidden>]
Nov  3 19:22:45 pluto pppd[6889]: rcvd [LCP EchoRep id=0x0 magic=0x4f09cbba]
Nov  3 19:22:45 pluto pppd[6889]: rcvd [PAP AuthAck id=0x2 ""]
Nov  3 19:22:45 pluto pppd[6889]: PAP authentication succeeded
Nov  3 19:22:45 pluto pppd[6889]: peer from calling number xx:xx:xx:xx:xx:xx
authorized
Nov  3 19:22:45 pluto pppd[6889]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0>]
Nov  3 19:22:45 pluto pppd[6889]: rcvd [IPCP ConfNak id=0x3 <addr
xxx.xxx.xxx.14>]
Nov  3 19:22:45 pluto pppd[6889]: sent [IPCP ConfReq id=0x4 <addr
xxx.xxx.xxx.14>]
Nov  3 19:22:45 pluto pppd[6889]: rcvd [IPCP ConfAck id=0x4 <addr
xxx.xxx.xxx.14>]
Nov  3 19:22:45 pluto pppd[6889]: rcvd [IPCP ConfReq id=0xde <addr
xxx.xxx.xxx.78>]
Nov  3 19:22:45 pluto pppd[6889]: sent [IPCP ConfAck id=0xde <addr
xxx.xxx.xxx.78>]
Nov  3 19:22:45 pluto pppd[6889]: local  IP address xxx.xxx.xxx.14
Nov  3 19:22:45 pluto pppd[6889]: remote IP address xxx.xxx.xxx.78
Nov  3 19:22:45 pluto pppd[6889]: Script /etc/ppp/ip-up started (pid 8071)
Nov  3 19:23:07 pluto pppd[6889]: Script /etc/ppp/ip-up finished (pid 8071),
status = 0x0

Workaround:

disable the code in ip-down as in: 

https://bugs.gentoo.org/show_bug.cgi?id=153798#c11

Then the ip-down finishes successfully:

Nov  3 19:35:33 pluto pppd[6889]: Hangup (SIGHUP)
Nov  3 19:35:33 pluto pppd[6889]: Connect time 1.2 minutes.
Nov  3 19:35:33 pluto pppd[6889]: Sent 56661 bytes, received 28717 bytes.
Nov  3 19:35:33 pluto pppd[6889]: Script /etc/ppp/ip-down started (pid 12207)
Nov  3 19:35:33 pluto pppd[6889]: sent [LCP TermReq id=0x8 "User request"]
Nov  3 19:35:33 pluto pppd[6889]: rcvd [LCP TermAck id=0x8]
Nov  3 19:35:33 pluto pppd[6889]: Connection terminated.
Nov  3 19:35:33 pluto pppd[6889]: Waiting for 1 child processes...
Nov  3 19:35:33 pluto pppd[6889]:   script /etc/ppp/ip-down, pid 12207
Nov  3 19:35:33 pluto pppd[6889]: Script /etc/ppp/ip-down finished (pid 12207),
status = 0x0
Nov  3 19:35:33 pluto pppd[6889]: PADS: Service-Name: ''
Nov  3 19:35:33 pluto pppd[6889]: PPP session is 6980
Nov  3 19:35:33 pluto pppd[6889]: using channel 15
Nov  3 19:35:33 pluto pppd[6889]: Using interface ppp0
Nov  3 19:35:33 pluto pppd[6889]: Connect: ppp0 <--> eth1
Nov  3 19:35:33 pluto pppd[6889]: sent [LCP ConfReq id=0x9 <mru 1492> <magic
0xeeddd119>]
Nov  3 19:35:33 pluto pppd[6889]: rcvd [LCP ConfReq id=0x3d <mru 1492> <auth
pap> <magic 0x50ced5b7>]
Nov  3 19:35:33 pluto pppd[6889]: sent [LCP ConfAck id=0x3d <mru 1492> <auth
pap> <magic 0x50ced5b7>]
Nov  3 19:35:33 pluto pppd[6889]: rcvd [LCP ConfAck id=0x9 <mru 1492> <magic
0xeeddd119>]
Nov  3 19:35:33 pluto pppd[6889]: sent [LCP EchoReq id=0x0 magic=0xeeddd119]
Nov  3 19:35:33 pluto pppd[6889]: sent [PAP AuthReq id=0x5 user="<hidden>"
password=<hidden>]
Nov  3 19:35:34 pluto pppd[6889]: rcvd [LCP EchoRep id=0x0 magic=0x50ced5b7]
Nov  3 19:35:34 pluto pppd[6889]: rcvd [PAP AuthAck id=0x5 ""]
Nov  3 19:35:34 pluto pppd[6889]: PAP authentication succeeded
Nov  3 19:35:34 pluto pppd[6889]: peer from calling number xx:xx:xx:xx:xx:xx
authorized
Nov  3 19:35:34 pluto pppd[6889]: sent [IPCP ConfReq id=0x9 <addr 0.0.0.0>]
Nov  3 19:35:34 pluto pppd[6889]: rcvd [IPCP ConfNak id=0x9 <addr
xxx.xxx.xxx.184>]
Nov  3 19:35:34 pluto pppd[6889]: sent [IPCP ConfReq id=0xa <addr
xxx.xxx.xxx.184>]
Nov  3 19:35:34 pluto pppd[6889]: rcvd [IPCP ConfReq id=0xce <addr
xxx.xxx.xxx6.78>]
Nov  3 19:35:34 pluto pppd[6889]: sent [IPCP ConfAck id=0xce <addr
xxx.xxx.xxx6.78>]
Nov  3 19:35:34 pluto pppd[6889]: rcvd [IPCP ConfAck id=0xa <addr
xxx.xxx.xxx.184>]
Nov  3 19:35:34 pluto pppd[6889]: local  IP address xxx.xxx.xxx.184
Nov  3 19:35:34 pluto pppd[6889]: remote IP address xxx.xxx.xxx6.78
Nov  3 19:35:34 pluto pppd[6889]: Script /etc/ppp/ip-up started (pid 12236)
Nov  3 19:35:49 pluto pppd[6889]: Script /etc/ppp/ip-up finished (pid 12236),
status = 0x0

What you have described in comment 13 is normal functionality, not a bug. 

From pppd's point of view: pppd have a parameter called child-timeout, which by
default is set to 5 seconds. pppd reserves the right to kill any child that
don't end in "child-timeout" seconds.

From baselayout pov: depending on your configuration, there are actions to be
take when net.ppp0 become inactive. For instance, if net.ppp0 is the service
associated with "net" dependency, it will close all services with "need net".
To discover what serviced are depending on net.ppp0, just shut it down and see
the list of services closed by the command.

Re-closed as FIXED.