debug traces, cleanup/fix

3 files changed, 71 insertions, 29 deletions

diff --git a/xhfc/xhfc.c b/xhfc/xhfc.c
index 606770e..67168ac 100644
--- a/xhfc/xhfc.c
+++ b/xhfc/xhfc.c
@@ -303,7 +303,7 @@ static void hdlc_signal_complete(struct xhfc_span *xhfc_span, u8 stat)
 
 /* if STAT != 0, indicates bad frame */
 	if (stat != 0x00) {
-		if (DBG_HDLC && DBG_SPANFILTER) {
+		if (DBG_HDLC && DBG_SPAN(xhfc_span)) {
 			xhfc_info(xhfc, "(span %d) STAT=0x%02x indicates "
 				  "frame problem: %s\n", xhfc_span->port + 1,
 				  stat,
@@ -314,7 +314,7 @@ static void hdlc_signal_complete(struct xhfc_span *xhfc_span, u8 stat)
 				 DAHDI_EVENT_ABORT : DAHDI_EVENT_BADFCS);
 /* STAT == 0, means frame was OK */
 	} else {
-		if (DBG_HDLC && DBG_SPANFILTER) {
+		if (DBG_HDLC && DBG_SPAN(xhfc_span)) {
 			xhfc_info(xhfc,
 				  "(span %d) Frame " /*"%d" */ "is good!\n",
 				  xhfc_span->port +
@@ -342,7 +342,7 @@ static int hdlc_rx_frame(struct xhfc_span *xhfc_span)
 
 	fifo = dchan_fifo(xhfc_span);
 
-	if (DBG_VERBOSE_HDLC && DBG_SPANFILTER)
+	if (DBG_VERBOSE_HDLC && DBG_SPAN(xhfc_span))
 		xhfc_info(x, "%s(fifo %d): start\n", __func__, fifo);
 
 	xhfc_selfifo(x, fifo, RECEIVE);
@@ -353,17 +353,17 @@ static int hdlc_rx_frame(struct xhfc_span *xhfc_span)
 	debug_fz(x, fifo, __func__, debugbuf);
 
 	if (!flen && !zlen) {
-		if (DBG_VERBOSE_HDLC && DBG_SPANFILTER)
+		if (DBG_VERBOSE_HDLC && DBG_SPAN(xhfc_span))
 			xhfc_info(x, "%s, nothing to receive (%ld).\n", debugbuf, xhfc_span->non_rx_cnt);
 		xhfc_span->non_rx_cnt++;
-		if (DBG_HDLC && DBG_SPANFILTER && 0 == xhfc_span->non_rx_cnt % 2000)
+		if (DBG_HDLC && DBG_SPAN(xhfc_span) && 0 == xhfc_span->non_rx_cnt % 2000)
 			xhfc_info(x, "%s(fifo %d): Received nothing for %ld seconds.\n",
 					__func__, fifo, xhfc_span->non_rx_cnt / 2000);
 		return 0;
 	}
 	xhfc_span->non_rx_cnt = 0;
 
-	if (DBG_VERBOSE_HDLC && DBG_SPANFILTER)
+	if (DBG_VERBOSE_HDLC && DBG_SPAN(xhfc_span))
 		xhfc_info(x, "%s\n", debugbuf);
 
 	/* if we have at least one complete frame, increment zleft to include
@@ -394,12 +394,12 @@ static int hdlc_rx_frame(struct xhfc_span *xhfc_span)
 
 		zleft -= j;
 
-		if (DBG_VERBOSE_HDLC && DBG_SPANFILTER) {
+		if (DBG_VERBOSE_HDLC && DBG_SPAN(xhfc_span)) {
 			xhfc_info(x, "transmitted %d bytes to dahdi, "
 				  "zleft=%d\n", k, zleft);
 		}
 
-		if (DBG_HDLC && DBG_SPANFILTER) {
+		if (DBG_HDLC && DBG_SPAN(xhfc_span)) {
 			dbglen = 0;
 			for (i = 0; i < j; i++)
 				dbglen += sprintf(debugbuf+dbglen, "%02x ", buf[i]);
@@ -418,7 +418,7 @@ static int hdlc_rx_frame(struct xhfc_span *xhfc_span)
 	/* If this channel is not configured with a signalling span we don't
 	 * need to notify the rest of dahdi about this frame. */
 	if (!xhfc_span->sigchan) {
-		if (DBG_HDLC && DBG_SPANFILTER) {
+		if (DBG_HDLC && DBG_SPAN(xhfc_span)) {
 			xhfc_info(x, "hdlc_rx_frame(fifo %d): "
 				  "flen %d, early end.\n", fifo, flen);
 		}
@@ -428,7 +428,7 @@ static int hdlc_rx_frame(struct xhfc_span *xhfc_span)
 	if (flen) {
 #if 0 		/*  disable < 3 check for now */
 		if (zlen < 3) {
-			if (DBG_HDLC && DBG_SPANFILTER)
+			if (DBG_HDLC && DBG_SPAN(xhfc_span))
 				xhfc_info(x, "odd, zlen less then 3?\n");
 			dahdi_hdlc_abort(xhfc_span->sigchan, DAHDI_EVENT_ABORT);
 		} else
@@ -436,7 +436,7 @@ static int hdlc_rx_frame(struct xhfc_span *xhfc_span)
 		hdlc_signal_complete(xhfc_span, buf[i - 1]);
 	}
 
-	if (DBG_VERBOSE_HDLC && DBG_SPANFILTER) {
+	if (DBG_VERBOSE_HDLC && DBG_SPAN(xhfc_span)) {
 		xhfc_info(x, "hdlc_rx_frame(fifo %d): flen=%d end.\n",
 			  fifo, flen);
 	}
@@ -499,7 +499,7 @@ static int hdlc_tx_frame(struct xhfc_span *xhfc_span)
 		}
 	}
 
-	if (DBG_HDLC && DBG_SPANFILTER) {
+	if (DBG_HDLC && DBG_SPAN(xhfc_span)) {
 		xhfc_info(xhfc_span->xhfc, "%s\n", debugbuf);
 
 		dbglen = 0;
@@ -535,7 +535,7 @@ void xhfc_hdlc_hard_xmit(struct dahdi_chan *chan)
 	xhfc = xhfc_span->xhfc;
 	span = xhfc_span->port;
 
-	if ((DBG_FOPS || DBG_HDLC) && DBG_SPANFILTER) {
+	if ((DBG_FOPS || DBG_HDLC) && DBG_SPAN(xhfc_span)) {
 		xhfc_info(xhfc, "hdlc_hard_xmit on chan %s (%i/%i), " \
 			 "span=%i (sigchan=%p, chan=%p)\n", chan->name,
 			 chan->channo, chan->chanpos, span + 1,
@@ -620,10 +620,10 @@ irqreturn_t xhfc_interrupt(int irq, void *dev_id, struct pt_regs* ptregs)
 		r_su_irq = read_xhfc(xhfc, R_SU_IRQ);
 
 		for (i = 0; i < ARRAY_SIZE(xhfc->spans); i++)
+			handle_st_timers(&xhfc->spans[i]);
 			if (r_su_irq & (1 << i)/* || 2 == xhfc->ticks /* bootstrap XXX WTF*/)
 				handle_state_change(&xhfc->spans[i]);
 
-		handle_timers(xhfc);
 	}
 
 	return IRQ_HANDLED;
@@ -729,6 +729,7 @@ void xhfc_init_and_configure(struct xhfc* x)
 	/* "stage 2" */
 	xhfc_config_pcm(x, XHFC_PCM_MASTER);
 
+	/* XXX does not need to be done here. */
 	for (i = 0; i < SPANS_PER_CHIP; i++)
 		xhfc_config_st(x, x->spans[i].port, x->spans[i].nt);
 
@@ -783,6 +784,9 @@ int xhfc_spanconfig(struct dahdi_span *span, struct dahdi_lineconfig *lc)
 		lc->sync = 0;
 	}
 
+
+	activate_request(xhfc_span);
+
 	return 0;
 }
 
diff --git a/xhfc/xhfc.h b/xhfc/xhfc.h
index 4709c10..0fb1375 100644
--- a/xhfc/xhfc.h
+++ b/xhfc/xhfc.h
@@ -71,7 +71,7 @@ enum { XHFC_T1, XHFC_T2, XHFC_T3, XHFC_T4 };
 #define DBG_ALARM		(debug & DEBUG_ALARM)
 #define DBG_TIMING		(debug & DEBUG_TIMING)
 
-#define DBG_SPANFILTER		((1 << xhfc_span->port) & dbg_spanfilter)
+#define DBG_SPAN(xhfc_span)	((1 << xhfc_span->port) & dbg_spanfilter)
 
 #define CORRUPTED_FRAME 	(-1)
 
@@ -172,9 +172,10 @@ int xhfc_reset(struct xhfc * xhfc);
 int xhfc_chipid(struct xhfc * xhfc);
 int xhfc_cfg_pcm(struct xhfc * xhfc, __u8 pcm);
 
-void hfc_handle_state(struct xhfc_span *s);
-void hfc_update_st_timers(struct xhfc *x);
-void hfc_start_st(struct xhfc_span *s);
+void activate_request(struct xhfc_span* s);
+void deactivate_request(struct xhfc_span* s);
+void handle_state_change(struct xhfc_span* s);
+void handle_st_timers(struct xhfc_span* s)
 
 int __devinit xhfc_init_one(struct pci_dev *pdev, const struct pci_device_id *ent);
 void __devexit xhfc_remove_one(struct pci_dev *pdev);
diff --git a/xhfc/xhfc_st_state.c b/xhfc/xhfc_st_state.c
index 809d80f..9f3f6e6 100644
--- a/xhfc/xhfc_st_state.c
+++ b/xhfc/xhfc_st_state.c
@@ -27,11 +27,6 @@
 enum te_state { F0, F1, F2, F3, F4, F5, F6, F7, F8 };
 enum nt_state { G0, G1, G2, G3 };
 
-void activate_request(struct xhfc_span* s);
-void deactivate_request(struct xhfc_span* s);
-void handle_state_change(struct xhfc_span* s);
-void handle_st_timers(struct xhfc_span* s)
-
 static void expiry_T1(struct xhfc_span* s);
 static void expiry_T3(struct xhfc_span* s);
 
@@ -47,6 +42,12 @@ static void print_current_state(struct xhfc_span* s);
 void activate_request(struct xhfc_span* s)
 {
 	u8 a_su_wr_sta = 0;
+
+	if(DBG_ST && DBG_SPAN(s))
+		printk(KERN_DEBUG DRIVER_NAME
+				": activate on port %d\n",
+				xhfc_span->port);
+
 	SET_V_SU_ACT(a_su_wr_sta, V_SU_ACT_ACTIVATE);
 
 	write_xhfc(s->xhfc, R_SU_SEL, s->port);
@@ -56,6 +57,20 @@ void activate_request(struct xhfc_span* s)
 	else 		s->t3++;
 }
 
+void deactivate_request(struct xhfc_span* s) /* XXX not called */
+{
+
+	int sta = GET_V_SU_STA(s->state);
+
+	if(DBG_ST && DBG_SPAN(s))
+		printk(KERN_DEBUG DRIVER_NAME
+				": deactivate on port %d\n",
+				xhfc_span->port);
+
+	if(s->nt && (sta == G2 || sta == G3))
+		set_st_state(s, G4);
+}
+
 void handle_state_change(struct xhfc_span* s)
 {
 	struct xhfc* x = s->xhfc;
@@ -65,10 +80,10 @@ void handle_state_change(struct xhfc_span* s)
 	write_xhfc(x, R_SU_SEL, s->port);
 	s->state = read_xhfc(x, A_SU_RD_STA);
 
-	if(DBG_ST)
+	if(DBG_ST && DBG_SPAN(s))
 		print_state(s);
 
-	if(s->prev_state == s->state) {
+	if(unlikely(s->prev_state == s->state)) {
 		printk(KERN_WARNING DRIVER_NAME ": a state change has been "
 				"reported on port %d but it looks like the "
 				"state has not changed?", s->port + 1);
@@ -153,7 +168,6 @@ static void handle_state_change_te(struct xhfc_span* s)
 			}
 
 			signal_f7_transition(s);
-			s->f6_f7_transition = NOT_RUNNING;
 
 			break;
 	}
@@ -161,25 +175,38 @@ static void handle_state_change_te(struct xhfc_span* s)
 
 void handle_st_timers(struct xhfc_span* s)
 {
-	if(s->t1 && ++t1 > T1_MS) expiry_T1(s);
-	if(s->t3 && ++t3 > T3_MS) expiry_T3(s);
-	if(s->f6_f7_transition && ++f6_f7_transition > F6_F7_MS)
+	if(unlikely(s->t1 && ++t1 > T1_MS)) expiry_T1(s);
+	if(unlikely(s->t3 && ++t3 > T3_MS)) expiry_T3(s);
+	if(unlikely(s->f6_f7_transition && ++f6_f7_transition > F6_F7_MS))
 		signal_f7_transition(s);
 }
 
 static void signal_f7_transition(struct xhfc_span* s)
 {
+	if(DBG_ST && DBG_SPAN(s))
+		printk(KERN_DEBUG DRIVER_NAME ": signalling transition to F7 "
+				"on port %d", s->port + 1);
+
 	s->span.alarms = DAHDI_ALARM_NONE;
+	s->f6_f7_transition = NOT_RUNNING;
 }
 
 static void expiry_T1(struct xhfc_span* s)
 {
+	if(DBG_ST && DBG_SPAN(s))
+		printk(KERN_INFO DRIVER_NAME ": NT activation timeout"
+			       " on port %d", s->port + 1);
+
 	set_st_state(s, G4);
 	s->t1 = NOT_RUNNING;
 }
 
 static void expiry_T3(struct xhfc_span* s);
 {
+	if(DBG_ST && DBG_SPAN(s))
+		printk(KERN_INFO DRIVER_NAME ": TE activation timeout"
+			       " on port %d", s->port + 1);
+
 	set_st_state(s, F3);
 	s->t3 = NOT_RUNNING;
 }
@@ -187,6 +214,16 @@ static void expiry_T3(struct xhfc_span* s);
 static void set_st_state(struct xhfc_span* s, int state)
 {
 	u8 a_su_wr_sta = 0;
+
+	s->prev_state = s->state;
+	s->state = state;
+
+	if(DBG_ST && DBG_SPAN(s)) {
+		printk(KERN_DEBUG DRIVER_NAME "port %d: "
+				"Forcing state change:\n", s->port +1);
+		print_state(s);
+	}
+
 	SET_V_SU_SET_STA(a_su_wr_sta, state);
 	SET_V_SU_LD_STA(a_su_wr_sta, 1);