virtio: Add support for logging

Change-Id: Ieadf0a97379ed8b17241e454895c4e5e195dc52f
Signed-off-by: Mohsin Kazmi <sykazmi@cisco.com>
diff --git a/src/vnet/devices/virtio/cli.c b/src/vnet/devices/virtio/cli.c
index 82dc5a1..d006524 100644
--- a/src/vnet/devices/virtio/cli.c
+++ b/src/vnet/devices/virtio/cli.c
@@ -79,7 +79,7 @@
   unformat_input_t _line_input, *line_input = &_line_input;
   u32 sw_if_index = ~0;
   vnet_hw_interface_t *hw;
-  virtio_main_t *vmxm = &virtio_main;
+  virtio_main_t *vim = &virtio_main;
   virtio_if_t *vif;
   vnet_main_t *vnm = vnet_get_main ();
 
@@ -108,7 +108,7 @@
   if (hw == NULL || virtio_device_class.index != hw->dev_class_index)
     return clib_error_return (0, "not a virtio interface");
 
-  vif = pool_elt_at_index (vmxm->interfaces, hw->dev_instance);
+  vif = pool_elt_at_index (vim->interfaces, hw->dev_instance);
 
   if (virtio_pci_delete_if (vm, vif) < 0)
     return clib_error_return (0, "not a virtio pci interface");
@@ -129,7 +129,7 @@
 show_virtio_pci_fn (vlib_main_t * vm, unformat_input_t * input,
 		    vlib_cli_command_t * cmd)
 {
-  virtio_main_t *vmxm = &virtio_main;
+  virtio_main_t *vim = &virtio_main;
   vnet_main_t *vnm = &vnet_main;
   virtio_if_t *vif;
   clib_error_t *error = 0;
@@ -165,13 +165,13 @@
 
   if (vec_len (hw_if_indices) == 0)
     {
-      pool_foreach (vif, vmxm->interfaces,
+      pool_foreach (vif, vim->interfaces,
 		    vec_add1 (hw_if_indices, vif->hw_if_index);
 	);
     }
   else if (show_device_config)
     {
-      vif = pool_elt_at_index (vmxm->interfaces, hi->dev_instance);
+      vif = pool_elt_at_index (vim->interfaces, hi->dev_instance);
       if (vif->type == VIRTIO_IF_TYPE_PCI)
 	debug_device_config_space (vm, vif);
     }
@@ -194,6 +194,8 @@
 clib_error_t *
 virtio_pci_cli_init (vlib_main_t * vm)
 {
+  virtio_main_t *vim = &virtio_main;
+  vim->log_default = vlib_log_register_class ("virtio-pci", 0);
   return 0;
 }
 
diff --git a/src/vnet/devices/virtio/pci.c b/src/vnet/devices/virtio/pci.c
index 63c8c54..531a7fb 100644
--- a/src/vnet/devices/virtio/pci.c
+++ b/src/vnet/devices/virtio/pci.c
@@ -306,9 +306,9 @@
 virtio_pci_irq_0_handler (vlib_main_t * vm, vlib_pci_dev_handle_t h, u16 line)
 {
   vnet_main_t *vnm = vnet_get_main ();
-  virtio_main_t *vmxm = &virtio_main;
+  virtio_main_t *vim = &virtio_main;
   uword pd = vlib_pci_get_private_data (vm, h);
-  virtio_if_t *vif = pool_elt_at_index (vmxm->interfaces, pd);
+  virtio_if_t *vif = pool_elt_at_index (vim->interfaces, pd);
   u16 qid = line;
 
   vnet_device_input_set_interrupt_pending (vnm, vif->hw_if_index, qid);
@@ -318,9 +318,9 @@
 virtio_pci_irq_1_handler (vlib_main_t * vm, vlib_pci_dev_handle_t h, u16 line)
 {
   vnet_main_t *vnm = vnet_get_main ();
-  virtio_main_t *vmxm = &virtio_main;
+  virtio_main_t *vim = &virtio_main;
   uword pd = vlib_pci_get_private_data (vm, h);
-  virtio_if_t *vif = pool_elt_at_index (vmxm->interfaces, pd);
+  virtio_if_t *vif = pool_elt_at_index (vim->interfaces, pd);
 
   if (virtio_pci_is_link_up (vm, vif) & VIRTIO_NET_S_LINK_UP)
     {
@@ -338,9 +338,9 @@
 static void
 virtio_pci_irq_handler (vlib_main_t * vm, vlib_pci_dev_handle_t h)
 {
-  virtio_main_t *vmxm = &virtio_main;
+  virtio_main_t *vim = &virtio_main;
   uword pd = vlib_pci_get_private_data (vm, h);
-  virtio_if_t *vif = pool_elt_at_index (vmxm->interfaces, pd);
+  virtio_if_t *vif = pool_elt_at_index (vim->interfaces, pd);
   u8 isr = 0;
   u16 line = 0;
 
@@ -592,6 +592,7 @@
 virtio_pci_read_caps (vlib_main_t * vm, virtio_if_t * vif)
 {
   clib_error_t *error = 0;
+  virtio_main_t *vim = &virtio_main;
   struct virtio_pci_cap cap;
   u8 pos, common_cfg = 0, notify_base = 0, dev_cfg = 0, isr = 0;
   vlib_pci_dev_handle_t h = vif->pci_dev_handle;
@@ -625,8 +626,8 @@
 
       if (cap.cap_vndr != PCI_CAP_ID_VNDR)
 	{
-	  clib_warning ("[%2x] skipping non VNDR cap id: %2x", pos,
-			cap.cap_vndr);
+	  virtio_log_debug (vim, vif, "[%2x] %s %2x ", pos,
+			    "skipping non VNDR cap id:", cap.cap_vndr);
 	  goto next;
 	}
 
@@ -651,11 +652,12 @@
 
   if (common_cfg == 0 || notify_base == 0 || dev_cfg == 0 || isr == 0)
     {
-      clib_warning ("no modern virtio pci device found");
+      virtio_log_debug (vim, vif, "legacy virtio pci device found");
       return error;
     }
 
-  return clib_error_return (error, "modern virtio pci device found");
+  virtio_log_debug (vim, vif, "modern virtio pci device found");
+  return error;
 }
 
 static clib_error_t *
@@ -725,7 +727,7 @@
 virtio_pci_create_if (vlib_main_t * vm, virtio_pci_create_if_args_t * args)
 {
   vnet_main_t *vnm = vnet_get_main ();
-  virtio_main_t *vmxm = &virtio_main;
+  virtio_main_t *vim = &virtio_main;
   virtio_if_t *vif;
   vlib_pci_dev_handle_t h;
   clib_error_t *error = 0;
@@ -743,23 +745,29 @@
 	clib_error_return (error,
 			   "queue size must be <= 4096, >= 64, "
 			   "and multiples of 64");
+      vlib_log (VLIB_LOG_LEVEL_ERR, vim->log_default, "%U: %s",
+		format_vlib_pci_addr, &args->addr,
+		"queue size must be <= 4096, >= 64, and multiples of 64");
       return;
     }
 
   /* *INDENT-OFF* */
-  pool_foreach (vif, vmxm->interfaces, ({
+  pool_foreach (vif, vim->interfaces, ({
     if (vif->pci_addr.as_u32 == args->addr)
       {
 	args->rv = VNET_API_ERROR_INVALID_VALUE;
 	args->error =
 	  clib_error_return (error, "PCI address in use");
+	  vlib_log (VLIB_LOG_LEVEL_ERR, vim->log_default, "%U: %s",
+                format_vlib_pci_addr, &args->addr,
+                " PCI address in use");
 	return;
       }
   }));
   /* *INDENT-ON* */
 
-  pool_get (vmxm->interfaces, vif);
-  vif->dev_instance = vif - vmxm->interfaces;
+  pool_get (vim->interfaces, vif);
+  vif->dev_instance = vif - vim->interfaces;
   vif->per_interface_next_index = ~0;
   vif->pci_addr.as_u32 = args->addr;
 
@@ -774,37 +782,61 @@
        vlib_pci_device_open (vm, (vlib_pci_addr_t *) & vif->pci_addr,
 			     virtio_pci_device_ids, &h)))
     {
-      pool_put (vmxm->interfaces, vif);
+      pool_put (vim->interfaces, vif);
       args->rv = VNET_API_ERROR_INVALID_INTERFACE;
       args->error =
 	clib_error_return (error, "pci-addr %U", format_vlib_pci_addr,
 			   &vif->pci_addr);
+      vlib_log (VLIB_LOG_LEVEL_ERR, vim->log_default, "%U: %s",
+		format_vlib_pci_addr, &vif->pci_addr,
+		"error encountered on pci device open");
       return;
     }
   vif->pci_dev_handle = h;
   vlib_pci_set_private_data (vm, h, vif->dev_instance);
 
   if ((error = vlib_pci_bus_master_enable (vm, h)))
-    goto error;
+    {
+      virtio_log_error (vim, vif,
+			"error encountered on pci bus master enable");
+      goto error;
+    }
 
   if ((error = vlib_pci_io_region (vm, h, 0)))
-    goto error;
+    {
+      virtio_log_error (vim, vif, "error encountered on pci io region");
+      goto error;
+    }
 
   if ((error = virtio_pci_device_init (vm, vif, args)))
-    goto error;
+    {
+      virtio_log_error (vim, vif, "error encountered on device init");
+      goto error;
+    }
 
   if (msix_enabled == VIRTIO_MSIX_ENABLED)
     {
       if ((error = vlib_pci_register_msix_handler (vm, h, 0, 1,
 						   &virtio_pci_irq_0_handler)))
-	goto error;
-
+	{
+	  virtio_log_error (vim, vif,
+			    "error encountered on pci register msix handler 0");
+	  goto error;
+	}
       if ((error = vlib_pci_register_msix_handler (vm, h, 1, 1,
 						   &virtio_pci_irq_1_handler)))
-	goto error;
+	{
+	  virtio_log_error (vim, vif,
+			    "error encountered on pci register msix handler 1");
+	  goto error;
+	}
 
       if ((error = vlib_pci_enable_msix_irq (vm, h, 0, 2)))
-	goto error;
+	{
+	  virtio_log_error (vim, vif,
+			    "error encountered on pci enable msix irq");
+	  goto error;
+	}
     }
   else
     {
@@ -812,7 +844,11 @@
     }
 
   if ((error = vlib_pci_intr_enable (vm, h)))
-    goto error;
+    {
+      virtio_log_error (vim, vif,
+			"error encountered on pci interrupt enable");
+      goto error;
+    }
 
   vif->type = VIRTIO_IF_TYPE_PCI;
   /* create interface */
@@ -822,7 +858,11 @@
 				       virtio_pci_flag_change);
 
   if (error)
-    goto error;
+    {
+      virtio_log_error (vim, vif,
+			"error encountered on ethernet register interface");
+      goto error;
+    }
 
   vnet_sw_interface_t *sw = vnet_get_hw_sw_interface (vnm, vif->hw_if_index);
   vif->sw_if_index = sw->sw_if_index;
@@ -854,7 +894,7 @@
 virtio_pci_delete_if (vlib_main_t * vm, virtio_if_t * vif)
 {
   vnet_main_t *vnm = vnet_get_main ();
-  virtio_main_t *vmxm = &virtio_main;
+  virtio_main_t *vim = &virtio_main;
   u32 i = 0;
 
   if (vif->type != VIRTIO_IF_TYPE_PCI)
@@ -905,7 +945,7 @@
     vif->tap_fd = -1;
   clib_error_free (vif->error);
   memset (vif, 0, sizeof (*vif));
-  pool_put (vmxm->interfaces, vif);
+  pool_put (vim->interfaces, vif);
 
   return 0;
 }
diff --git a/src/vnet/devices/virtio/pci.h b/src/vnet/devices/virtio/pci.h
index 7552dd8..b08e40e 100644
--- a/src/vnet/devices/virtio/pci.h
+++ b/src/vnet/devices/virtio/pci.h
@@ -120,6 +120,27 @@
 
 #define VIRTIO_PCI_VRING_ALIGN 4096
 
+#define virtio_log_debug(vim, vif, f, ...)			\
+{								\
+  vlib_log(VLIB_LOG_LEVEL_DEBUG, vim->log_default, "%U: " f,	\
+           format_vlib_pci_addr, &vif->pci_addr,		\
+           ##__VA_ARGS__);					\
+};
+
+#define virtio_log_warning(vim, vif, f, ...)			\
+{								\
+  vlib_log(VLIB_LOG_LEVEL_WARNING, vim->log_default, "%U: " f,	\
+           format_vlib_pci_addr, &vif->pci_addr,		\
+           ##__VA_ARGS__);					\
+};
+
+#define virtio_log_error(vim, vif, f, ...)			\
+{								\
+  vlib_log(VLIB_LOG_LEVEL_ERR, vim->log_default, "%U: " f,	\
+           format_vlib_pci_addr, &vif->pci_addr,		\
+           ##__VA_ARGS__);					\
+};
+
 typedef enum
 {
   VIRTIO_MSIX_NONE = 0,
diff --git a/src/vnet/devices/virtio/virtio.h b/src/vnet/devices/virtio/virtio.h
index f4a8103..73bb33f 100644
--- a/src/vnet/devices/virtio/virtio.h
+++ b/src/vnet/devices/virtio/virtio.h
@@ -174,6 +174,9 @@
 
 typedef struct
 {
+  /* logging */
+  vlib_log_class_t log_default;
+
   virtio_if_t *interfaces;
 } virtio_main_t;