Changes to improve state reporting in libpri. (#7260)

git-svn-id: https://origsvn.digium.com/svn/libpri/trunk@350 2fbb986a-6c06-0410-b554-c9c1f0a7f128
2006-06-06 22:06:52 +00:00
parent 7db8af4b80
commit de008c4d60
2 changed files with 48 additions and 35 deletions
--- a/pri_internal.h
+++ b/pri_internal.h
@@ -27,6 +27,9 @@

 #include <sys/time.h>

+#define DBGHEAD __FILE__ ":%d %s: "
+#define DBGINFO __LINE__,__PRETTY_FUNCTION__
+
 struct pri_sched {
 	struct timeval when;
 	void (*callback)(void *data);
--- a/q921.c
+++ b/q921.c
@@ -80,7 +80,7 @@ static int q921_transmit(struct pri *pri, q921_h *h, int len)
 	pri->q921_txcount++;      
 #endif
 	/* Just send it raw */
-	if (pri->debug & PRI_DEBUG_Q921_DUMP)
+	if (pri->debug & (PRI_DEBUG_Q921_DUMP | PRI_DEBUG_Q921_RAW))
 		q921_dump(pri, h, len, pri->debug & PRI_DEBUG_Q921_RAW, 1);
 	/* Write an extra two bytes for the FCS */
 	res = pri->write_func ? pri->write_func(pri, h, len + 2) : 0;
@@ -111,7 +111,7 @@ static void q921_send_ua(struct pri *pri, int pfbit)
 		pri_error(pri, "Don't know how to U/A on a type %d node\n", pri->localtype);
 		return;
 	}
-	if (pri->debug & PRI_DEBUG_Q921_STATE)
+	if (pri->debug & (PRI_DEBUG_Q921_STATE | PRI_DEBUG_Q921_DUMP))
 		pri_message(pri, "Sending Unnumbered Acknowledgement\n");
 	q921_transmit(pri, &h, 3);
 }
@@ -143,9 +143,11 @@ static void q921_send_sabme(void *vpri, int now)
 		pri_error(pri, "Don't know how to U/A on a type %d node\n", pri->localtype);
 		return;
 	}
-	if (pri->debug & PRI_DEBUG_Q921_STATE)
+	if (pri->debug & (PRI_DEBUG_Q921_STATE | PRI_DEBUG_Q921_DUMP))
 		pri_message(pri, "Sending Set Asynchronous Balanced Mode Extended\n");
 	q921_transmit(pri, &h, 3);
+	if (pri->debug & PRI_DEBUG_Q921_STATE && pri->q921_state != Q921_AWAITING_ESTABLISH)
+		pri_message(pri, DBGHEAD "q921_state now is Q921_AWAITING_ESTABLISH\n", DBGINFO);
 	pri->q921_state = Q921_AWAITING_ESTABLISH;
 }

@@ -166,7 +168,7 @@ static int q921_ack_packet(struct pri *pri, int num)
 				prev->next = f->next;
 			else
 				pri->txqueue = f->next;
-			if (pri->debug & PRI_DEBUG_Q921_STATE)
+			if (pri->debug & PRI_DEBUG_Q921_DUMP)
 				pri_message(pri, "-- ACKing packet %d, new txqueue is %d (-1 means empty)\n", f->h.n_s, pri->txqueue ? pri->txqueue->h.n_s : -1);
 			/* Update v_a */
 			pri->v_a = num;
@@ -180,7 +182,7 @@ static int q921_ack_packet(struct pri *pri, int num)
 			while(f) {
 				if (!f->transmitted) {
 					/* Send it now... */
-					if (pri->debug & PRI_DEBUG_Q921_STATE)
+					if (pri->debug & PRI_DEBUG_Q921_DUMP)
 						pri_message(pri, "-- Finally transmitting %d, since window opened up\n", f->h.n_s);
 					f->transmitted++;
 					pri->windowlen++;
@@ -206,7 +208,7 @@ static void reschedule_t203(struct pri *pri)
 {
 	if (pri->t203_timer) {
 		pri_schedule_del(pri, pri->t203_timer);
-		if (pri->debug &  PRI_DEBUG_Q921_STATE)
+		if (pri->debug & PRI_DEBUG_Q921_DUMP)
 			pri_message(pri, "-- Restarting T203 counter\n");
 		/* Nothing to transmit, start the T203 counter instead */
 		pri->t203_timer = pri_schedule_event(pri, pri->timers[PRI_TIMER_T203], t203_expire, pri);
@@ -229,31 +231,31 @@ static pri_event *q921_ack_rx(struct pri *pri, int ack)
 		return ev;
 	}
 	/* Cancel each packet as necessary */
-	if (pri->debug & PRI_DEBUG_Q921_STATE)
+	if (pri->debug & PRI_DEBUG_Q921_DUMP)
 		pri_message(pri, "-- ACKing all packets from %d to (but not including) %d\n", pri->v_a, ack);
 	for (x=pri->v_a; x != ack; Q921_INC(x)) 
 		cnt += q921_ack_packet(pri, x);	
 	if (!pri->txqueue) {
-		if (pri->debug &  PRI_DEBUG_Q921_STATE)
+		if (pri->debug & PRI_DEBUG_Q921_DUMP)
 			pri_message(pri, "-- Since there was nothing left, stopping T200 counter\n");
 		/* Something was ACK'd.  Stop T200 counter */
 		pri_schedule_del(pri, pri->t200_timer);
 		pri->t200_timer = 0;
 	}
 	if (pri->t203_timer) {
-		if (pri->debug &  PRI_DEBUG_Q921_STATE)
+		if (pri->debug & PRI_DEBUG_Q921_DUMP)
 			pri_message(pri, "-- Stopping T203 counter since we got an ACK\n");
 		pri_schedule_del(pri, pri->t203_timer);
 		pri->t203_timer = 0;
 	}
 	if (pri->txqueue) {
 		/* Something left to transmit, Start the T200 counter again if we stopped it */
-		if (pri->debug &  PRI_DEBUG_Q921_STATE)
+		if (pri->debug & PRI_DEBUG_Q921_DUMP)
 			pri_message(pri, "-- Something left to transmit (%d), restarting T200 counter\n", pri->txqueue->h.n_s);
 		if (!pri->t200_timer)
 			pri->t200_timer = pri_schedule_event(pri, pri->timers[PRI_TIMER_T200], t200_expire, pri);
 	} else {
-		if (pri->debug &  PRI_DEBUG_Q921_STATE)
+		if (pri->debug & PRI_DEBUG_Q921_DUMP)
 			pri_message(pri, "-- Nothing left, starting T203 counter\n");
 		/* Nothing to transmit, start the T203 counter instead */
 		pri->t203_timer = pri_schedule_event(pri, pri->timers[PRI_TIMER_T203], t203_expire, pri);
@@ -281,7 +283,7 @@ static void q921_reject(struct pri *pri, int pf)
 		pri_error(pri, "Don't know how to U/A on a type %d node\n", pri->localtype);
 		return;
 	}
-	if (pri->debug & PRI_DEBUG_Q921_STATE)
+	if (pri->debug & PRI_DEBUG_Q921_DUMP)
 		pri_message(pri, "Sending Reject (%d)\n", pri->v_r);
 	pri->sentrej = 1;
 	q921_transmit(pri, &h, 4);
@@ -313,7 +315,7 @@ static void q921_rr(struct pri *pri, int pbit, int cmd) {
 		return;
 	}
 	pri->v_na = pri->v_r;	/* Make a note that we've already acked this */
-	if (pri->debug & PRI_DEBUG_Q921_STATE)
+	if (pri->debug & PRI_DEBUG_Q921_DUMP)
 		pri_message(pri, "Sending Receiver Ready (%d)\n", pri->v_r);
 	q921_transmit(pri, &h, 4);
 }
@@ -323,7 +325,7 @@ static void t200_expire(void *vpri)
 	struct pri *pri = vpri;
 	if (pri->txqueue) {
 		/* Retransmit first packet in the queue, setting the poll bit */
-		if (pri->debug & PRI_DEBUG_Q921_STATE)
+		if (pri->debug & PRI_DEBUG_Q921_DUMP)
 			pri_message(pri, "-- T200 counter expired, What to do...\n");
 		/* Force Poll bit */
 		pri->txqueue->h.p_f = 1;	
@@ -335,7 +337,7 @@ static void t200_expire(void *vpri)
      /* Up to three retransmissions */
      if (pri->retrans < pri->timers[PRI_TIMER_N200]) {
         /* Reschedule t200_timer */
-         if (pri->debug & PRI_DEBUG_Q921_STATE)
+         if (pri->debug & PRI_DEBUG_Q921_DUMP)
            pri_message(pri, "-- Retransmitting %d bytes\n", pri->txqueue->len);
 		if (pri->busy) 
 			q921_rr(pri, 1, 1);
@@ -344,12 +346,14 @@ static void t200_expire(void *vpri)
 				pri_error(pri, "!! Not good - head of queue has not been transmitted yet\n");
 			q921_transmit(pri, (q921_h *)&pri->txqueue->h, pri->txqueue->len);
 		}
-         if (pri->debug & PRI_DEBUG_Q921_STATE) 
+         if (pri->debug & PRI_DEBUG_Q921_DUMP)
               pri_message(pri, "-- Rescheduling retransmission (%d)\n", pri->retrans);
         pri->t200_timer = pri_schedule_event(pri, pri->timers[PRI_TIMER_T200], t200_expire, pri);
      } else {
-         if (pri->debug & PRI_DEBUG_Q921_STATE) 
+         if (pri->debug & PRI_DEBUG_Q921_STATE)
               pri_message(pri, "-- Timeout occured, restarting PRI\n");
+	if (pri->debug & PRI_DEBUG_Q921_STATE && pri->q921_state != Q921_LINK_CONNECTION_RELEASED)
+		pri_message(pri, DBGHEAD "q921_state now is Q921_LINK_CONNECTION_RELEASED\n",DBGINFO);
         pri->q921_state = Q921_LINK_CONNECTION_RELEASED;
      	pri->t200_timer = 0;
         q921_dchannel_down(pri);
@@ -357,7 +361,7 @@ static void t200_expire(void *vpri)
         pri->schedev = 1;
      }
 	} else if (pri->solicitfbit) {
-         if (pri->debug & PRI_DEBUG_Q921_STATE)
+         if (pri->debug & PRI_DEBUG_Q921_DUMP)
            pri_message(pri, "-- Retrying poll with f-bit\n");
 		pri->retrans++;
 		if (pri->retrans < pri->timers[PRI_TIMER_N200]) {
@@ -365,8 +369,10 @@ static void t200_expire(void *vpri)
 			q921_rr(pri, 1, 1);
 			pri->t200_timer = pri_schedule_event(pri, pri->timers[PRI_TIMER_T200], t200_expire, pri);
 		} else {
-			if (pri->debug & PRI_DEBUG_Q921_STATE) 
+			if (pri->debug & PRI_DEBUG_Q921_STATE)
 				pri_message(pri, "-- Timeout occured, restarting PRI\n");
+			if (pri->debug & PRI_DEBUG_Q921_STATE && pri->q921_state != Q921_LINK_CONNECTION_RELEASED)
+				pri_message(pri, DBGHEAD "q921_state now is Q921_LINK_CONNECTION_RELEASED\n", DBGINFO);
 			pri->q921_state = Q921_LINK_CONNECTION_RELEASED;
 			pri->t200_timer = 0;
 			q921_dchannel_down(pri);
@@ -423,23 +429,23 @@ int q921_transmit_iframe(struct pri *pri, void *buf, int len, int cr)
 				q921_transmit(pri, (q921_h *)(&f->h), f->len);
 				f->transmitted++;
 			} else {
-				if (pri->debug & PRI_DEBUG_Q921_STATE)
+				if (pri->debug & PRI_DEBUG_Q921_DUMP)
 					pri_message(pri, "Delaying transmission of %d, window is %d/%d long\n", 
 						f->h.n_s, pri->windowlen, pri->window);
 			}
 		}
 		if (pri->t203_timer) {
-			if (pri->debug & PRI_DEBUG_Q921_STATE)
+			if (pri->debug & PRI_DEBUG_Q921_DUMP)
 				pri_message(pri, "Stopping T_203 timer\n");
 			pri_schedule_del(pri, pri->t203_timer);
 			pri->t203_timer = 0;
 		}
 		if (!pri->t200_timer) {
-			if (pri->debug & PRI_DEBUG_Q921_STATE)
+			if (pri->debug & PRI_DEBUG_Q921_DUMP)
 				pri_message(pri, "Starting T_200 timer\n");
 			pri->t200_timer = pri_schedule_event(pri, pri->timers[PRI_TIMER_T200], t200_expire, pri);
 		} else
-			if (pri->debug & PRI_DEBUG_Q921_STATE)
+			if (pri->debug & PRI_DEBUG_Q921_DUMP)
 				pri_message(pri, "T_200 timer already going (%d)\n", pri->t200_timer);
 		
 	} else {
@@ -453,7 +459,7 @@ static void t203_expire(void *vpri)
 {
 	struct pri *pri = vpri;
 	if (pri->q921_state == Q921_LINK_CONNECTION_ESTABLISHED) {
-		if (pri->debug &  PRI_DEBUG_Q921_STATE)
+		if (pri->debug & PRI_DEBUG_Q921_DUMP)
 			pri_message(pri, "T203 counter expired, sending RR and scheduling T203 again\n");
 		/* Solicit an F-bit in the other's RR */
 		pri->solicitfbit = 1;
@@ -462,7 +468,7 @@ static void t203_expire(void *vpri)
 		/* Start timer T200 to resend our RR if we don't get it */
 		pri->t203_timer = pri_schedule_event(pri, pri->timers[PRI_TIMER_T200], t200_expire, pri);
 	} else {
-		if (pri->debug &  PRI_DEBUG_Q921_STATE)
+		if (pri->debug & PRI_DEBUG_Q921_DUMP)
 			pri_message(pri, "T203 counter expired in weird state %d\n", pri->q921_state);
 		pri->t203_timer = 0;
 	}
@@ -654,6 +660,8 @@ static pri_event *q921_dchannel_up(struct pri *pri)
 	pri->sentrej = 0;
 	
 	/* Go into connection established state */
+	if (pri->debug & PRI_DEBUG_Q921_STATE && pri->q921_state != Q921_LINK_CONNECTION_ESTABLISHED)
+		pri_message(pri, DBGHEAD "q921_state now is Q921_LINK_CONNECTION_ESTABLISHED\n", DBGINFO);
 	pri->q921_state = Q921_LINK_CONNECTION_ESTABLISHED;

 	/* Start the T203 timer */
@@ -691,6 +699,8 @@ void q921_reset(struct pri *pri)
 	pri->t200_timer = 0;
 	pri->busy = 0;
 	pri->solicitfbit = 0;
+	if (pri->debug & PRI_DEBUG_Q921_STATE && pri->q921_state != Q921_LINK_CONNECTION_RELEASED)
+		pri_message(pri, DBGHEAD "q921_state now is Q921_LINK_CONNECTION_RELEASED\n", DBGINFO);
 	pri->q921_state = Q921_LINK_CONNECTION_RELEASED;
 	pri->retrans = 0;
 	pri->sentrej = 0;
@@ -739,10 +749,10 @@ static pri_event *__q921_receive_qualified(struct pri *pri, q921_h *h, int len)
 			if (h->s.p_f) {
 				/* If it's a p/f one then send back a RR in return with the p/f bit set */
 				if (pri->solicitfbit) {
-					if (pri->debug & PRI_DEBUG_Q921_STATE) 
+					if (pri->debug & PRI_DEBUG_Q921_DUMP)
 						pri_message(pri, "-- Got RR response to our frame\n");
 				} else {
-					if (pri->debug & PRI_DEBUG_Q921_STATE) 
+					if (pri->debug & PRI_DEBUG_Q921_DUMP)
 						pri_message(pri, "-- Unsolicited RR with P/F bit, responding\n");
 						q921_rr(pri, 1, 0);
 				}
@@ -751,7 +761,7 @@ static pri_event *__q921_receive_qualified(struct pri *pri, q921_h *h, int len)
 			break;
      case 1:
         /* Receiver not ready */
-         if (pri->debug & PRI_DEBUG_Q921_STATE)
+         if (pri->debug & PRI_DEBUG_Q921_DUMP)
            pri_message(pri, "-- Got receiver not ready\n");
 	 if(h->s.p_f) {
 		/* Send RR if poll bit set */
@@ -761,7 +771,7 @@ static pri_event *__q921_receive_qualified(struct pri *pri, q921_h *h, int len)
         break;   
      case 2:
         /* Just retransmit */
-         if (pri->debug & PRI_DEBUG_Q921_STATE)
+         if (pri->debug & PRI_DEBUG_Q921_DUMP)
            pri_message(pri, "-- Got reject requesting packet %d...  Retransmitting.\n", h->s.n_r);
         if (h->s.p_f) {
            /* If it has the poll bit set, send an appropriate supervisory response */
@@ -818,7 +828,7 @@ static pri_event *__q921_receive_qualified(struct pri *pri, q921_h *h, int len)
 				if (h->u.p_f) {
 					/* Section 5.7.1 says we should restart on receiving a DM response with the f-bit set to
 					   one, but we wait T200 first */
-					if (pri->debug & PRI_DEBUG_Q921_STATE)
+					if (pri->debug & (PRI_DEBUG_Q921_STATE | PRI_DEBUG_Q921_DUMP))
 						pri_message(pri, "-- Got DM Mode from peer.\n");
 					/* Disconnected mode, try again after T200 */
 					ev = q921_dchannel_down(pri);
@@ -826,7 +836,7 @@ static pri_event *__q921_receive_qualified(struct pri *pri, q921_h *h, int len)
 					return ev;
 						
 				} else {
-					if (pri->debug & PRI_DEBUG_Q921_STATE)
+					if (pri->debug & PRI_DEBUG_Q921_DUMP)
 						pri_message(pri, "-- Ignoring unsolicited DM with p/f set to 0\n");
 #if 0
 					/* Requesting that we start */
@@ -839,7 +849,7 @@ static pri_event *__q921_receive_qualified(struct pri *pri, q921_h *h, int len)
 			}
 			break;
 		case 2:
-			if (pri->debug &  PRI_DEBUG_Q921_STATE)
+			if (pri->debug & (PRI_DEBUG_Q921_STATE | PRI_DEBUG_Q921_DUMP))
 				pri_message(pri, "-- Got Disconnect from peer.\n");
 			/* Acknowledge */
 			q921_send_ua(pri, h->u.p_f);
@@ -849,7 +859,7 @@ static pri_event *__q921_receive_qualified(struct pri *pri, q921_h *h, int len)
 		case 3:
 			if (h->u.m2 == 3) {
 				/* SABME */
-				if (pri->debug & PRI_DEBUG_Q921_STATE) {
+				if (pri->debug & (PRI_DEBUG_Q921_STATE | PRI_DEBUG_Q921_DUMP)) {
 					pri_message(pri, "-- Got SABME from %s peer.\n", h->h.c_r ? "network" : "cpe");
 				}
 				if (h->h.c_r) {
@@ -871,7 +881,7 @@ static pri_event *__q921_receive_qualified(struct pri *pri, q921_h *h, int len)
 			} else if (h->u.m2 == 0) {
 					/* It's a UA */
 				if (pri->q921_state == Q921_AWAITING_ESTABLISH) {
-					if (pri->debug & PRI_DEBUG_Q921_STATE) {
+					if (pri->debug & (PRI_DEBUG_Q921_STATE | PRI_DEBUG_Q921_DUMP)) {
 						pri_message(pri, "-- Got UA from %s peer  Link up.\n", h->h.c_r ? "cpe" : "network");
 					}
 					return q921_dchannel_up(pri);
@@ -901,7 +911,7 @@ static pri_event *__q921_receive(struct pri *pri, q921_h *h, int len)
 	/* Discard FCS */
 	len -= 2;
 	
-	if (!pri->master && pri->debug & PRI_DEBUG_Q921_DUMP)
+	if (!pri->master && pri->debug & (PRI_DEBUG_Q921_DUMP | PRI_DEBUG_Q921_RAW))
 		q921_dump(pri, h, len, pri->debug & PRI_DEBUG_Q921_RAW, 0);

 	/* Check some reject conditions -- Start by rejecting improper ea's */