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: I53c23cf10958bfbc06abb1c252d368003563cd04
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 1a97dc0d0fa..566b0d68079 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 ce810f049e2..c80ad0706cc 100644
--- a/src/plugins/vmxnet3/output.c
+++ b/src/plugins/vmxnet3/output.c
@@ -195,7 +195,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 ec316c85a96..08d4d5cea52 100644
--- a/src/plugins/vmxnet3/vmxnet3.c
+++ b/src/plugins/vmxnet3/vmxnet3.c
@@ -311,7 +311,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;
     }
 
@@ -478,6 +478,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;
     }
 
@@ -488,6 +491,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;
       }
   }));
@@ -509,37 +514,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 (vm, h, vd->dev_instance);
 
   if ((error = vlib_pci_bus_master_enable (vm, h)))
-    goto error;
+    {
+      vmxnet3_log_error (vd, "error encountered on pci bus master enable");
+      goto error;
+    }
 
   if ((error = vlib_pci_map_region (vm, 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 (vm, 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 (vm, 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 (vm, 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 (vm, h, 0, 2)))
-    goto error;
+    {
+      vmxnet3_log_error (vd, "error encountered on pci enable msix irq");
+      goto error;
+    }
 
   if ((error = vlib_pci_intr_enable (vm, 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,
@@ -547,7 +585,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 befbe368d67..87ccd407073 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
@@ -494,6 +494,7 @@ typedef struct
 {
   vmxnet3_device_t *devices;
   u16 msg_id_base;
+  vlib_log_class_t log_default;
 } vmxnet3_main_t;
 
 extern vmxnet3_main_t vmxnet3_main;
@@ -529,16 +530,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, &dev->pci_addr, \
+	    ## __VA_ARGS__)
+
+#define vmxnet3_log_error(dev, f, ...)			    \
+  vlib_log (VLIB_LOG_LEVEL_ERR, vmxnet3_main.log_default, "%U: " f, \
+	    format_vlib_pci_addr, &dev->pci_addr, \
+	    ## __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
@@ -596,7 +620,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;
 }
@@ -638,7 +662,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;
 }