diff -r -U4 ppp-2.4.4/pppd/chap-new.c ppp-2.4.4+times/pppd/chap-new.c
--- ppp-2.4.4/pppd/chap-new.c	2005-07-13 11:41:58.000000000 +0100
+++ ppp-2.4.4+times/pppd/chap-new.c	2009-06-27 09:20:37.000000000 +0100
@@ -78,8 +78,9 @@
 	int flags;
 	char *name;
 	struct chap_digest_type *digest;
 	unsigned char priv[64];		/* private area for digest's use */
+	unsigned long long ts;
 } client;
 
 /*
  * These limits apply to challenge and response packets we send.
@@ -140,8 +141,9 @@
 chap_init(int unit)
 {
 	memset(&client, 0, sizeof(client));
 	memset(&server, 0, sizeof(server));
+	client.ts = 0;
 
 	chap_md5_init();
 #ifdef CHAPMS
 	chapms_init();
@@ -423,16 +425,21 @@
 	unsigned char *p;
 	unsigned char response[RESP_MAX_PKTLEN];
 	char rname[MAXNAMELEN+1];
 	char secret[MAXSECRETLEN+1];
+	struct timeval tv;
 
 	if ((cs->flags & (LOWERUP | AUTH_STARTED)) != (LOWERUP | AUTH_STARTED))
 		return;		/* not ready */
 	if (len < 2 || len < pkt[0] + 1)
 		return;		/* too short */
 	clen = pkt[0];
 	nlen = len - (clen + 1);
 
+	tv.tv_sec = tv.tv_usec = cs->ts = 0;
+	if (gettimeofday(&tv, NULL) == 0)
+		cs->ts = (unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec;
+
 	/* Null terminate and clean remote name. */
 	slprintf(rname, sizeof(rname), "%.*v", nlen, pkt + clen + 1);
 
 	/* Microsoft doesn't send their name back in the PPP packet */
@@ -471,14 +478,22 @@
 chap_handle_status(struct chap_client_state *cs, int code, int id,
 		   unsigned char *pkt, int len)
 {
 	const char *msg = NULL;
+	struct timeval tv;
 
 	if ((cs->flags & (AUTH_DONE|AUTH_STARTED|LOWERUP))
 	    != (AUTH_STARTED|LOWERUP))
 		return;
 	cs->flags |= AUTH_DONE;
 
+	tv.tv_sec = tv.tv_usec = 0;
+	if (cs->ts != 0 && gettimeofday(&tv, NULL) == 0)
+		cs->ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec) - cs->ts;
+	else
+		cs->ts = 0;
+	len = 0;
+
 	if (code == CHAP_SUCCESS) {
 		/* used for MS-CHAP v2 mutual auth, yuck */
 		if (cs->digest->check_success != NULL) {
 			if (!(*cs->digest->check_success)(pkt, len, cs->priv))
@@ -491,13 +506,21 @@
 		else
 			msg = "CHAP authentication failed";
 	}
 	if (msg) {
-		if (len > 0)
-			info("%s: %.*v", msg, len, pkt);
-		else
-			info("%s", msg);
+		if (cs->ts <= 0) {
+			if (len > 0)
+				info("%s: %.*v", msg, len, pkt);
+			else
+				info("%s", msg);
+		} else {
+			if (len > 0)
+				info("%s: %.*v (%s in %lu.%06lus)", msg, len, pkt, cs->name, (unsigned long)(cs->ts/1000000), (unsigned long)(cs->ts%1000000));
+			else
+				info("%s (%s in %lu.%06lus)", msg, cs->name, (unsigned long)(cs->ts/1000000), (unsigned long)(cs->ts%1000000));
+		}
 	}
+	cs->ts = 0;
 	if (code == CHAP_SUCCESS)
 		auth_withpeer_success(0, PPP_CHAP, cs->digest->code);
 	else {
 		cs->flags |= AUTH_FAILED;
diff -r -U4 ppp-2.4.4/pppd/ipcp.c ppp-2.4.4+times/pppd/ipcp.c
--- ppp-2.4.4/pppd/ipcp.c	2005-08-26 00:59:34.000000000 +0100
+++ ppp-2.4.4+times/pppd/ipcp.c	2009-11-01 10:38:55.000000000 +0000
@@ -279,8 +279,10 @@
 
 #define CODENAME(x)	((x) == CONFACK ? "ACK" : \
 			 (x) == CONFNAK ? "NAK" : "REJ")
 
+static unsigned long long ts = 0;
+
 /*
  * This state variable is used to ensure that we don't
  * run an ipcp-up/down script while one is already running.
  */
@@ -1685,10 +1687,22 @@
     u_int32_t mask;
     ipcp_options *ho = &ipcp_hisoptions[f->unit];
     ipcp_options *go = &ipcp_gotoptions[f->unit];
     ipcp_options *wo = &ipcp_wantoptions[f->unit];
+	struct timeval tv;
+
+   	IPCPDEBUG(("ipcp: up"));
 
-    IPCPDEBUG(("ipcp: up"));
+	tv.tv_sec = tv.tv_usec = 0;
+//	IPCPDEBUG(("ipcp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));
+	if (gettimeofday(&tv, NULL) == 0) {
+		if (ts > 0 && (ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec) - ts) > 0)
+   			info("IPCP was down for %lu.%06lus", (unsigned long)(ts/1000000), (unsigned long)(ts%1000000));
+//		IPCPDEBUG(("ipcp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));
+		ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec);
+	} else
+		ts = 0;
+//	IPCPDEBUG(("ipcp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));
 
     /*
      * We must have a non-zero IP address for both ends of the link.
      */
@@ -1864,9 +1878,23 @@
 static void
 ipcp_down(f)
     fsm *f;
 {
+	struct timeval tv;
+
     IPCPDEBUG(("ipcp: down"));
+
+	tv.tv_sec = tv.tv_usec = 0;
+//	IPCPDEBUG(("ipcp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned long)(ts/1000000), (unsigned long)(ts%1000000)));
+	if (gettimeofday(&tv, NULL) == 0) {
+		if (ts > 0 && (ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec) - ts) > 0)
+   			info("IPCP was up for %lu.%06lus", (unsigned long)(ts/1000000), (unsigned long)(ts%1000000));
+//		IPCPDEBUG(("ipcp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned long)(ts/1000000), (unsigned long)(ts%1000000)));
+		ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec);
+	} else
+		ts = 0;
+//	IPCPDEBUG(("ipcp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned long)(ts/1000000), (unsigned long)(ts%1000000)));
+
     /* XXX a bit IPv4-centric here, we only need to get the stats
      * before the interface is marked down. */
     /* XXX more correct: we must get the stats before running the notifiers,
      * at least for the radius plugin */
diff -r -U4 ppp-2.4.4/pppd/ipv6cp.c ppp-2.4.4+times/pppd/ipv6cp.c
--- ppp-2.4.4/pppd/ipv6cp.c	2005-08-26 00:59:34.000000000 +0100
+++ ppp-2.4.4+times/pppd/ipv6cp.c	2009-11-01 15:12:53.000000000 +0000
@@ -305,8 +305,10 @@
 
 #define CODENAME(x)	((x) == CONFACK ? "ACK" : \
 			 (x) == CONFNAK ? "NAK" : "REJ")
 
+static unsigned long long ts = 0;
+
 /*
  * This state variable is used to ensure that we don't
  * run an ipcp-up/down script while one is already running.
  */
@@ -1172,10 +1174,22 @@
 {
     ipv6cp_options *ho = &ipv6cp_hisoptions[f->unit];
     ipv6cp_options *go = &ipv6cp_gotoptions[f->unit];
     ipv6cp_options *wo = &ipv6cp_wantoptions[f->unit];
+	struct timeval tv;
+
+	IPV6CPDEBUG(("ipv6cp: up"));
 
-    IPV6CPDEBUG(("ipv6cp: up"));
+	tv.tv_sec = tv.tv_usec = 0;
+//	IPV6CPDEBUG(("ipv6cp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));
+	if (gettimeofday(&tv, NULL) == 0) {
+		if (ts > 0 && (ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec) - ts) > 0)
+			info("IPV6CP was down for %lu.%06lus", (unsigned long)(ts/1000000), (unsigned long)(ts%1000000));
+//		IPV6CPDEBUG(("ipv6cp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));
+		ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec);
+	} else
+		ts = 0;
+//	IPV6CPDEBUG(("ipv6cp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));
 
     /*
      * We must have a non-zero LL address for both ends of the link.
      */
@@ -1302,9 +1316,23 @@
 static void
 ipv6cp_down(f)
     fsm *f;
 {
+	struct timeval tv;
+
     IPV6CPDEBUG(("ipv6cp: down"));
+
+	tv.tv_sec = tv.tv_usec = 0;
+//	IPV6CPDEBUG(("ipv6cp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));	
+	if (gettimeofday(&tv, NULL) == 0) {
+		if (ts > 0 && (ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec) - ts) > 0)
+			info("IPV6CP was up for %lu.%06lus", (unsigned long)(ts/1000000), (unsigned long)(ts%1000000));
+//		IPV6CPDEBUG(("ipv6cp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));	
+		ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec);
+	} else
+		ts = 0;
+//	IPV6CPDEBUG(("ipv6cp: tv=%u,%u ts=%u,%u", tv.tv_sec, tv.tv_usec, (unsigned int)(ts/1000000), (unsigned int)(ts%1000000)));	
+
     update_link_stats(f->unit);
     if (ipv6cp_is_up) {
 	ipv6cp_is_up = 0;
 	np_down(f->unit, PPP_IPV6);
diff -r -U4 ppp-2.4.4/pppd/main.c ppp-2.4.4+times/pppd/main.c
--- ppp-2.4.4/pppd/main.c	2006-06-04 04:52:50.000000000 +0100
+++ ppp-2.4.4+times/pppd/main.c	2009-06-27 09:22:08.000000000 +0100
@@ -219,8 +219,9 @@
     pid_t	pid;
     char	*prog;
     void	(*done) __P((void *));
     void	*arg;
+	unsigned long long ts;
     struct subprocess *next;
 };
 
 static struct subprocess *children;
@@ -1761,13 +1762,20 @@
     chp = (struct subprocess *) malloc(sizeof(struct subprocess));
     if (chp == NULL) {
 	warn("losing track of %s process", prog);
     } else {
+	struct timeval tv;
+
 	chp->pid = pid;
 	chp->prog = prog;
 	chp->done = done;
 	chp->arg = arg;
 	chp->next = children;
+
+	tv.tv_sec = tv.tv_usec = chp->ts = 0;
+	if (gettimeofday(&tv, NULL) == 0)
+		chp->ts = (unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec;
+
 	children = chp;
     }
 }
 
@@ -1796,23 +1804,39 @@
 forget_child(pid, status)
     int pid, status;
 {
     struct subprocess *chp, **prevp;
+	struct timeval tv;
 
     for (prevp = &children; (chp = *prevp) != NULL; prevp = &chp->next) {
         if (chp->pid == pid) {
 	    --n_children;
 	    *prevp = chp->next;
 	    break;
 	}
     }
+
+	tv.tv_sec = tv.tv_usec = 0;
+	if (chp->ts > 0 && gettimeofday(&tv, NULL) == 0)
+		chp->ts = ((unsigned long long)tv.tv_sec * 1000000 + tv.tv_usec) - chp->ts;
+
     if (WIFSIGNALED(status)) {
-        warn("Child process %s (pid %d) terminated with signal %d",
-	     (chp? chp->prog: "??"), pid, WTERMSIG(status));
-    } else if (debug)
-        dbglog("Script %s finished (pid %d), status = 0x%x",
-	       (chp? chp->prog: "??"), pid,
-	       WIFEXITED(status) ? WEXITSTATUS(status) : status);
+		if (chp->ts <= 0)
+        	warn("Child process %s (pid %d) terminated with signal %d",
+		     (chp? chp->prog: "??"), pid, WTERMSIG(status));
+		else
+        	warn("Child process %s (pid %d) terminated with signal %d (%lu.%06lus)",
+		     (chp? chp->prog: "??"), pid, WTERMSIG(status), (unsigned long)(chp->ts/1000000), (unsigned long)(chp->ts%1000000));
+    } else if (debug) {
+		if (chp->ts <= 0)
+        	dbglog("Script %s finished (pid %d), status = 0x%x",
+		       (chp? chp->prog: "??"), pid,
+		       WIFEXITED(status) ? WEXITSTATUS(status) : status);
+		else
+        	dbglog("Script %s finished (pid %d), status = 0x%x (%lu.%06lus)",
+		       (chp? chp->prog: "??"), pid,
+		       WIFEXITED(status) ? WEXITSTATUS(status) : status, (unsigned long)(chp->ts/1000000), (unsigned long)(chp->ts%1000000));
+	}
     if (chp && chp->done)
         (*chp->done)(chp->arg);
     if (chp)
         free(chp);