Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 1ddb3210 authored by Ajay Agarwal's avatar Ajay Agarwal
Browse files

net: usbnet: Add UTC timestamp logging for packets 



Add UTC timestamp logs in usbnet class driver for incoming and
outgoing data packets. This is required for packet profiling,
latency calculations and debug purposes.

By default, the skb and urb kernel addresses will show up as 0's.
To expose actual addresses, please run the command:
 echo 0 > /proc/sys/kernel/kptr_restrict

Change-Id: I3cf54eb5d38498c7858b0db07c37c0eaf93c8c37
Signed-off-by: default avatarAjay Agarwal <ajaya@codeaurora.org>
parent 02899c18

drivers/net/usb/usbnet.c

+51 −1
Original line number Diff line number Diff line
@@ -45,9 +45,13 @@ 
#include <linux/slab.h>

#include <linux/kernel.h>

#include <linux/pm_runtime.h>

#include <linux/ipc_logging.h>



#define DRIVER_VERSION		"22-Aug-2005"



#define dbg_log_string(fmt, ...) \

	ipc_log_string(dev->ipc_log_ctxt,\

			"%s: " fmt, __func__, ##__VA_ARGS__)



/*-------------------------------------------------------------------------*/
@@ -322,8 +326,10 @@ void usbnet_skb_return (struct usbnet *dev, struct sk_buff *skb) 
	struct pcpu_sw_netstats *stats64 = this_cpu_ptr(dev->stats64);

	unsigned long flags;

	int	status;

	struct timespec64 now;



	if (test_bit(EVENT_RX_PAUSED, &dev->flags)) {

		dbg_log_string("skb %pK added to pause list", skb);

		skb_queue_tail(&dev->rxq_pause, skb);

		return;

	}
@@ -346,6 +352,8 @@ void usbnet_skb_return (struct usbnet *dev, struct sk_buff *skb) 
	if (skb_defer_rx_timestamp(skb))

		return;



	getnstimeofday64(&now);

	dbg_log_string("skb %pK, time %lu.%lu", skb, now.tv_sec, now.tv_nsec);

	status = netif_rx (skb);

	if (status != NET_RX_SUCCESS)

		netif_dbg(dev, rx_err, dev->net,
@@ -402,6 +410,8 @@ int usbnet_change_mtu (struct net_device *net, int new_mtu) 
	net->mtu = new_mtu;



	dev->hard_mtu = net->mtu + net->hard_header_len;

	dbg_log_string("changing MTU to %d", dev->hard_mtu);

	netdev_info(dev->net, "Changing MTU to %d\n", dev->hard_mtu);

	if (dev->rx_urb_size == old_hard_mtu) {

		dev->rx_urb_size = dev->hard_mtu;

		if (dev->rx_urb_size > old_rx_urb_size) {
@@ -489,9 +499,11 @@ static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags) 
	unsigned long		lockflags;

	size_t			size = dev->rx_urb_size;



	dbg_log_string("urb %pK", urb);

	/* prevent rx skb allocation when error ratio is high */

	if (test_bit(EVENT_RX_KILL, &dev->flags)) {

		usb_free_urb(urb);

		dbg_log_string("high error rate, aborting...");

		return -ENOLINK;

	}
@@ -501,11 +513,13 @@ static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags) 
		skb = __netdev_alloc_skb_ip_align(dev->net, size, flags);

	if (!skb) {

		netif_dbg(dev, rx_err, dev->net, "no rx skb\n");

		dbg_log_string("skb alloc fail");

		usbnet_defer_kevent (dev, EVENT_RX_MEMORY);

		usb_free_urb (urb);

		return -ENOMEM;

	}



	dbg_log_string("skb %pK", skb);

	entry = (struct skb_data *) skb->cb;

	entry->urb = urb;

	entry->dev = dev;
@@ -549,6 +563,7 @@ static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags) 
	}

	spin_unlock_irqrestore (&dev->rxq.lock, lockflags);

	if (retval) {

		dbg_log_string("Submission error %d", retval);

		dev_kfree_skb_any (skb);

		usb_free_urb (urb);

	}
@@ -573,7 +588,9 @@ static inline void rx_process (struct usbnet *dev, struct sk_buff *skb) 
	if (dev->driver_info->flags & FLAG_MULTI_PACKET)

		goto done;



	dbg_log_string("skb %pK", skb);

	if (skb->len < ETH_HLEN) {

		dbg_log_string("Very short skb->len %d", skb->len);

		dev->net->stats.rx_errors++;

		dev->net->stats.rx_length_errors++;

		netif_dbg(dev, rx_err, dev->net, "rx length %d\n", skb->len);
@@ -595,11 +612,15 @@ static void rx_complete (struct urb *urb) 
	struct usbnet		*dev = entry->dev;

	int			urb_status = urb->status;

	enum skb_state		state;

	struct timespec64 now;



	skb_put (skb, urb->actual_length);

	state = rx_done;

	entry->urb = NULL;



	getnstimeofday64(&now);

	dbg_log_string("skb %pK, urb %pK, time %lu.%lu",

		       skb, urb, now.tv_sec, now.tv_nsec);

	switch (urb_status) {

	/* success */

	case 0:
@@ -653,6 +674,7 @@ static void rx_complete (struct urb *urb) 
		break;

	}



	dbg_log_string("status %d, state %d", urb_status, state);

	/* stop rx if packet error rate is high */

	if (++dev->pkt_cnt > 30) {

		dev->pkt_cnt = 0;
@@ -864,6 +886,9 @@ int usbnet_stop (struct net_device *net) 
	else

		usb_autopm_put_interface(dev->intf);



	dbg_log_string();

	netdev_info(dev->net, "%s\n", __func__);



	return 0;

}

EXPORT_SYMBOL_GPL(usbnet_stop);
@@ -949,6 +974,10 @@ int usbnet_open (struct net_device *net) 
			usb_autopm_put_interface(dev->intf);

		}

	}



	dbg_log_string();

	netdev_info(dev->net, "%s\n", __func__);



	return retval;

done:

	usb_autopm_put_interface(dev->intf);
@@ -1259,7 +1288,11 @@ static void tx_complete (struct urb *urb) 
	struct sk_buff		*skb = (struct sk_buff *) urb->context;

	struct skb_data		*entry = (struct skb_data *) skb->cb;

	struct usbnet		*dev = entry->dev;

	struct timespec64 now;



	getnstimeofday64(&now);

	dbg_log_string("skb %pK, urb %pK, time %lu.%lu",

		       skb, urb, now.tv_sec, now.tv_nsec);

	if (urb->status == 0) {

		struct pcpu_sw_netstats *stats64 = this_cpu_ptr(dev->stats64);

		unsigned long flags;
@@ -1305,6 +1338,7 @@ static void tx_complete (struct urb *urb) 
		}

	}



	dbg_log_string("status %d", urb->status);

	usb_autopm_put_interface_async(dev->intf);

	(void) defer_bh(dev, skb, &dev->txq, tx_done);

}
@@ -1371,10 +1405,13 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb, 
	struct driver_info	*info = dev->driver_info;

	unsigned long		flags;

	int retval;

	struct timespec64 now;



	if (skb)

		skb_tx_timestamp(skb);



	getnstimeofday64(&now);

	dbg_log_string("skb %pK, time %lu.%lu", skb, now.tv_sec, now.tv_nsec);

	// some devices want funky USB-level framing, for

	// win32 driver (usually) and/or hardware quirks

	if (info->tx_fixup) {
@@ -1390,9 +1427,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb, 


	if (!(urb = usb_alloc_urb (0, GFP_ATOMIC))) {

		netif_dbg(dev, tx_err, dev->net, "no urb\n");

		retval = -ENOMEM;

		goto drop;

	}



	dbg_log_string("urb %pK", urb);

	entry = (struct skb_data *) skb->cb;

	entry->urb = urb;

	entry->dev = dev;
@@ -1400,7 +1439,8 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb, 
	usb_fill_bulk_urb (urb, dev->udev, dev->out,

			skb->data, skb->len, tx_complete, skb);

	if (dev->can_dma_sg) {

		if (build_dma_sg(skb, urb) < 0)

		retval = build_dma_sg(skb, urb);

		if (retval < 0)

			goto drop;

	}

	length = urb->transfer_buffer_length;
@@ -1488,6 +1528,7 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb, 
	if (retval) {

		netif_dbg(dev, tx_err, dev->net, "drop, code %d\n", retval);

drop:

		dbg_log_string("skb dropped, error %d", retval);

		dev->net->stats.tx_dropped++;

not_drop:

		if (skb)
@@ -1540,6 +1581,7 @@ static void usbnet_bh (unsigned long param) 


	while ((skb = skb_dequeue (&dev->done))) {

		entry = (struct skb_data *) skb->cb;

		dbg_log_string("skb %pK, state %d", skb, entry->state);

		switch (entry->state) {

		case rx_done:

			entry->state = rx_cleanup;
@@ -1610,6 +1652,9 @@ void usbnet_disconnect (struct usb_interface *intf) 
	if (!dev)

		return;



	ipc_log_context_destroy(dev->ipc_log_ctxt);

	dev->ipc_log_ctxt = NULL;



	xdev = interface_to_usbdev (intf);



	netif_info(dev, probe, dev->net, "unregister '%s' usb-%s-%s, %s\n",
@@ -1832,6 +1877,11 @@ usbnet_probe (struct usb_interface *udev, const struct usb_device_id *prod) 
	if (dev->driver_info->flags & FLAG_LINK_INTR)

		usbnet_link_change(dev, 0, 0);



	dev->ipc_log_ctxt = ipc_log_context_create(IPC_LOG_NUM_PAGES,

						   dev->net->name, 0);

	if (!dev->ipc_log_ctxt)

		pr_err("%s: Error getting ipc_log_ctxt\n", __func__);



	return 0;



out5:

include/linux/usb/usbnet.h

+4 −0
Original line number Diff line number Diff line
@@ -22,6 +22,8 @@ 
#ifndef	__LINUX_USB_USBNET_H

#define	__LINUX_USB_USBNET_H



#define IPC_LOG_NUM_PAGES 30



/* interface from usbnet core to each USB networking link we handle */

struct usbnet {

	/* housekeeping */
@@ -82,6 +84,8 @@ struct usbnet { 
#		define EVENT_LINK_CHANGE	11

#		define EVENT_SET_RX_MODE	12

#		define EVENT_NO_IP_ALIGN	13



	void			*ipc_log_ctxt;

};



static inline struct usb_driver *driver_of(struct usb_interface *intf)