avf: add logging macros and improve logging
[vpp.git] / src / plugins / avf / device.c
index f6a00a1..8172c83 100644 (file)
@@ -43,6 +43,18 @@ static pci_device_id_t avf_pci_device_ids[] = {
   {0},
 };
 
+const static char *virtchnl_event_names[] = {
+#define _(v, n) [v] = #n,
+  foreach_virtchnl_event_code
+#undef _
+};
+
+const static char *virtchnl_link_speed_str[] = {
+#define _(v, n, s) [v] = s,
+  foreach_virtchnl_link_speed
+#undef _
+};
+
 static inline void
 avf_irq_0_disable (avf_device_t * ad)
 {
@@ -224,9 +236,14 @@ avf_rxq_init (vlib_main_t * vm, avf_device_t * ad, u16 qid, u16 rxq_size)
   rxq = vec_elt_at_index (ad->rxqs, qid);
   rxq->size = rxq_size;
   rxq->next = 0;
-  rxq->descs = vlib_physmem_alloc_aligned (vm, rxq->size *
-                                          sizeof (avf_rx_desc_t),
-                                          2 * CLIB_CACHE_LINE_BYTES);
+  rxq->descs = vlib_physmem_alloc_aligned_on_numa (vm, rxq->size *
+                                                  sizeof (avf_rx_desc_t),
+                                                  2 * CLIB_CACHE_LINE_BYTES,
+                                                  ad->numa_node);
+
+  rxq->buffer_pool_index =
+    vlib_buffer_pool_get_default_for_numa (vm, ad->numa_node);
+
   if (rxq->descs == 0)
     return vlib_physmem_last_error (vm);
 
@@ -237,7 +254,8 @@ avf_rxq_init (vlib_main_t * vm, avf_device_t * ad, u16 qid, u16 rxq_size)
   vec_validate_aligned (rxq->bufs, rxq->size, CLIB_CACHE_LINE_BYTES);
   rxq->qrx_tail = ad->bar0 + AVF_QRX_TAIL (qid);
 
-  n_alloc = vlib_buffer_alloc (vm, rxq->bufs, rxq->size - 8);
+  n_alloc = vlib_buffer_alloc_from_pool (vm, rxq->bufs, rxq->size - 8,
+                                        rxq->buffer_pool_index);
 
   if (n_alloc == 0)
     return clib_error_return (0, "buffer allocation error");
@@ -278,9 +296,10 @@ avf_txq_init (vlib_main_t * vm, avf_device_t * ad, u16 qid, u16 txq_size)
   txq = vec_elt_at_index (ad->txqs, qid);
   txq->size = txq_size;
   txq->next = 0;
-  txq->descs = vlib_physmem_alloc_aligned (vm, txq->size *
-                                          sizeof (avf_tx_desc_t),
-                                          2 * CLIB_CACHE_LINE_BYTES);
+  txq->descs = vlib_physmem_alloc_aligned_on_numa (vm, txq->size *
+                                                  sizeof (avf_tx_desc_t),
+                                                  2 * CLIB_CACHE_LINE_BYTES,
+                                                  ad->numa_node);
   if (txq->descs == 0)
     return vlib_physmem_last_error (vm);
 
@@ -370,7 +389,7 @@ avf_send_to_pf (vlib_main_t * vm, avf_device_t * ad, virtchnl_ops_t op,
   int n_retry = 5;
 
 
-  /* supppres interrupt in the next adminq receive slot
+  /* suppress interrupt in the next adminq receive slot
      as we are going to wait for response
      we only need interrupts when event is received */
   d = &ad->arq[ad->arq_next_slot];
@@ -480,6 +499,8 @@ avf_op_version (vlib_main_t * vm, avf_device_t * ad,
     .minor = VIRTCHNL_VERSION_MINOR,
   };
 
+  avf_log_debug (ad, "version: major %u minor %u", myver.major, myver.minor);
+
   err = avf_send_to_pf (vm, ad, VIRTCHNL_OP_VERSION, &myver,
                        sizeof (virtchnl_version_info_t), ver,
                        sizeof (virtchnl_version_info_t));
@@ -494,12 +515,37 @@ clib_error_t *
 avf_op_get_vf_resources (vlib_main_t * vm, avf_device_t * ad,
                         virtchnl_vf_resource_t * res)
 {
+  clib_error_t *err = 0;
   u32 bitmap = (VIRTCHNL_VF_OFFLOAD_L2 | VIRTCHNL_VF_OFFLOAD_RSS_PF |
                VIRTCHNL_VF_OFFLOAD_WB_ON_ITR | VIRTCHNL_VF_OFFLOAD_VLAN |
                VIRTCHNL_VF_OFFLOAD_RX_POLLING);
 
-  return avf_send_to_pf (vm, ad, VIRTCHNL_OP_GET_VF_RESOURCES, &bitmap,
-                        sizeof (u32), res, sizeof (virtchnl_vf_resource_t));
+  avf_log_debug (ad, "get_vf_reqources: bitmap 0x%x", bitmap);
+  err = avf_send_to_pf (vm, ad, VIRTCHNL_OP_GET_VF_RESOURCES, &bitmap,
+                       sizeof (u32), res, sizeof (virtchnl_vf_resource_t));
+
+  if (err == 0)
+    {
+      int i;
+      avf_log_debug (ad, "get_vf_reqources: num_vsis %u num_queue_pairs %u "
+                    "max_vectors %u max_mtu %u vf_offload_flags 0x%04x "
+                    "rss_key_size %u rss_lut_size %u",
+                    res->num_vsis, res->num_queue_pairs, res->max_vectors,
+                    res->max_mtu, res->vf_offload_flags, res->rss_key_size,
+                    res->rss_lut_size);
+      for (i = 0; i < res->num_vsis; i++)
+       avf_log_debug (ad, "get_vf_reqources_vsi[%u]: vsi_id %u "
+                      "num_queue_pairs %u vsi_type %u qset_handle %u "
+                      "default_mac_addr %U", i,
+                      res->vsi_res[i].vsi_id,
+                      res->vsi_res[i].num_queue_pairs,
+                      res->vsi_res[i].vsi_type,
+                      res->vsi_res[i].qset_handle,
+                      format_ethernet_address,
+                      res->vsi_res[i].default_mac_addr);
+    }
+
+  return err;
 }
 
 clib_error_t *
@@ -517,6 +563,10 @@ avf_op_config_rss_lut (vlib_main_t * vm, avf_device_t * ad)
   for (i = 0; i < ad->rss_lut_size; i++)
     rl->lut[i] = i % ad->n_rx_queues;
 
+  avf_log_debug (ad, "config_rss_lut: vsi_id %u rss_lut_size %u lut %U",
+                rl->vsi_id, rl->lut_entries, format_hex_bytes, rl->lut,
+                rl->lut_entries);
+
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_CONFIG_RSS_LUT, msg, msg_len, 0,
                         0);
 }
@@ -537,6 +587,10 @@ avf_op_config_rss_key (vlib_main_t * vm, avf_device_t * ad)
   for (i = 0; i < ad->rss_key_size; i++)
     rk->key[i] = (u8) random_u32 (&seed);
 
+  avf_log_debug (ad, "config_rss_key: vsi_id %u rss_key_size %u key %U",
+                rk->vsi_id, rk->key_len, format_hex_bytes, rk->key,
+                rk->key_len);
+
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_CONFIG_RSS_KEY, msg, msg_len, 0,
                         0);
 }
@@ -544,6 +598,8 @@ avf_op_config_rss_key (vlib_main_t * vm, avf_device_t * ad)
 clib_error_t *
 avf_op_disable_vlan_stripping (vlib_main_t * vm, avf_device_t * ad)
 {
+  avf_log_debug (ad, "disable_vlan_stripping");
+
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_DISABLE_VLAN_STRIPPING, 0, 0, 0,
                         0);
 }
@@ -554,7 +610,12 @@ avf_config_promisc_mode (vlib_main_t * vm, avf_device_t * ad)
   virtchnl_promisc_info_t pi = { 0 };
 
   pi.vsi_id = ad->vsi_id;
-  pi.flags = 1;
+  pi.flags = FLAG_VF_UNICAST_PROMISC | FLAG_VF_MULTICAST_PROMISC;
+
+  avf_log_debug (ad, "config_promisc_mode: unicast %s multicast %s",
+                pi.flags & FLAG_VF_UNICAST_PROMISC ? "on" : "off",
+                pi.flags & FLAG_VF_MULTICAST_PROMISC ? "on" : "off");
+
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_CONFIG_PROMISCUOUS_MODE, &pi,
                         sizeof (virtchnl_promisc_info_t), 0, 0);
 }
@@ -575,6 +636,9 @@ avf_op_config_vsi_queues (vlib_main_t * vm, avf_device_t * ad)
   ci->vsi_id = ad->vsi_id;
   ci->num_queue_pairs = n_qp;
 
+  avf_log_debug (ad, "config_vsi_queues: vsi_id %u num_queue_pairs %u",
+                ad->vsi_id, ci->num_queue_pairs);
+
   for (i = 0; i < n_qp; i++)
     {
       virtchnl_txq_info_t *txq = &ci->qpair[i].txq;
@@ -587,10 +651,14 @@ avf_op_config_vsi_queues (vlib_main_t * vm, avf_device_t * ad)
        {
          avf_rxq_t *q = vec_elt_at_index (ad->rxqs, i);
          rxq->ring_len = q->size;
-         rxq->databuffer_size = VLIB_BUFFER_DEFAULT_FREE_LIST_BYTES;
+         rxq->databuffer_size = vlib_buffer_get_default_data_size (vm);
          rxq->dma_ring_addr = avf_dma_addr (vm, ad, (void *) q->descs);
          avf_reg_write (ad, AVF_QRX_TAIL (i), q->size - 1);
        }
+      avf_log_debug (ad, "config_vsi_queues_rx[%u]: max_pkt_size %u "
+                    "ring_len %u databuffer_size %u dma_ring_addr 0x%llx",
+                    i, rxq->max_pkt_size, rxq->ring_len,
+                    rxq->databuffer_size, rxq->dma_ring_addr);
 
       avf_txq_t *q = vec_elt_at_index (ad->txqs, i);
       txq->vsi_id = ad->vsi_id;
@@ -600,6 +668,9 @@ avf_op_config_vsi_queues (vlib_main_t * vm, avf_device_t * ad)
          txq->ring_len = q->size;
          txq->dma_ring_addr = avf_dma_addr (vm, ad, (void *) q->descs);
        }
+      avf_log_debug (ad, "config_vsi_queues_tx[%u]: ring_len %u "
+                    "dma_ring_addr 0x%llx", i, txq->ring_len,
+                    txq->dma_ring_addr);
     }
 
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_CONFIG_VSI_QUEUES, msg, msg_len,
@@ -622,6 +693,11 @@ avf_op_config_irq_map (vlib_main_t * vm, avf_device_t * ad)
   imi->vecmap[0].vector_id = 1;
   imi->vecmap[0].vsi_id = ad->vsi_id;
   imi->vecmap[0].rxq_map = 1;
+
+  avf_log_debug (ad, "config_irq_map: vsi_id %u vector_id %u rxq_map %u",
+                ad->vsi_id, imi->vecmap[0].vector_id,
+                imi->vecmap[0].rxq_map);
+
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_CONFIG_IRQ_MAP, msg, msg_len, 0,
                         0);
 }
@@ -640,8 +716,16 @@ avf_op_add_eth_addr (vlib_main_t * vm, avf_device_t * ad, u8 count, u8 * macs)
   al = (virtchnl_ether_addr_list_t *) msg;
   al->vsi_id = ad->vsi_id;
   al->num_elements = count;
+
+  avf_log_debug (ad, "add_eth_addr: vsi_id %u num_elements %u",
+                ad->vsi_id, al->num_elements);
+
   for (i = 0; i < count; i++)
-    clib_memcpy_fast (&al->list[i].addr, macs + i * 6, 6);
+    {
+      clib_memcpy_fast (&al->list[i].addr, macs + i * 6, 6);
+      avf_log_debug (ad, "add_eth_addr[%u]: %U", i,
+                    format_ethernet_address, &al->list[i].addr);
+    }
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_ADD_ETH_ADDR, msg, msg_len, 0,
                         0);
 }
@@ -650,14 +734,23 @@ clib_error_t *
 avf_op_enable_queues (vlib_main_t * vm, avf_device_t * ad, u32 rx, u32 tx)
 {
   virtchnl_queue_select_t qs = { 0 };
-  int i;
+  int i = 0;
   qs.vsi_id = ad->vsi_id;
   qs.rx_queues = rx;
   qs.tx_queues = tx;
-  for (i = 0; i < ad->n_rx_queues; i++)
+
+  avf_log_debug (ad, "enable_queues: vsi_id %u rx_queues %u tx_queues %u",
+                ad->vsi_id, qs.rx_queues, qs.tx_queues);
+
+  while (rx)
     {
-      avf_rxq_t *rxq = vec_elt_at_index (ad->rxqs, i);
-      avf_reg_write (ad, AVF_QRX_TAIL (i), rxq->n_enqueued);
+      if (rx & (1 << i))
+       {
+         avf_rxq_t *rxq = vec_elt_at_index (ad->rxqs, i);
+         avf_reg_write (ad, AVF_QRX_TAIL (i), rxq->n_enqueued);
+         rx &= ~(1 << i);
+       }
+      i++;
     }
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_ENABLE_QUEUES, &qs,
                         sizeof (virtchnl_queue_select_t), 0, 0);
@@ -669,6 +762,9 @@ avf_op_get_stats (vlib_main_t * vm, avf_device_t * ad,
 {
   virtchnl_queue_select_t qs = { 0 };
   qs.vsi_id = ad->vsi_id;
+
+  avf_log_debug (ad, "get_stats: vsi_id %u", ad->vsi_id);
+
   return avf_send_to_pf (vm, ad, VIRTCHNL_OP_GET_STATS,
                         &qs, sizeof (virtchnl_queue_select_t),
                         es, sizeof (virtchnl_eth_stats_t));
@@ -682,6 +778,8 @@ avf_device_reset (vlib_main_t * vm, avf_device_t * ad)
   u32 rstat;
   int n_retry = 20;
 
+  avf_log_debug (ad, "reset");
+
   d.opcode = 0x801;
   d.v_opcode = VIRTCHNL_OP_RESET_VF;
   if ((error = avf_aq_desc_enq (vm, ad, &d, 0, 0)))
@@ -695,7 +793,10 @@ retry:
     return 0;
 
   if (--n_retry == 0)
-    return clib_error_return (0, "reset failed (timeout)");
+    {
+      avf_log_err (ad, "reset failed");
+      return clib_error_return (0, "reset failed (timeout)");
+    }
 
   goto retry;
 }
@@ -710,12 +811,14 @@ avf_request_queues (vlib_main_t * vm, avf_device_t * ad, u16 num_queue_pairs)
 
   res_req.num_queue_pairs = num_queue_pairs;
 
+  avf_log_debug (ad, "request_queues: num_queue_pairs %u", num_queue_pairs);
+
   error = avf_send_to_pf (vm, ad, VIRTCHNL_OP_REQUEST_QUEUES, &res_req,
                          sizeof (virtchnl_vf_res_request_t), &res_req,
                          sizeof (virtchnl_vf_res_request_t));
 
   /*
-   * if PF respondes, the request failed
+   * if PF responds, the request failed
    * else PF initializes restart and avf_send_to_pf returns an error
    */
   if (!error)
@@ -776,7 +879,7 @@ avf_device_init (vlib_main_t * vm, avf_main_t * am, avf_device_t * ad,
                              "(remote %d.%d)", ver.major, ver.minor);
 
   /*
-   * OP_GET_VF_RESOUCES
+   * OP_GET_VF_RESOURCES
    */
   if ((error = avf_op_get_vf_resources (vm, ad, &res)))
     return error;
@@ -813,9 +916,8 @@ avf_device_init (vlib_main_t * vm, avf_main_t * am, avf_device_t * ad,
   else if (args->rxq_num > ad->num_queue_pairs)
     {
       args->rxq_num = ad->num_queue_pairs;
-      vlib_log_warn (am->log_class, "Requested more rx queues than"
-                    "queue pairs available. Using %u rx queues.",
-                    args->rxq_num);
+      avf_log_warn (ad, "Requested more rx queues than queue pairs available."
+                   "Using %u rx queues.", args->rxq_num);
     }
 
   for (i = 0; i < args->rxq_num; i++)
@@ -847,10 +949,8 @@ avf_device_init (vlib_main_t * vm, avf_main_t * am, avf_device_t * ad,
   if ((error = avf_op_add_eth_addr (vm, ad, 1, ad->hwaddr)))
     return error;
 
-  if ((error = avf_op_enable_queues (vm, ad, ad->n_rx_queues, 0)))
-    return error;
-
-  if ((error = avf_op_enable_queues (vm, ad, 0, ad->n_tx_queues)))
+  if ((error = avf_op_enable_queues (vm, ad, pow2_mask (ad->n_rx_queues),
+                                    pow2_mask (ad->n_tx_queues))))
     return error;
 
   ad->flags |= AVF_DEVICE_F_INITIALIZED;
@@ -882,6 +982,7 @@ avf_process_one_device (vlib_main_t * vm, avf_device_t * ad, int is_irq)
   if ((r & 0xf0000000) != (1ULL << 31))
     {
       ad->error = clib_error_return (0, "arq not enabled, arqlen = 0x%x", r);
+      avf_log_err (ad, "error: %U", format_clib_error, ad->error);
       goto error;
     }
 
@@ -889,6 +990,7 @@ avf_process_one_device (vlib_main_t * vm, avf_device_t * ad, int is_irq)
   if ((r & 0xf0000000) != (1ULL << 31))
     {
       ad->error = clib_error_return (0, "atq not enabled, atqlen = 0x%x", r);
+      avf_log_err (ad, "error: %U", format_clib_error, ad->error);
       goto error;
     }
 
@@ -898,6 +1000,8 @@ avf_process_one_device (vlib_main_t * vm, avf_device_t * ad, int is_irq)
   /* *INDENT-OFF* */
   vec_foreach (e, ad->events)
     {
+      avf_log_debug (ad, "event: %s (%u) sev %d",
+                    virtchnl_event_names[e->event], e->event, e->severity);
       if (e->event == VIRTCHNL_EVENT_LINK_CHANGE)
        {
          int link_up = e->event_data.link_event.link_status;
@@ -905,6 +1009,11 @@ avf_process_one_device (vlib_main_t * vm, avf_device_t * ad, int is_irq)
          u32 flags = 0;
          u32 kbps = 0;
 
+         avf_log_debug (ad, "event_link_change: status %d speed '%s' (%d)",
+                        link_up,
+                        speed < ARRAY_LEN (virtchnl_link_speed_str) ?
+                        virtchnl_link_speed_str[speed] : "unknown", speed);
+
          if (link_up && (ad->flags & AVF_DEVICE_F_LINK_UP) == 0)
            {
              ad->flags |= AVF_DEVICE_F_LINK_UP;
@@ -1223,6 +1332,8 @@ avf_create_if (vlib_main_t * vm, avf_create_if_args_t * args)
       return;
     }
   ad->pci_dev_handle = h;
+  ad->pci_addr = args->addr;
+  ad->numa_node = vlib_pci_get_numa_node (vm, h);
 
   vlib_pci_set_private_data (vm, h, ad->dev_instance);
 
@@ -1243,8 +1354,11 @@ avf_create_if (vlib_main_t * vm, avf_create_if_args_t * args)
   if ((error = vlib_pci_enable_msix_irq (vm, h, 0, 2)))
     goto error;
 
-  if (!(ad->atq = vlib_physmem_alloc (vm, sizeof (avf_aq_desc_t) *
-                                     AVF_MBOX_LEN)))
+  ad->atq = vlib_physmem_alloc_aligned_on_numa (vm, sizeof (avf_aq_desc_t) *
+                                               AVF_MBOX_LEN,
+                                               CLIB_CACHE_LINE_BYTES,
+                                               ad->numa_node);
+  if (ad->atq == 0)
     {
       error = vlib_physmem_last_error (vm);
       goto error;
@@ -1253,8 +1367,11 @@ avf_create_if (vlib_main_t * vm, avf_create_if_args_t * args)
   if ((error = vlib_pci_map_dma (vm, h, ad->atq)))
     goto error;
 
-  if (!(ad->arq = vlib_physmem_alloc (vm, sizeof (avf_aq_desc_t) *
-                                     AVF_MBOX_LEN)))
+  ad->arq = vlib_physmem_alloc_aligned_on_numa (vm, sizeof (avf_aq_desc_t) *
+                                               AVF_MBOX_LEN,
+                                               CLIB_CACHE_LINE_BYTES,
+                                               ad->numa_node);
+  if (ad->arq == 0)
     {
       error = vlib_physmem_last_error (vm);
       goto error;
@@ -1263,8 +1380,11 @@ avf_create_if (vlib_main_t * vm, avf_create_if_args_t * args)
   if ((error = vlib_pci_map_dma (vm, h, ad->arq)))
     goto error;
 
-  if (!(ad->atq_bufs = vlib_physmem_alloc (vm, AVF_MBOX_BUF_SZ *
-                                          AVF_MBOX_LEN)))
+  ad->atq_bufs = vlib_physmem_alloc_aligned_on_numa (vm, AVF_MBOX_BUF_SZ *
+                                                    AVF_MBOX_LEN,
+                                                    CLIB_CACHE_LINE_BYTES,
+                                                    ad->numa_node);
+  if (ad->atq_bufs == 0)
     {
       error = vlib_physmem_last_error (vm);
       goto error;
@@ -1273,8 +1393,11 @@ avf_create_if (vlib_main_t * vm, avf_create_if_args_t * args)
   if ((error = vlib_pci_map_dma (vm, h, ad->atq_bufs)))
     goto error;
 
-  if (!(ad->arq_bufs = vlib_physmem_alloc (vm, AVF_MBOX_BUF_SZ *
-                                          AVF_MBOX_LEN)))
+  ad->arq_bufs = vlib_physmem_alloc_aligned_on_numa (vm, AVF_MBOX_BUF_SZ *
+                                                    AVF_MBOX_LEN,
+                                                    CLIB_CACHE_LINE_BYTES,
+                                                    ad->numa_node);
+  if (ad->arq_bufs == 0)
     {
       error = vlib_physmem_last_error (vm);
       goto error;
@@ -1322,7 +1445,7 @@ error:
   args->rv = VNET_API_ERROR_INVALID_INTERFACE;
   args->error = clib_error_return (error, "pci-addr %U",
                                   format_vlib_pci_addr, &args->addr);
-  vlib_log_err (am->log_class, "%U", format_clib_error, args->error);
+  avf_log_err (ad, "error: %U", format_clib_error, args->error);
 }
 
 static clib_error_t *
@@ -1410,22 +1533,23 @@ clib_error_t *
 avf_init (vlib_main_t * vm)
 {
   avf_main_t *am = &avf_main;
-  clib_error_t *error;
   vlib_thread_main_t *tm = vlib_get_thread_main ();
 
-  if ((error = vlib_call_init_function (vm, pci_bus_init)))
-    return error;
-
   vec_validate_aligned (am->per_thread_data, tm->n_vlib_mains - 1,
                        CLIB_CACHE_LINE_BYTES);
 
-  am->log_class = vlib_log_register_class ("avf_plugin", 0);
+  am->log_class = vlib_log_register_class ("avf", 0);
   vlib_log_debug (am->log_class, "initialized");
 
   return 0;
 }
 
-VLIB_INIT_FUNCTION (avf_init);
+/* *INDENT-OFF* */
+VLIB_INIT_FUNCTION (avf_init) =
+{
+  .runs_after = VLIB_INITS ("pci_bus_init"),
+};
+/* *INDENT-OFF* */
 
 /*
  * fd.io coding-style-patch-verification: ON