SMP report

[Denis Vlasenko]

On 18 August 2003 08:26, Denis Vlasenko wrote:
> On 17 August 2003 13:24, James Harper wrote:
> > I'm running 2.6.0-test3 with the latest cvs version of hostap on an SMP 
> > system and it appears much more stable than previous versions. I just 
> > tried a flood ping for a few minutes and the only error I got was:
> > 
> > Aug 17 20:19:17 portal kernel: wlan0: hfa384x_cmd_issue: cmd reg was 
> > busy for 1 usec
> > Aug 17 20:20:53 portal kernel: wlan0: detected fid change (try=0, 
> > reg=0044): 0166 a5a4 0166
> > Aug 17 20:20:59 portal kernel: wlan0: detected fid change (try=0, 
> > reg=0040): 0000 03d6 03d6
> > 
> > which probably isn't good but previously I would be getting card resets 
> > and/or crashes etc all over the place.
> 
> Hmm I will hack together a patch because I believe
> those 'fid change' messages indicate a locking bug.
> Hopefully today.

This is it. Will try to catch SMP race condition.

The interface is rather simple: printk_trace()
prints events recorded in a circular buffer,
mark_in_trace("Some text") records event.
Event is (jiffies,cpu,text) triple.

Only compile tested.
--
vda

--- hostap_hw.c.orig	Wed Aug  6 05:50:00 2003
+++ hostap_hw.c	Wed Aug 20 16:59:46 2003
@@ -2199,6 +2199,43 @@
  * and will try to get the correct fid eventually. */
 #define EXTRA_FID_READ_TESTS
 
+#ifdef EXTRA_FID_READ_TESTS
+struct trace {
+        int cpu;
+        int jiffy;
+        const char *event;
+};
+static struct trace tracebuf[16];
+static int tracepos=0;
+spinlock_t tracelock = SPIN_LOCK_UNLOCKED;
+#define TRACESZ (sizeof(tracebuf)/sizeof(tracebuf[0]))
+
+static void printk_trace(void) {
+        int i,flags;
+        spin_lock_irqsave(&tracelock,flags);
+        i = tracepos;
+        do {
+                struct trace *p = tracebuf+i;
+                printk("time:%d cpu:%d event:%s\n", p->jiffy, p->cpu, p->event);
+                i = (i+1)%TRACESZ;
+        } while(i!=tracepos);
+        spin_unlock_irqrestore(&tracelock,flags);
+}
+
+static void mark_in_trace(const char* event) {
+        int flags;
+        struct trace *p;
+
+        spin_lock_irqsave(&tracelock,flags);
+        p = tracebuf+tracepos;
+        tracepos = (tracepos+1)%TRACESZ;
+        p->jiffy = jiffies;
+        p->cpu = smp_processor_id();
+        p->event = event;
+        spin_unlock_irqrestore(&tracelock,flags);
+}
+#endif
+
 static inline u16 prism2_read_fid_reg(struct net_device *dev, u16 reg)
 {
 #ifdef EXTRA_FID_READ_TESTS
@@ -2216,6 +2253,8 @@
 		printk(KERN_DEBUG "%s: detected fid change (try=%d, reg=%04x):"
 		       " %04x %04x %04x\n",
 		       dev->name, i, reg, val, val2, val3);
+		printk_trace();
+
 		if ((val == val2 || val == val3) && val != 0)
 			return val;
 		if (val2 == val3 && val2 != 0)
@@ -2957,6 +2996,10 @@
 	local_info_t *local = (local_info_t *) dev->priv;
 	int events = 0;
 	u16 ev;
+
+#ifdef EXTRA_FID_READ_TESTS
+        mark_in_trace("prism2_interrupt");
+#endif
 
 	prism2_io_debug_add(dev, PRISM2_IO_DEBUG_CMD_INTERRUPT, 0, 0);