[Prism54-devel] Ndiswrapper logs

Feyd feyd at seznam.cz
Thu Dec 23 15:15:02 UTC 2004


On Wed, 22 Dec 2004 18:59:43 +0100
Jean-Baptiste Note <jean-baptiste.note at wanadoo.fr> wrote:

> 
> Hi Joerg, Philip, dear list,
> 
> I've quickly made a version of ndiswrapper (based on latest CVS, tested
> on my Linksys wgusb54) with decent pretty-print of the urbs. At least
> the infrastructure is there, so you can easily adjust the output (at the
> end of usb.c).

I'm using ndiswrapper with a fancy output (see the attachment). To decrease
chance of the lines getting corrupt I first sprintf it to a buffer and then
prinkt, still it breaks sometimes.. May be another way (socket or something)
would better suit dumping of the urbs. There is also work on usbmon in
progress, so may be we will be able to snoop the urbs without modifying the
ndiswrapper.

Feyd
-------------- next part --------------
diff -urNd ndiswrapper-orig/driver/ntoskernel.h ndiswrapper-dump/driver/ntoskernel.h
--- ndiswrapper-orig/driver/ntoskernel.h	2004-12-19 17:16:20.000000000 +0100
+++ ndiswrapper-dump/driver/ntoskernel.h	2004-12-20 10:32:08.000000000 +0100
@@ -571,6 +571,9 @@
 	/* ndiswrapper extension */
 	enum irp_work_type irp_work_type;
 	struct list_head cancel_list_entry;
+#ifdef DUMPURBS
+	struct timeval submit, complete;
+#endif
 };
 
 enum nt_obj_type
diff -urNd ndiswrapper-orig/driver/usb.c ndiswrapper-dump/driver/usb.c
--- ndiswrapper-orig/driver/usb.c	2004-12-19 17:16:20.000000000 +0100
+++ ndiswrapper-dump/driver/usb.c	2004-12-20 10:32:08.000000000 +0100
@@ -30,9 +30,16 @@
 void usb_cancel_worker(void *dummy);
 DECLARE_WORK(cancel_usb_irp_work, usb_cancel_worker, 0);
 
+#ifdef DUMPURBS
+struct timeval loaded;
+#endif
+
 void usb_init(void)
 {
 	wrap_spin_lock_init(&canceled_irps_lock);
+//#ifdef DUMPURBS
+//	do_gettimeofday(&loaded);
+//#endif
 	return;
 }
 
@@ -50,6 +57,9 @@
 	struct irp *irp = urb->context;
 	int cancel;
 
+#ifdef DUMPURBS
+	do_gettimeofday(&irp->complete);
+#endif
 
 	TRACEENTER3("urb = %p", urb);
 
@@ -74,6 +84,88 @@
 	TRACEEXIT3(return);
 }
 
+#ifdef DUMPURBS
+static long timediff_ms(struct timeval t1, struct timeval t2)
+{
+	struct timeval d;
+	
+	d.tv_sec = t2.tv_sec - t1.tv_sec;
+	d.tv_usec = t2.tv_usec - t1.tv_usec;
+	
+	if(d.tv_usec < 0) {
+		d.tv_sec--;
+		d.tv_usec += 1000000;
+	}
+	
+	d.tv_usec += 500;
+	d.tv_usec /= 1000;
+	d.tv_sec *= 1000;
+	d.tv_sec += d.tv_usec;
+	
+	return d.tv_sec;
+}
+
+#define BYTES_PER_ROW 16
+static void dumprow(char *str, unsigned char *data, int start, int end)
+{
+	int i;
+	
+	str += sprintf(str, "%08x: ", start);
+	
+	for(i = start; i < end; i++)
+		str += sprintf(str, "%02X ", data[i]);
+	
+	for(i = end; i < start + BYTES_PER_ROW; i++)
+		str += sprintf(str, "   ");
+	
+	for(i = start; i < end; i++)
+		str += sprintf(str, "%c", ((data[i] > 31) && (data[i] < 128)) ? data[i] : '.');
+}
+
+static void dumpblock(char *str, int pos, unsigned char *data, int start, int end)
+{
+	int i, _end;
+	
+	for(i = start; i < end; i += BYTES_PER_ROW) {
+		_end = i + BYTES_PER_ROW;
+		_end = _end > end ? end : _end;
+		dumprow(str + pos, data, i, _end);
+		printk(KERN_DEBUG "%s\n", str);
+		sprintf(str, "%-*s", pos, "urb:");
+	}
+}
+
+static void dumpurb(struct urb *urb)
+{
+	struct irp *irp = urb->context;
+	char *str;
+	long s, c, d;
+	int ep, pos;
+	
+	str = kmalloc(256, GFP_KERNEL);
+	
+	s = timediff_ms(loaded, irp->submit);
+	c = timediff_ms(loaded, irp->complete);
+	d = timediff_ms(irp->submit, irp->complete);
+	
+	ep = (urb->pipe >> 15) & USB_ENDPOINT_NUMBER_MASK;
+	ep |= urb->pipe & USB_DIR_IN;
+	
+	pos = sprintf(str,"urb: [>%li <%li +%-4li :%i] %02x %s ",
+		s, c, d, urb->status,
+		ep, urb->pipe & USB_DIR_IN ? "<-" : "->");
+
+	dumpblock(str, pos, urb->transfer_buffer, 0, urb->actual_length);
+	
+	if(!(urb->pipe & USB_DIR_IN) && (urb->actual_length < urb->transfer_buffer_length)) {
+		sprintf(str, "%-*s", pos, "urb: unsent data");
+		dumpblock(str, pos, urb->transfer_buffer, urb->actual_length, urb->transfer_buffer_length);
+	}
+	
+	kfree(str);
+}
+#endif /* DUMPURBS */
+
 void usb_transfer_complete_tasklet(unsigned long dummy)
 {
 	struct irp *irp;
@@ -118,15 +210,7 @@
 		nt_urb->bulkIntrTrans.transferBufLen = urb->actual_length;
 
 #ifdef DUMPURBS
-		if ((urb->pipe & USB_DIR_IN)) {
-			int i;
-
-			printk("Receiving ");
-			for (i = 0; i < urb->actual_length; i++)
-				printk("%02X ", *(((unsigned char *)
-					urb->transfer_buffer)+i));
-			printk("\n");
-		}
+		dumpurb(urb);
 #endif /* DUMPURBS */
 
 		if (irp->driver_context[2]) {
@@ -262,18 +346,6 @@
 	     USBD_TRANSFER_DIRECTION_IN)
 		urb->transfer_flags |= URB_SHORT_NOT_OK;
 
-#ifdef DUMPURBS
-	if (!(urb->pipe & USB_DIR_IN)) {
-		int i;
-
-		printk("Sending ");
-		for (i = 0; i < urb->transfer_buffer_length; i++)
-			printk("%02X ",
-				*(((unsigned char *)urb->transfer_buffer)+i));
-		printk("\n");
-	}
-#endif /* DUMPURBS */
-
 	/* non-DMA-capable buffers have to be mirrored */
 	irp->driver_context[2] = NULL;
 	if (!virt_addr_valid(nt_urb->bulkIntrTrans.transferBuf)) {
@@ -298,8 +370,17 @@
 
 	DBGTRACE3("submitting urb %p on pipe %p", urb, pipe_handle.handle);
 	/* FIXME: we should better check what GFP_ is required */
+#ifdef DUMPURBS
+	do_gettimeofday(&irp->submit);
+#endif
 	ret = WRAP_SUBMIT_URB(urb, GFP_ATOMIC);
 	if (ret != 0) {
+#ifdef DUMPURBS
+		do_gettimeofday(&irp->complete);
+		urb->actual_length = 0;
+		urb->status = ret;
+		dumpurb(urb);
+#endif
 		ERROR("usb_submit_urb() = %d", ret);
 		usb_free_urb(urb);
 		if (irp->driver_context[2])
@@ -369,18 +450,6 @@
 	     USBD_TRANSFER_DIRECTION_IN)
 		urb->transfer_flags |= URB_SHORT_NOT_OK;
 
-#ifdef DUMPURBS
-	if (!(urb->pipe & USB_DIR_IN)) {
-		int i;
-
-		printk("Sending ");
-		for (i = 0; i < urb->transfer_buffer_length; i++)
-			printk("%02X ",
-				*(((unsigned char *)urb->transfer_buffer)+i));
-		printk("\n");
-	}
-#endif /* DUMPURBS */
-
 	/* non-DMA-capable buffers have to be mirrored */
 	irp->driver_context[2] = NULL;
 	if ((nt_urb->venClsReq.transferBufLen > 0) &&
@@ -408,8 +477,17 @@
 
 	DBGTRACE3("submitting urb %p on control pipe", urb);
 	/* FIXME: we should better check what GFP_ is required */
+#ifdef DUMPURBS
+	do_gettimeofday(&irp->submit);
+#endif
 	ret = WRAP_SUBMIT_URB(urb, GFP_ATOMIC);
 	if (ret != 0) {
+#ifdef DUMPURBS
+		do_gettimeofday(&irp->complete);
+		urb->actual_length = 0;
+		urb->status = ret;
+		dumpurb(urb);
+#endif
 		ERROR("usb_submit_urb() = %d", ret);
 		kfree(dr);
 		usb_free_urb(urb);
diff -urNd ndiswrapper-orig/driver/wrapper.c ndiswrapper-dump/driver/wrapper.c
--- ndiswrapper-orig/driver/wrapper.c	2004-12-19 22:04:01.000000000 +0100
+++ ndiswrapper-dump/driver/wrapper.c	2004-12-20 10:32:08.000000000 +0100
@@ -71,6 +71,10 @@
 extern struct wrap_spinlock wrap_allocs_lock;
 extern struct wrap_spinlock dispatch_event_lock;
 
+#ifdef DUMPURBS
+extern struct timeval loaded;
+#endif
+
 static void ndis_set_rx_mode(struct net_device *dev);
 
 /*
@@ -1466,6 +1470,9 @@
 	char *env[] = {0};
 	int err;
 
+#ifdef DUMPURBS
+	do_gettimeofday(&loaded);
+#endif
 	printk(KERN_INFO "%s version %s%s loaded (preempt=%s,smp=%s)\n",
 	       DRV_NAME, NDISWRAPPER_VERSION, EXTRA_VERSION,
 #if defined CONFIG_PREEMPT


More information about the Prism54-devel mailing list