diff -U4 -r ppp-2.4.4/pppd/fsm.c ppp-2.4.4+debug/pppd/fsm.c --- ppp-2.4.4/pppd/fsm.c 2004-11-13 02:28:15.000000000 +0000 +++ ppp-2.4.4+debug/pppd/fsm.c 2009-06-22 18:49:57.000000000 +0100 @@ -65,9 +65,12 @@ static void fsm_rtermack __P((fsm *)); static void fsm_rcoderej __P((fsm *, u_char *, int)); static void fsm_sconfreq __P((fsm *, int)); +static char *states[] = { "INITIAL", "STARTING", "CLOSED", "STOPPED", "CLOSING", "STOPPING", "REQSENT", "ACKRCVD", "ACKSENT", "OPENED" }; + #define PROTO_NAME(f) ((f)->callbacks->proto_name) +#define STATE_NAME(f) (states[(f)->state]) int peer_mru[NUM_PPP]; @@ -79,8 +82,9 @@ void fsm_init(f) fsm *f; { + FSMDEBUG(("%s: INITIAL", PROTO_NAME(f))); f->state = INITIAL; f->flags = 0; f->id = 0; /* XXX Start with random id? */ f->timeouttime = DEFTIMEOUT; @@ -100,22 +104,25 @@ { switch( f->state ){ case INITIAL: f->state = CLOSED; + FSMDEBUG(("%s: INITIAL->CLOSED", PROTO_NAME(f))); break; case STARTING: - if( f->flags & OPT_SILENT ) + if( f->flags & OPT_SILENT ) { + FSMDEBUG(("%s: %s->STOPPED", PROTO_NAME(f), STATE_NAME(f))); f->state = STOPPED; - else { + } else { /* Send an initial configure-request */ fsm_sconfreq(f, 0); + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; } break; default: - FSMDEBUG(("%s: Up event in state %d!", PROTO_NAME(f), f->state)); + FSMDEBUG(("%s: Up event in state %s!", PROTO_NAME(f), STATE_NAME(f))); } } @@ -129,38 +136,43 @@ fsm *f; { switch( f->state ){ case CLOSED: + FSMDEBUG(("%s: %s->INITIAL", PROTO_NAME(f), STATE_NAME(f))); f->state = INITIAL; break; case STOPPED: + FSMDEBUG(("%s: %s->STARTING", PROTO_NAME(f), STATE_NAME(f))); f->state = STARTING; if( f->callbacks->starting ) (*f->callbacks->starting)(f); break; case CLOSING: + FSMDEBUG(("%s: %s->INITIAL", PROTO_NAME(f), STATE_NAME(f))); f->state = INITIAL; UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ break; case STOPPING: case REQSENT: case ACKRCVD: case ACKSENT: + FSMDEBUG(("%s: %s->STARTING", PROTO_NAME(f), STATE_NAME(f))); f->state = STARTING; UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ break; case OPENED: if( f->callbacks->down ) (*f->callbacks->down)(f); + FSMDEBUG(("%s: %s->STARTING", PROTO_NAME(f), STATE_NAME(f))); f->state = STARTING; break; default: - FSMDEBUG(("%s: Down event in state %d!", PROTO_NAME(f), f->state)); + FSMDEBUG(("%s: Down event in state %s!", PROTO_NAME(f), STATE_NAME(f))); } } @@ -172,24 +184,28 @@ fsm *f; { switch( f->state ){ case INITIAL: + FSMDEBUG(("%s: %s->STARTING", PROTO_NAME(f), STATE_NAME(f))); f->state = STARTING; if( f->callbacks->starting ) (*f->callbacks->starting)(f); break; case CLOSED: - if( f->flags & OPT_SILENT ) + if( f->flags & OPT_SILENT ) { + FSMDEBUG(("%s: %s->STOPPED", PROTO_NAME(f), STATE_NAME(f))); f->state = STOPPED; - else { + } else { /* Send an initial configure-request */ fsm_sconfreq(f, 0); + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; } break; case CLOSING: + FSMDEBUG(("%s: %s->STOPPING", PROTO_NAME(f), STATE_NAME(f))); f->state = STOPPING; /* fall through */ case STOPPED: case OPENED: @@ -227,8 +243,12 @@ * User asked for no terminate requests at all; just close it. * We've already fired off one Terminate-Request just to be nice * to the peer, but we're not going to wait for a reply. */ + if (nextstate == CLOSING) + FSMDEBUG(("%s: %s->CLOSED", PROTO_NAME(f), STATE_NAME(f))); + else + FSMDEBUG(("%s: %s->STOPPED", PROTO_NAME(f), STATE_NAME(f))); f->state = nextstate == CLOSING ? CLOSED : STOPPED; if( f->callbacks->finished ) (*f->callbacks->finished)(f); return; @@ -254,14 +274,17 @@ f->term_reason = reason; f->term_reason_len = (reason == NULL? 0: strlen(reason)); switch( f->state ){ case STARTING: + FSMDEBUG(("%s: %s->INITIAL", PROTO_NAME(f), STATE_NAME(f))); f->state = INITIAL; break; case STOPPED: + FSMDEBUG(("%s: %s->CLOSED", PROTO_NAME(f), STATE_NAME(f))); f->state = CLOSED; break; case STOPPING: + FSMDEBUG(("%s: %s->CLOSING", PROTO_NAME(f), STATE_NAME(f))); f->state = CLOSING; break; case REQSENT: @@ -289,8 +312,12 @@ if( f->retransmits <= 0 ){ /* * We've waited for an ack long enough. Peer probably heard us. */ + if (f->state == CLOSING) + FSMDEBUG(("%s: %s->CLOSED", PROTO_NAME(f), STATE_NAME(f))); + else + FSMDEBUG(("%s: %s->STOPPED", PROTO_NAME(f), STATE_NAME(f))); f->state = (f->state == CLOSING)? CLOSED: STOPPED; if( f->callbacks->finished ) (*f->callbacks->finished)(f); } else { @@ -306,8 +333,9 @@ case ACKRCVD: case ACKSENT: if (f->retransmits <= 0) { warn("%s: timeout sending Config-Requests\n", PROTO_NAME(f)); + FSMDEBUG(("%s: %s->STOPPED", PROTO_NAME(f), STATE_NAME(f))); f->state = STOPPED; if( (f->flags & OPT_PASSIVE) == 0 && f->callbacks->finished ) (*f->callbacks->finished)(f); @@ -315,15 +343,17 @@ /* Retransmit the configure-request */ if (f->callbacks->retransmit) (*f->callbacks->retransmit)(f); fsm_sconfreq(f, 1); /* Re-send Configure-Request */ - if( f->state == ACKRCVD ) - f->state = REQSENT; + if( f->state == ACKRCVD ) { + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); + f->state = REQSENT; + } } break; default: - FSMDEBUG(("%s: Timeout event in state %d!", PROTO_NAME(f), f->state)); + FSMDEBUG(("%s: Timeout event in state %s!", PROTO_NAME(f), STATE_NAME(f))); } } @@ -362,10 +392,10 @@ } len -= HEADERLEN; /* subtract header length */ if( f->state == INITIAL || f->state == STARTING ){ - FSMDEBUG(("fsm_input(%x): Rcvd packet in state %d.", - f->protocol, f->state)); + FSMDEBUG(("fsm_input(%x): Rcvd packet in state %s.", + f->protocol, STATE_NAME(f))); return; } /* @@ -431,14 +461,16 @@ /* Go down and restart negotiation */ if( f->callbacks->down ) (*f->callbacks->down)(f); /* Inform upper layers */ fsm_sconfreq(f, 0); /* Send initial Configure-Request */ + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; break; case STOPPED: /* Negotiation started by our peer */ fsm_sconfreq(f, 0); /* Send initial Configure-Request */ + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; break; } @@ -459,19 +491,24 @@ if (code == CONFACK) { if (f->state == ACKRCVD) { UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ + FSMDEBUG(("%s: %s->OPENED", PROTO_NAME(f), STATE_NAME(f))); f->state = OPENED; if (f->callbacks->up) (*f->callbacks->up)(f); /* Inform upper layers */ - } else + } else { + FSMDEBUG(("%s: %s->ACKSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = ACKSENT; + } f->nakloops = 0; } else { /* we sent CONFACK or CONFREJ */ - if (f->state != ACKRCVD) + if (f->state != ACKRCVD) { + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; + } if( code == CONFNAK ) ++f->nakloops; } } @@ -504,21 +541,24 @@ fsm_sdata(f, TERMACK, id, NULL, 0); break; case REQSENT: + FSMDEBUG(("%s: %s->ACKRCVD", PROTO_NAME(f), STATE_NAME(f))); f->state = ACKRCVD; f->retransmits = f->maxconfreqtransmits; break; case ACKRCVD: /* Huh? an extra valid Ack? oh well... */ UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ fsm_sconfreq(f, 0); + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; break; case ACKSENT: UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ + FSMDEBUG(("%s: %s->OPENED", PROTO_NAME(f), STATE_NAME(f))); f->state = OPENED; f->retransmits = f->maxconfreqtransmits; if (f->callbacks->up) (*f->callbacks->up)(f); /* Inform upper layers */ @@ -528,8 +568,9 @@ /* Go down and restart negotiation */ if (f->callbacks->down) (*f->callbacks->down)(f); /* Inform upper layers */ fsm_sconfreq(f, 0); /* Send initial Configure-Request */ + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; break; } } @@ -579,26 +620,29 @@ case REQSENT: case ACKSENT: /* They didn't agree to what we wanted - try another request */ UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ - if (ret < 0) + if (ret < 0) { f->state = STOPPED; /* kludge for stopping CCP */ - else + FSMDEBUG(("%s: %s->STOPPED", PROTO_NAME(f), STATE_NAME(f))); + } else fsm_sconfreq(f, 0); /* Send Configure-Request */ break; case ACKRCVD: /* Got a Nak/reject when we had already had an Ack?? oh well... */ UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ fsm_sconfreq(f, 0); + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; break; case OPENED: /* Go down and restart negotiation */ if (f->callbacks->down) (*f->callbacks->down)(f); /* Inform upper layers */ fsm_sconfreq(f, 0); /* Send initial Configure-Request */ + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; break; } } @@ -616,8 +660,9 @@ { switch (f->state) { case ACKRCVD: case ACKSENT: + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; /* Start over but keep trying */ break; case OPENED: @@ -625,8 +670,9 @@ info("%s terminated by peer (%0.*v)", PROTO_NAME(f), len, p); } else info("%s terminated by peer", PROTO_NAME(f)); f->retransmits = 0; + FSMDEBUG(("%s: %s->STOPPING", PROTO_NAME(f), STATE_NAME(f))); f->state = STOPPING; if (f->callbacks->down) (*f->callbacks->down)(f); /* Inform upper layers */ TIMEOUT(fsm_timeout, f, f->timeouttime); @@ -646,27 +692,31 @@ { switch (f->state) { case CLOSING: UNTIMEOUT(fsm_timeout, f); + FSMDEBUG(("%s: %s->CLOSED", PROTO_NAME(f), STATE_NAME(f))); f->state = CLOSED; if( f->callbacks->finished ) (*f->callbacks->finished)(f); break; case STOPPING: UNTIMEOUT(fsm_timeout, f); + FSMDEBUG(("%s: %s->STOPPED", PROTO_NAME(f), STATE_NAME(f))); f->state = STOPPED; if( f->callbacks->finished ) (*f->callbacks->finished)(f); break; case ACKRCVD: + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; break; case OPENED: if (f->callbacks->down) (*f->callbacks->down)(f); /* Inform upper layers */ fsm_sconfreq(f, 0); + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); f->state = REQSENT; break; } } @@ -690,10 +740,12 @@ GETCHAR(code, inp); GETCHAR(id, inp); warn("%s: Rcvd Code-Reject for code %d, id %d", PROTO_NAME(f), code, id); - if( f->state == ACKRCVD ) - f->state = REQSENT; + if( f->state == ACKRCVD ) { + FSMDEBUG(("%s: %s->REQSENT", PROTO_NAME(f), STATE_NAME(f))); + f->state = REQSENT; + } } /* @@ -709,8 +761,9 @@ case CLOSING: UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ /* fall through */ case CLOSED: + FSMDEBUG(("%s: %s->CLOSED", PROTO_NAME(f), STATE_NAME(f))); f->state = CLOSED; if( f->callbacks->finished ) (*f->callbacks->finished)(f); break; @@ -721,8 +774,9 @@ case ACKSENT: UNTIMEOUT(fsm_timeout, f); /* Cancel timeout */ /* fall through */ case STOPPED: + FSMDEBUG(("%s: %s->STOPPED", PROTO_NAME(f), STATE_NAME(f))); f->state = STOPPED; if( f->callbacks->finished ) (*f->callbacks->finished)(f); break; @@ -731,10 +785,10 @@ terminate_layer(f, STOPPING); break; default: - FSMDEBUG(("%s: Protocol-reject event in state %d!", - PROTO_NAME(f), f->state)); + FSMDEBUG(("%s: Protocol-reject event in state %s!", + PROTO_NAME(f), STATE_NAME(f))); } } diff -U4 -r ppp-2.4.4/pppd/ipv6cp.c ppp-2.4.4+debug/pppd/ipv6cp.c --- ppp-2.4.4/pppd/ipv6cp.c 2005-08-26 00:59:34.000000000 +0100 +++ ppp-2.4.4+debug/pppd/ipv6cp.c 2009-06-27 11:56:15.000000000 +0100 @@ -945,9 +945,9 @@ * In particular, if we don't know his identifier, but he does, * then accept it. */ eui64_get(ifaceid, p); - IPV6CPDEBUG(("(%s)", llv6_ntoa(ifaceid))); +// IPV6CPDEBUG(("(%s)", llv6_ntoa(ifaceid))); if (eui64_iszero(ifaceid) && eui64_iszero(go->ourid)) { orc = CONFREJ; /* Reject CI */ break; } @@ -1006,9 +1006,9 @@ break; } endswitch: - IPV6CPDEBUG((" (%s)\n", CODENAME(orc))); +// IPV6CPDEBUG((" (%s)\n", CODENAME(orc))); if (orc == CONFACK && /* Good CI */ rc != CONFACK) /* but prior CI wasnt? */ continue; /* Don't send this one */ diff -U4 -r ppp-2.4.4/pppd/pppd.h ppp-2.4.4+debug/pppd/pppd.h --- ppp-2.4.4/pppd/pppd.h 2005-08-26 00:59:34.000000000 +0100 +++ ppp-2.4.4+debug/pppd/pppd.h 2009-06-22 18:34:08.000000000 +0100 @@ -810,8 +810,9 @@ /* * Debug macros. Slightly useful for finding bugs in pppd, not particularly * useful for finding out why your connection isn't being established. */ +#define DEBUGALL 1 #ifdef DEBUGALL #define DEBUGMAIN 1 #define DEBUGFSM 1 #define DEBUGLCP 1