vmxnet3: add logging support to the control plane [VPP-1470]

There are different flavors of vmxnet3 device, esxi server, vm fusion, vmware
workstation, and vmware player, that we need to communicate with. Each of
them also has different versions. We really need the control plane logging
to debug when things don't work as expected.

Change-Id: Idab6896e3d8bf841f1cd877c13a21531fa110568
Signed-off-by: Steven <sluong@cisco.com>

4 files changed, 87 insertions, 17 deletions

diff --git a/src/plugins/vmxnet3/cli.c b/src/plugins/vmxnet3/cli.c
index 170f9ad7f5b..096791b1003 100644
--- a/src/plugins/vmxnet3/cli.c
+++ b/src/plugins/vmxnet3/cli.c
@@ -567,9 +567,12 @@ VLIB_CLI_COMMAND (show_vmxnet3_command, static) = {
 clib_error_t *
 vmxnet3_cli_init (vlib_main_t * vm)
 {
+  vmxnet3_main_t *vmxm = &vmxnet3_main;
+
   /* initialize binary API */
   vmxnet3_plugin_api_hookup (vm);
 
+  vmxm->log_default = vlib_log_register_class ("vmxnet3", 0);
   return 0;
 }
 
diff --git a/src/plugins/vmxnet3/output.c b/src/plugins/vmxnet3/output.c
index 2a8494ed447..1dc394a62ef 100644
--- a/src/plugins/vmxnet3/output.c
+++ b/src/plugins/vmxnet3/output.c
@@ -197,7 +197,8 @@ VNET_DEVICE_CLASS_TX_FN (vmxnet3_device_class) (vlib_main_t * vm,
        * Device can start reading the packet
        */
       txq->tx_desc[first_idx].flags[0] ^= VMXNET3_TXF_GEN;
-      vmxnet3_reg_write (vd, 0, VMXNET3_REG_TXPROD, txq->tx_ring.produce);
+      vmxnet3_reg_write_inline (vd, 0, VMXNET3_REG_TXPROD,
+				txq->tx_ring.produce);
 
       buffers++;
       n_left--;
diff --git a/src/plugins/vmxnet3/vmxnet3.c b/src/plugins/vmxnet3/vmxnet3.c
index ac99411a4e2..ccc76dae06f 100644
--- a/src/plugins/vmxnet3/vmxnet3.c
+++ b/src/plugins/vmxnet3/vmxnet3.c
@@ -319,7 +319,7 @@ vmxnet3_device_init (vlib_main_t * vm, vmxnet3_device_t * vd,
   ret = vmxnet3_reg_read (vd, 1, VMXNET3_REG_CMD);
   if (ret != 0)
     {
-      error = clib_error_return (0, "error on quisecing device rc (%u)", ret);
+      error = clib_error_return (0, "error on quiescing device rc (%u)", ret);
       return error;
     }
 
@@ -497,6 +497,9 @@ vmxnet3_create_if (vlib_main_t * vm, vmxnet3_create_if_args_t * args)
 	clib_error_return (error,
 			   "queue size must be <= 4096, >= 64, "
 			   "and multiples of 64");
+      vlib_log (VLIB_LOG_LEVEL_ERR, vmxm->log_default, "%U: %s",
+		format_vlib_pci_addr, &args->addr,
+		"queue size must be <= 4096, >= 64, and multiples of 64");
       return;
     }
 
@@ -507,6 +510,8 @@ vmxnet3_create_if (vlib_main_t * vm, vmxnet3_create_if_args_t * args)
 	args->rv = VNET_API_ERROR_INVALID_VALUE;
 	args->error =
 	  clib_error_return (error, "PCI address in use");
+	vlib_log (VLIB_LOG_LEVEL_ERR, vmxm->log_default, "%U: %s",
+		  format_vlib_pci_addr, &args->addr, "pci address in use");
 	return;
       }
   }));
@@ -528,37 +533,70 @@ vmxnet3_create_if (vlib_main_t * vm, vmxnet3_create_if_args_t * args)
       args->error =
 	clib_error_return (error, "pci-addr %U", format_vlib_pci_addr,
 			   &args->addr);
+      vlib_log (VLIB_LOG_LEVEL_ERR, vmxm->log_default, "%U: %s",
+		format_vlib_pci_addr, &args->addr,
+		"error encountered on pci device open");
       return;
     }
-  vd->pci_dev_handle = h;
 
+  /*
+   * Do not use vmxnet3_log_error prior to this line since the macro
+   * references vd->pci_dev_handle
+   */
+  vd->pci_dev_handle = h;
   vlib_pci_set_private_data (h, vd->dev_instance);
 
   if ((error = vlib_pci_bus_master_enable (h)))
-    goto error;
+    {
+      vmxnet3_log_error (vd, "error encountered on pci bus master enable");
+      goto error;
+    }
 
   if ((error = vlib_pci_map_region (h, 0, (void **) &vd->bar[0])))
-    goto error;
+    {
+      vmxnet3_log_error (vd, "error encountered on pci map region for bar 0");
+      goto error;
+    }
 
   if ((error = vlib_pci_map_region (h, 1, (void **) &vd->bar[1])))
-    goto error;
+    {
+      vmxnet3_log_error (vd, "error encountered on pci map region for bar 1");
+      goto error;
+    }
 
   if ((error = vlib_pci_register_msix_handler (h, 0, 1,
 					       &vmxnet3_irq_0_handler)))
-    goto error;
+    {
+      vmxnet3_log_error (vd,
+			 "error encountered on pci register msix handler 0");
+      goto error;
+    }
 
   if ((error = vlib_pci_register_msix_handler (h, 1, 1,
 					       &vmxnet3_irq_1_handler)))
-    goto error;
+    {
+      vmxnet3_log_error (vd,
+			 "error encountered on pci register msix handler 1");
+      goto error;
+    }
 
   if ((error = vlib_pci_enable_msix_irq (h, 0, 2)))
-    goto error;
+    {
+      vmxnet3_log_error (vd, "error encountered on pci enable msix irq");
+      goto error;
+    }
 
   if ((error = vlib_pci_intr_enable (h)))
-    goto error;
+    {
+      vmxnet3_log_error (vd, "error encountered on pci interrupt enable");
+      goto error;
+    }
 
   if ((error = vmxnet3_device_init (vm, vd, args)))
-    goto error;
+    {
+      vmxnet3_log_error (vd, "error encountered on device init");
+      goto error;
+    }
 
   /* create interface */
   error = ethernet_register_interface (vnm, vmxnet3_device_class.index,
@@ -566,7 +604,11 @@ vmxnet3_create_if (vlib_main_t * vm, vmxnet3_create_if_args_t * args)
 				       &vd->hw_if_index, vmxnet3_flag_change);
 
   if (error)
-    goto error;
+    {
+      vmxnet3_log_error (vd,
+			 "error encountered on ethernet register interface");
+      goto error;
+    }
 
   vnet_sw_interface_t *sw = vnet_get_hw_sw_interface (vnm, vd->hw_if_index);
   vd->sw_if_index = sw->sw_if_index;
diff --git a/src/plugins/vmxnet3/vmxnet3.h b/src/plugins/vmxnet3/vmxnet3.h
index 491b8c10246..daf6275ec0f 100644
--- a/src/plugins/vmxnet3/vmxnet3.h
+++ b/src/plugins/vmxnet3/vmxnet3.h
@@ -166,7 +166,7 @@ enum
   _(7, GET_DEV_EXTRA_INFO, "get dev extra info") \
   _(8, GET_CONF_INTR, "get conf intr") \
   _(9, GET_ADAPTIVE_RING_INFO, "get adaptive ring info") \
-  _(10, GET_TXDATA_DESC_SIZE, "gte txdata desc size") \
+  _(10, GET_TXDATA_DESC_SIZE, "get txdata desc size") \
   _(11, RESERVED5, "reserved5")
 
 enum
@@ -496,6 +496,7 @@ typedef struct
   vlib_physmem_region_index_t physmem_region;
   u32 physmem_region_alloc;
   u16 msg_id_base;
+  vlib_log_class_t log_default;
 } vmxnet3_main_t;
 
 extern vmxnet3_main_t vmxnet3_main;
@@ -531,16 +532,39 @@ format_function_t format_vmxnet3_device;
 format_function_t format_vmxnet3_device_name;
 format_function_t format_vmxnet3_input_trace;
 
+#define vmxnet3_log_debug(dev, f, ...) \
+  vlib_log (VLIB_LOG_LEVEL_DEBUG, vmxnet3_main.log_default, "%U: " f, \
+	    format_vlib_pci_addr, vlib_pci_get_addr(dev->pci_dev_handle), \
+	    ## __VA_ARGS__)
+
+#define vmxnet3_log_error(dev, f, ...)			     \
+  vlib_log (VLIB_LOG_LEVEL_ERR, vmxnet3_main.log_default, "%U: " f, \
+	    format_vlib_pci_addr, vlib_pci_get_addr(dev->pci_dev_handle), \
+	    ## __VA_ARGS__)
+
+/* no log version, called by data plane */
 static_always_inline void
-vmxnet3_reg_write (vmxnet3_device_t * vd, u8 bar, u32 addr, u32 val)
+vmxnet3_reg_write_inline (vmxnet3_device_t * vd, u8 bar, u32 addr, u32 val)
 {
   *(volatile u32 *) ((u8 *) vd->bar[bar] + addr) = val;
 }
 
+static_always_inline void
+vmxnet3_reg_write (vmxnet3_device_t * vd, u8 bar, u32 addr, u32 val)
+{
+  vmxnet3_log_debug (vd, "reg wr bar %u addr 0x%x val 0x%x", bar, addr, val);
+  vmxnet3_reg_write_inline (vd, bar, addr, val);
+}
+
 static_always_inline u32
 vmxnet3_reg_read (vmxnet3_device_t * vd, u8 bar, u32 addr)
 {
-  return *(volatile u32 *) (vd->bar[bar] + addr);
+  u32 val;
+
+  val = *(volatile u32 *) (vd->bar[bar] + addr);
+  vmxnet3_log_debug (vd, "reg rd bar %u addr 0x%x val 0x%x", bar, addr, val);
+
+  return val;
 }
 
 static_always_inline uword
@@ -600,7 +624,7 @@ vmxnet3_rxq_refill_ring0 (vlib_main_t * vm, vmxnet3_device_t * vd,
       n_alloc--;
     }
 
-  vmxnet3_reg_write (vd, 0, VMXNET3_REG_RXPROD, ring->produce);
+  vmxnet3_reg_write_inline (vd, 0, VMXNET3_REG_RXPROD, ring->produce);
 
   return 0;
 }
@@ -642,7 +666,7 @@ vmxnet3_rxq_refill_ring1 (vlib_main_t * vm, vmxnet3_device_t * vd,
       n_alloc--;
     }
 
-  vmxnet3_reg_write (vd, 0, VMXNET3_REG_RXPROD2, ring->produce);
+  vmxnet3_reg_write_inline (vd, 0, VMXNET3_REG_RXPROD2, ring->produce);
 
   return 0;
 }