net: rmnet_data: Add trace points for device force unassociation

Added trace points to debug processing time of rmnet_config_notify_cb.
Additionally, tracepoints were added for succesfull associate/unassociate
events. Needed to debug unusually slow cleanup.

New trace points are:
rmnet_unregister_cb_unhandled
rmnet_unregister_cb_entry
rmnet_unregister_cb_exit
rmnet_unregister_cb_clear_vnds
rmnet_unregister_cb_clear_lepcs
rmnet_associate
rmnet_unassociate

Change-Id: I0269435d9c7234ef21092ba13510fff106a1966f
Signed-off-by: Harout Hedeshian <harouth@codeaurora.org>

net/rmnet_data/rmnet_data_config.c

@@ -25,6 +25,7 @@
 #include "rmnet_data_handlers.h"
 #include "rmnet_data_vnd.h"
 #include "rmnet_data_private.h"
+#include "rmnet_data_trace.h"
 
 RMNET_LOG_MODULE(RMNET_DATA_LOGMASK_CONFIG);
 
@@ -703,6 +704,7 @@ int rmnet_unassociate_network_device(struct net_device *dev)
 
 	/* Explicitly release the reference from the device */
 	dev_put(dev);
+	trace_rmnet_unassociate(dev);
 	return RMNET_CONFIG_OK;
 }
 
@@ -835,6 +837,7 @@ int rmnet_associate_network_device(struct net_device *dev)
 
 	/* Explicitly hold a reference to the device */
 	dev_hold(dev);
+	trace_rmnet_associate(dev);
 	return RMNET_CONFIG_OK;
 }
 
@@ -1146,6 +1149,7 @@ static void rmnet_force_unassociate_device(struct net_device *dev)
 		return;
 	}
 
+	trace_rmnet_unregister_cb_clear_vnds(dev);
 	/* Check the VNDs for offending mappings */
 	for (i = 0; i < RMNET_DATA_MAX_VND; i++) {
 		vndev = rmnet_vnd_get_by_id(i);
@@ -1166,7 +1170,8 @@ static void rmnet_force_unassociate_device(struct net_device *dev)
 		}
 	}
 
-	/* Clear on the mappings on the phys ep */
+	/* Clear the mappings on the phys ep */
+	trace_rmnet_unregister_cb_clear_lepcs(dev);
 	rmnet_unset_logical_endpoint_config(dev, RMNET_LOCAL_LOGICAL_ENDPOINT);
 	for (i = 0; i < RMNET_DATA_MAX_LOGICAL_EP; i++)
 		rmnet_unset_logical_endpoint_config(dev, i);
@@ -1195,13 +1200,16 @@ int rmnet_config_notify_cb(struct notifier_block *nb,
 	switch (event) {
 	case NETDEV_UNREGISTER_FINAL:
 	case NETDEV_UNREGISTER:
+		trace_rmnet_unregister_cb_entry(dev);
 		if (_rmnet_is_physical_endpoint_associated(dev)) {
 			LOGH("Kernel is trying to unregister %s", dev->name);
 			rmnet_force_unassociate_device(dev);
 		}
+		trace_rmnet_unregister_cb_exit(dev);
 		break;
 
 	default:
+		trace_rmnet_unregister_cb_unhandled(dev);
 		LOGD("Unhandeled event [%lu]", event);
 		break;
 	}

net/rmnet_data/rmnet_data_trace.h

@@ -240,6 +240,71 @@ TRACE_EVENT(rmnet_map_checksum_uplink_packet,
 		__get_str(name), __entry->res)
 )
 
+DECLARE_EVENT_CLASS(rmnet_physdev_action_template,
+
+	TP_PROTO(struct net_device *dev),
+
+	TP_ARGS(dev),
+
+	TP_STRUCT__entry(
+		__string(name, dev->name)
+	),
+
+	TP_fast_assign(
+		__assign_str(name, dev->name);
+	),
+
+	TP_printk("Physical dev=%s", __get_str(name))
+)
+
+DEFINE_EVENT(rmnet_physdev_action_template, rmnet_unregister_cb_unhandled,
+
+	TP_PROTO(struct net_device *dev),
+
+	TP_ARGS(dev)
+);
+
+DEFINE_EVENT(rmnet_physdev_action_template, rmnet_unregister_cb_entry,
+
+	TP_PROTO(struct net_device *dev),
+
+	TP_ARGS(dev)
+);
+
+DEFINE_EVENT(rmnet_physdev_action_template, rmnet_unregister_cb_exit,
+
+	TP_PROTO(struct net_device *dev),
+
+	TP_ARGS(dev)
+);
+
+DEFINE_EVENT(rmnet_physdev_action_template, rmnet_unregister_cb_clear_vnds,
+
+	TP_PROTO(struct net_device *dev),
+
+	TP_ARGS(dev)
+);
+
+DEFINE_EVENT(rmnet_physdev_action_template, rmnet_unregister_cb_clear_lepcs,
+
+	TP_PROTO(struct net_device *dev),
+
+	TP_ARGS(dev)
+);
+
+DEFINE_EVENT(rmnet_physdev_action_template, rmnet_associate,
+
+	TP_PROTO(struct net_device *dev),
+
+	TP_ARGS(dev)
+);
+
+DEFINE_EVENT(rmnet_physdev_action_template, rmnet_unassociate,
+
+	TP_PROTO(struct net_device *dev),
+
+	TP_ARGS(dev)
+);
 #endif /* _RMNET_DATA_TRACE_H_ */
 
 /* This part must be outside protection */