[dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Olivier Matz]

Today, all logs whose level is lower than INFO are dropped at
compile-time. This prevents from enabling debug logs at runtime using
--log-level=8.

The rationale was to remove debug logs from the data path at
compile-time, avoiding a test at run-time.

This patch changes the behavior of RTE_LOG() to avoid the compile-time
optimization, and introduces the RTE_LOG_DP() macro that has the same
behavior than the previous RTE_LOG(), for the rare cases where debug
logs are in the data path.

So it is now possible to enable debug logs at run-time by just
specifying --log-level=8. Some drivers still have special compile-time
options to enable more debug log. Maintainers may consider to
remove/reduce them.

Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
---
 config/common_base                      |  1 +
 doc/guides/faq/faq.rst                  |  2 +-
 drivers/net/bnxt/bnxt_txr.c             |  2 +-
 drivers/net/nfp/nfp_net.c               |  8 +++---
 examples/distributor/main.c             |  4 +--
 examples/ipsec-secgw/esp.c              |  2 +-
 examples/ipsec-secgw/ipsec.c            |  4 +--
 examples/packet_ordering/main.c         |  6 ++--
 examples/quota_watermark/qw/main.c      |  2 +-
 examples/tep_termination/main.c         |  4 +--
 examples/vhost/main.c                   | 14 +++++-----
 examples/vhost_xen/main.c               | 20 +++++++-------
 lib/librte_eal/common/include/rte_log.h | 49 +++++++++++++++++++++------------
 13 files changed, 67 insertions(+), 51 deletions(-)

diff --git a/config/common_base b/config/common_base
index 7830535..04b71e9 100644
--- a/config/common_base
+++ b/config/common_base
@@ -89,6 +89,7 @@ CONFIG_RTE_MAX_MEMSEG=256
 CONFIG_RTE_MAX_MEMZONE=2560
 CONFIG_RTE_MAX_TAILQ=32
 CONFIG_RTE_LOG_LEVEL=RTE_LOG_INFO
+CONFIG_RTE_LOG_DP_LEVEL=RTE_LOG_INFO
 CONFIG_RTE_LOG_HISTORY=256
 CONFIG_RTE_LIBEAL_USE_HPET=n
 CONFIG_RTE_EAL_ALLOW_INV_SOCKET_ID=n
diff --git a/doc/guides/faq/faq.rst b/doc/guides/faq/faq.rst
index 8d1ea6c..0adc549 100644
--- a/doc/guides/faq/faq.rst
+++ b/doc/guides/faq/faq.rst
@@ -101,7 +101,7 @@ Yes, the option ``--log-level=`` accepts one of these numbers:
     #define RTE_LOG_INFO 7U     /* Informational. */
     #define RTE_LOG_DEBUG 8U    /* Debug-level messages. */
 
-It is also possible to change the maximum (and default level) at compile time
+It is also possible to change the default level at compile time
 with ``CONFIG_RTE_LOG_LEVEL``.
 
 
diff --git a/drivers/net/bnxt/bnxt_txr.c b/drivers/net/bnxt/bnxt_txr.c
index 8bf8fee..0d15bb1 100644
--- a/drivers/net/bnxt/bnxt_txr.c
+++ b/drivers/net/bnxt/bnxt_txr.c
@@ -298,7 +298,7 @@ static int bnxt_handle_tx_cp(struct bnxt_tx_queue *txq)
 			if (CMP_TYPE(txcmp) == TX_CMPL_TYPE_TX_L2)
 				nb_tx_pkts++;
 			else
-				RTE_LOG(DEBUG, PMD,
+				RTE_LOG_DP(DEBUG, PMD,
 						"Unhandled CMP type %02x\n",
 						CMP_TYPE(txcmp));
 			raw_cons = NEXT_RAW_CMP(raw_cons);
diff --git a/drivers/net/nfp/nfp_net.c b/drivers/net/nfp/nfp_net.c
index 0d60baa..11f544c 100644
--- a/drivers/net/nfp/nfp_net.c
+++ b/drivers/net/nfp/nfp_net.c
@@ -1701,7 +1701,7 @@ nfp_net_recv_pkts(void *rx_queue, struct rte_mbuf **rx_pkts, uint16_t nb_pkts)
 		 * DPDK just checks the queue is lower than max queues
 		 * enabled. But the queue needs to be configured
 		 */
-		RTE_LOG(ERR, PMD, "RX Bad queue\n");
+		RTE_LOG_DP(ERR, PMD, "RX Bad queue\n");
 		return -EINVAL;
 	}
 
@@ -1714,7 +1714,7 @@ nfp_net_recv_pkts(void *rx_queue, struct rte_mbuf **rx_pkts, uint16_t nb_pkts)
 
 		rxb = &rxq->rxbufs[idx];
 		if (unlikely(rxb == NULL)) {
-			RTE_LOG(ERR, PMD, "rxb does not exist!\n");
+			RTE_LOG_DP(ERR, PMD, "rxb does not exist!\n");
 			break;
 		}
 
@@ -1734,7 +1734,7 @@ nfp_net_recv_pkts(void *rx_queue, struct rte_mbuf **rx_pkts, uint16_t nb_pkts)
 		 */
 		new_mb = rte_pktmbuf_alloc(rxq->mem_pool);
 		if (unlikely(new_mb == NULL)) {
-			RTE_LOG(DEBUG, PMD, "RX mbuf alloc failed port_id=%u "
+			RTE_LOG_DP(DEBUG, PMD, "RX mbuf alloc failed port_id=%u "
 				"queue_id=%u\n", (unsigned)rxq->port_id,
 				(unsigned)rxq->qidx);
 			nfp_net_mbuf_alloc_failed(rxq);
@@ -1765,7 +1765,7 @@ nfp_net_recv_pkts(void *rx_queue, struct rte_mbuf **rx_pkts, uint16_t nb_pkts)
 			 * responsibility of avoiding it. But we have
 			 * to give some info about the error
 			 */
-			RTE_LOG(ERR, PMD,
+			RTE_LOG_DP(ERR, PMD,
 				"mbuf overflow likely due to the RX offset.\n"
 				"\t\tYour mbuf size should have extra space for"
 				" RX offset=%u bytes.\n"
diff --git a/examples/distributor/main.c b/examples/distributor/main.c
index 537cee1..e7641d2 100644
--- a/examples/distributor/main.c
+++ b/examples/distributor/main.c
@@ -241,7 +241,7 @@ lcore_rx(struct lcore_params *p)
 		uint16_t sent = rte_ring_enqueue_burst(r, (void *)bufs, nb_ret);
 		app_stats.rx.enqueued_pkts += sent;
 		if (unlikely(sent < nb_ret)) {
-			RTE_LOG(DEBUG, DISTRAPP,
+			RTE_LOG_DP(DEBUG, DISTRAPP,
 				"%s:Packet loss due to full ring\n", __func__);
 			while (sent < nb_ret)
 				rte_pktmbuf_free(bufs[sent++]);
@@ -274,7 +274,7 @@ flush_one_port(struct output_buffer *outbuf, uint8_t outp)
 	app_stats.tx.tx_pkts += nb_tx;
 
 	if (unlikely(nb_tx < outbuf->count)) {
-		RTE_LOG(DEBUG, DISTRAPP,
+		RTE_LOG_DP(DEBUG, DISTRAPP,
 			"%s:Packet loss with tx_burst\n", __func__);
 		do {
 			rte_pktmbuf_free(outbuf->mbufs[nb_tx]);
diff --git a/examples/ipsec-secgw/esp.c b/examples/ipsec-secgw/esp.c
index 05caa77..987eb3f 100644
--- a/examples/ipsec-secgw/esp.c
+++ b/examples/ipsec-secgw/esp.c
@@ -93,7 +93,7 @@ esp_inbound(struct rte_mbuf *m, struct ipsec_sa *sa,
 		sizeof(struct esp_hdr) - sa->iv_len - sa->digest_len;
 
 	if ((payload_len & (sa->block_size - 1)) || (payload_len <= 0)) {
-		RTE_LOG(DEBUG, IPSEC_ESP, "payload %d not multiple of %u\n",
+		RTE_LOG_DP(DEBUG, IPSEC_ESP, "payload %d not multiple of %u\n",
 				payload_len, sa->block_size);
 		return -EINVAL;
 	}
diff --git a/examples/ipsec-secgw/ipsec.c b/examples/ipsec-secgw/ipsec.c
index 1e87d0d..4d9eff1 100644
--- a/examples/ipsec-secgw/ipsec.c
+++ b/examples/ipsec-secgw/ipsec.c
@@ -65,7 +65,7 @@ create_session(struct ipsec_ctx *ipsec_ctx __rte_unused, struct ipsec_sa *sa)
 		return -1;
 	}
 
-	RTE_LOG(DEBUG, IPSEC, "Create session for SA spi %u on cryptodev "
+	RTE_LOG_DP(DEBUG, IPSEC, "Create session for SA spi %u on cryptodev "
 			"%u qp %u\n", sa->spi,
 			ipsec_ctx->tbl[cdev_id_qp].id,
 			ipsec_ctx->tbl[cdev_id_qp].qp);
@@ -89,7 +89,7 @@ enqueue_cop(struct cdev_qp *cqp, struct rte_crypto_op *cop)
 		ret = rte_cryptodev_enqueue_burst(cqp->id, cqp->qp,
 				cqp->buf, cqp->len);
 		if (ret < cqp->len) {
-			RTE_LOG(DEBUG, IPSEC, "Cryptodev %u queue %u:"
+			RTE_LOG_DP(DEBUG, IPSEC, "Cryptodev %u queue %u:"
 					" enqueued %u crypto ops out of %u\n",
 					 cqp->id, cqp->qp,
 					 ret, cqp->len);
diff --git a/examples/packet_ordering/main.c b/examples/packet_ordering/main.c
index 3c88b86..d4dc789 100644
--- a/examples/packet_ordering/main.c
+++ b/examples/packet_ordering/main.c
@@ -229,7 +229,7 @@ flush_tx_error_callback(struct rte_mbuf **unsent, uint16_t count,
 
 	/* free the mbufs which failed from transmit */
 	app_stats.tx.ro_tx_failed_pkts += count;
-	RTE_LOG(DEBUG, REORDERAPP, "%s:Packet loss with tx_burst\n", __func__);
+	RTE_LOG_DP(DEBUG, REORDERAPP, "%s:Packet loss with tx_burst\n", __func__);
 	pktmbuf_free_bulk(unsent, count);
 
 }
@@ -410,7 +410,7 @@ rx_thread(struct rte_ring *ring_out)
 				nb_rx_pkts = rte_eth_rx_burst(port_id, 0,
 								pkts, MAX_PKTS_BURST);
 				if (nb_rx_pkts == 0) {
-					RTE_LOG(DEBUG, REORDERAPP,
+					RTE_LOG_DP(DEBUG, REORDERAPP,
 					"%s():Received zero packets\n",	__func__);
 					continue;
 				}
@@ -522,7 +522,7 @@ send_thread(struct send_thread_args *args)
 
 			if (ret == -1 && rte_errno == ERANGE) {
 				/* Too early pkts should be transmitted out directly */
-				RTE_LOG(DEBUG, REORDERAPP,
+				RTE_LOG_DP(DEBUG, REORDERAPP,
 						"%s():Cannot reorder early packet "
 						"direct enqueuing to TX\n", __func__);
 				outp = mbufs[i]->port;
diff --git a/examples/quota_watermark/qw/main.c b/examples/quota_watermark/qw/main.c
index 8ed0214..9162e28 100644
--- a/examples/quota_watermark/qw/main.c
+++ b/examples/quota_watermark/qw/main.c
@@ -81,7 +81,7 @@ static void send_pause_frame(uint8_t port_id, uint16_t duration)
     struct ether_hdr *hdr;
     struct ether_addr mac_addr;
 
-    RTE_LOG(DEBUG, USER1, "Sending PAUSE frame (duration=%d) on port %d\n",
+    RTE_LOG_DP(DEBUG, USER1, "Sending PAUSE frame (duration=%d) on port %d\n",
             duration, port_id);
 
     /* Get a mbuf from the pool */
diff --git a/examples/tep_termination/main.c b/examples/tep_termination/main.c
index 622f248..57c7541 100644
--- a/examples/tep_termination/main.c
+++ b/examples/tep_termination/main.c
@@ -567,7 +567,7 @@ virtio_tx_route(struct vhost_dev *vdev, struct rte_mbuf *m)
 	unsigned len, ret = 0;
 	const uint16_t lcore_id = rte_lcore_id();
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%d) TX: MAC address is external\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%d) TX: MAC address is external\n",
 		vdev->vid);
 
 	/* Add packet to the port tx queue */
@@ -649,7 +649,7 @@ switch_worker(__rte_unused void *arg)
 		if (unlikely(diff_tsc > drain_tsc)) {
 
 			if (tx_q->len) {
-				RTE_LOG(DEBUG, VHOST_DATA, "TX queue drained after "
+				RTE_LOG_DP(DEBUG, VHOST_DATA, "TX queue drained after "
 					"timeout with burst size %u\n",
 					tx_q->len);
 				ret = overlay_options.tx_handle(ports[0],
diff --git a/examples/vhost/main.c b/examples/vhost/main.c
index 92a9823..0f678f2 100644
--- a/examples/vhost/main.c
+++ b/examples/vhost/main.c
@@ -839,17 +839,17 @@ virtio_tx_local(struct vhost_dev *vdev, struct rte_mbuf *m)
 		return -1;
 
 	if (vdev->vid == dst_vdev->vid) {
-		RTE_LOG(DEBUG, VHOST_DATA,
+		RTE_LOG_DP(DEBUG, VHOST_DATA,
 			"(%d) TX: src and dst MAC is same. Dropping packet.\n",
 			vdev->vid);
 		return 0;
 	}
 
-	RTE_LOG(DEBUG, VHOST_DATA,
+	RTE_LOG_DP(DEBUG, VHOST_DATA,
 		"(%d) TX: MAC address is local\n", dst_vdev->vid);
 
 	if (unlikely(dst_vdev->remove)) {
-		RTE_LOG(DEBUG, VHOST_DATA,
+		RTE_LOG_DP(DEBUG, VHOST_DATA,
 			"(%d) device is marked for removal\n", dst_vdev->vid);
 		return 0;
 	}
@@ -874,7 +874,7 @@ find_local_dest(struct vhost_dev *vdev, struct rte_mbuf *m,
 		return 0;
 
 	if (vdev->vid == dst_vdev->vid) {
-		RTE_LOG(DEBUG, VHOST_DATA,
+		RTE_LOG_DP(DEBUG, VHOST_DATA,
 			"(%d) TX: src and dst MAC is same. Dropping packet.\n",
 			vdev->vid);
 		return -1;
@@ -888,7 +888,7 @@ find_local_dest(struct vhost_dev *vdev, struct rte_mbuf *m,
 	*offset  = VLAN_HLEN;
 	*vlan_tag = vlan_tags[vdev->vid];
 
-	RTE_LOG(DEBUG, VHOST_DATA,
+	RTE_LOG_DP(DEBUG, VHOST_DATA,
 		"(%d) TX: pkt to local VM device id: (%d), vlan tag: %u.\n",
 		vdev->vid, dst_vdev->vid, *vlan_tag);
 
@@ -980,7 +980,7 @@ virtio_tx_route(struct vhost_dev *vdev, struct rte_mbuf *m, uint16_t vlan_tag)
 		}
 	}
 
-	RTE_LOG(DEBUG, VHOST_DATA,
+	RTE_LOG_DP(DEBUG, VHOST_DATA,
 		"(%d) TX: MAC address is external\n", vdev->vid);
 
 queue2nic:
@@ -1048,7 +1048,7 @@ drain_mbuf_table(struct mbuf_table *tx_q)
 	if (unlikely(cur_tsc - prev_tsc > MBUF_TABLE_DRAIN_TSC)) {
 		prev_tsc = cur_tsc;
 
-		RTE_LOG(DEBUG, VHOST_DATA,
+		RTE_LOG_DP(DEBUG, VHOST_DATA,
 			"TX queue drained after timeout with burst size %u\n",
 			tx_q->len);
 		do_drain_mbuf_table(tx_q);
diff --git a/examples/vhost_xen/main.c b/examples/vhost_xen/main.c
index 2e40357..c532d32 100644
--- a/examples/vhost_xen/main.c
+++ b/examples/vhost_xen/main.c
@@ -525,7 +525,7 @@ gpa_to_vva(struct virtio_net *dev, uint64_t guest_pa)
 			break;
 		}
 	}
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") GPA %p| VVA %p\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") GPA %p| VVA %p\n",
 		dev->device_fh, (void*)(uintptr_t)guest_pa, (void*)(uintptr_t)vhost_va);
 
 	return vhost_va;
@@ -555,7 +555,7 @@ virtio_dev_rx(struct virtio_net *dev, struct rte_mbuf **pkts, uint32_t count)
 	uint8_t success = 0;
 	void *userdata;
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") virtio_dev_rx()\n", dev->device_fh);
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") virtio_dev_rx()\n", dev->device_fh);
 	vq = dev->virtqueue_rx;
 	count = (count > MAX_PKT_BURST) ? MAX_PKT_BURST : count;
 	/* As many data cores may want access to available buffers, they need to be reserved. */
@@ -580,7 +580,7 @@ virtio_dev_rx(struct virtio_net *dev, struct rte_mbuf **pkts, uint32_t count)
 									res_end_idx);
 	} while (unlikely(success == 0));
 	res_cur_idx = res_base_idx;
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") Current Index %d| End Index %d\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") Current Index %d| End Index %d\n",
 		dev->device_fh, res_cur_idx, res_end_idx);
 
 	/* Prefetch available ring to retrieve indexes. */
@@ -775,7 +775,7 @@ virtio_tx_local(struct virtio_net *dev, struct rte_mbuf *m)
 
 			/* Drop the packet if the TX packet is destined for the TX device. */
 			if (dev_ll->dev->device_fh == dev->device_fh) {
-				RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
+				RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
 					"Source and destination MAC addresses are the same. "
 					"Dropping packet.\n",
 					dev_ll->dev->device_fh);
@@ -783,12 +783,12 @@ virtio_tx_local(struct virtio_net *dev, struct rte_mbuf *m)
 			}
 
 
-			RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
+			RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
 				"MAC address is local\n", dev_ll->dev->device_fh);
 
 			if (dev_ll->dev->remove) {
 				/*drop the packet if the device is marked for removal*/
-				RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") "
+				RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") "
 					"Device is marked for removal\n",
 					dev_ll->dev->device_fh);
 			} else {
@@ -829,7 +829,7 @@ virtio_tx_route(struct virtio_net* dev, struct rte_mbuf *m, struct rte_mempool *
 		return;
 	}
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
 		"MAC address is external\n", dev->device_fh);
 
 	/*Add packet to the port tx queue*/
@@ -903,7 +903,7 @@ virtio_dev_tx(struct virtio_net* dev, struct rte_mempool *mbuf_pool)
 	if (vq->last_used_idx == avail_idx)
 		return;
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") virtio_dev_tx()\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") virtio_dev_tx()\n",
 		dev->device_fh);
 
 	/* Prefetch available ring to retrieve head indexes. */
@@ -913,7 +913,7 @@ virtio_dev_tx(struct virtio_net* dev, struct rte_mempool *mbuf_pool)
 	free_entries = avail_idx - vq->last_used_idx;
 	free_entries = unlikely(free_entries < MAX_PKT_BURST) ? free_entries : MAX_PKT_BURST;
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") Buffers available %d\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") Buffers available %d\n",
 		dev->device_fh, free_entries);
 	/* Retrieve all of the head indexes first to avoid caching issues. */
 	for (i = 0; i < free_entries; i++)
@@ -1003,7 +1003,7 @@ switch_worker(__attribute__((unused)) void *arg)
 		if (unlikely(diff_tsc > drain_tsc)) {
 
 			if (tx_q->len) {
-				RTE_LOG(DEBUG, VHOST_DATA,
+				RTE_LOG_DP(DEBUG, VHOST_DATA,
 					"TX queue drained after timeout with burst size %u\n",
 					tx_q->len);
 
diff --git a/lib/librte_eal/common/include/rte_log.h b/lib/librte_eal/common/include/rte_log.h
index 919563c..76b198f 100644
--- a/lib/librte_eal/common/include/rte_log.h
+++ b/lib/librte_eal/common/include/rte_log.h
@@ -121,9 +121,8 @@ int rte_openlog_stream(FILE *f);
 /**
  * Set the global log level.
  *
- * After this call, all logs that are lower or equal than level and
- * lower or equal than the RTE_LOG_LEVEL configuration option will be
- * displayed.
+ * After this call, logs with a level lower or equal than the level
+ * passed as argument will be displayed.
  *
  * @param level
  *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
@@ -187,9 +186,8 @@ int rte_log_cur_msg_logtype(void);
  * The level argument determines if the log should be displayed or
  * not, depending on the global rte_logs variable.
  *
- * The preferred alternative is the RTE_LOG() function because debug logs may
- * be removed at compilation time if optimization is enabled. Moreover,
- * logs are automatically prefixed by type when using the macro.
+ * The preferred alternative is the RTE_LOG() because it adds the
+ * level and type in the logged string.
  *
  * @param level
  *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
@@ -220,8 +218,8 @@ int rte_log(uint32_t level, uint32_t logtype, const char *format, ...)
  * not, depending on the global rte_logs variable. A trailing
  * newline may be added if needed.
  *
- * The preferred alternative is the RTE_LOG() because debug logs may be
- * removed at compilation time.
+ * The preferred alternative is the RTE_LOG() because it adds the
+ * level and type in the logged string.
  *
  * @param level
  *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
@@ -242,15 +240,8 @@ int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
 /**
  * Generates a log message.
  *
- * The RTE_LOG() is equivalent to rte_log() with two differences:
-
- * - RTE_LOG() can be used to remove debug logs at compilation time,
- *   depending on RTE_LOG_LEVEL configuration option, and compilation
- *   optimization level. If optimization is enabled, the tests
- *   involving constants only are pre-computed. If compilation is done
- *   with -O0, these tests will be done at run time.
- * - The log level and log type names are smaller, for example:
- *   RTE_LOG(INFO, EAL, "this is a %s", "log");
+ * The RTE_LOG() is a helper that prefixes the string with the log level
+ * and type, and call rte_log().
  *
  * @param l
  *   Log level. A value between EMERG (1) and DEBUG (8). The short name is
@@ -266,6 +257,30 @@ int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
  *   - Negative on error.
  */
 #define RTE_LOG(l, t, ...)					\
+	 rte_log(RTE_LOG_ ## l,					\
+		 RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__)
+
+/**
+ * Generates a log message for data path.
+ *
+ * Similar to RTE_LOG(), except that it is removed at compilation time
+ * if the RTE_LOG_DP_LEVEL configuration option is lower than the log
+ * level argument.
+ *
+ * @param l
+ *   Log level. A value between EMERG (1) and DEBUG (8). The short name is
+ *   expanded by the macro, so it cannot be an integer value.
+ * @param t
+ *   The log type, for example, EAL. The short name is expanded by the
+ *   macro, so it cannot be an integer value.
+ * @param ...
+ *   The fmt string, as in printf(3), followed by the variable arguments
+ *   required by the format.
+ * @return
+ *   - 0: Success.
+ *   - Negative on error.
+ */
+#define RTE_LOG_DP(l, t, ...)					\
 	(void)((RTE_LOG_ ## l <= RTE_LOG_LEVEL) ?		\
 	 rte_log(RTE_LOG_ ## l,					\
 		 RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__) :	\
-- 
2.8.1

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Thomas Monjalon]

2016-09-16 09:43, Olivier Matz:
> Today, all logs whose level is lower than INFO are dropped at
> compile-time. This prevents from enabling debug logs at runtime using
> --log-level=8.
> 
> The rationale was to remove debug logs from the data path at
> compile-time, avoiding a test at run-time.
> 
> This patch changes the behavior of RTE_LOG() to avoid the compile-time
> optimization, and introduces the RTE_LOG_DP() macro that has the same
> behavior than the previous RTE_LOG(), for the rare cases where debug
> logs are in the data path.
> 
> So it is now possible to enable debug logs at run-time by just
> specifying --log-level=8. Some drivers still have special compile-time
> options to enable more debug log. Maintainers may consider to
> remove/reduce them.
> 
> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>

I think it is a good change.
However I'm not sure we should take it for 16.11 as it was sent late and
there is no review comment.
It is neither really a fix nor really a feature.
If there are some +1, and no opinions against, it will go in 16.11.
Note that some drivers would need some changes to fully benefit of
debug logs enabled at run-time.

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Wiles, Keith]

Regards,
Keith

> On Sep 30, 2016, at 4:33 AM, Thomas Monjalon <thomas.monjalon@6wind.com> wrote:
> 
> 2016-09-16 09:43, Olivier Matz:
>> Today, all logs whose level is lower than INFO are dropped at
>> compile-time. This prevents from enabling debug logs at runtime using
>> --log-level=8.
>> 
>> The rationale was to remove debug logs from the data path at
>> compile-time, avoiding a test at run-time.
>> 
>> This patch changes the behavior of RTE_LOG() to avoid the compile-time
>> optimization, and introduces the RTE_LOG_DP() macro that has the same
>> behavior than the previous RTE_LOG(), for the rare cases where debug
>> logs are in the data path.
>> 
>> So it is now possible to enable debug logs at run-time by just
>> specifying --log-level=8. Some drivers still have special compile-time
>> options to enable more debug log. Maintainers may consider to
>> remove/reduce them.
>> 
>> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
> 
> I think it is a good change.
> However I'm not sure we should take it for 16.11 as it was sent late and
> there is no review comment.
> It is neither really a fix nor really a feature.
> If there are some +1, and no opinions against, it will go in 16.11.
> Note that some drivers would need some changes to fully benefit of
> debug logs enabled at run-time.

Would this be easier to add a new LOG level instead say DEBUG_DATAPATH and then change the RTE_LOG to exclude the new log level?

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Olivier Matz]

Hi Keith,

On 09/30/2016 05:48 PM, Wiles, Keith wrote:
>> On Sep 30, 2016, at 4:33 AM, Thomas Monjalon <thomas.monjalon@6wind.com> wrote:
>>
>> 2016-09-16 09:43, Olivier Matz:
>>> Today, all logs whose level is lower than INFO are dropped at
>>> compile-time. This prevents from enabling debug logs at runtime using
>>> --log-level=8.
>>>
>>> The rationale was to remove debug logs from the data path at
>>> compile-time, avoiding a test at run-time.
>>>
>>> This patch changes the behavior of RTE_LOG() to avoid the compile-time
>>> optimization, and introduces the RTE_LOG_DP() macro that has the same
>>> behavior than the previous RTE_LOG(), for the rare cases where debug
>>> logs are in the data path.
>>>
>>> So it is now possible to enable debug logs at run-time by just
>>> specifying --log-level=8. Some drivers still have special compile-time
>>> options to enable more debug log. Maintainers may consider to
>>> remove/reduce them.
>>>
>>> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
>>
>> I think it is a good change.
>> However I'm not sure we should take it for 16.11 as it was sent late and
>> there is no review comment.
>> It is neither really a fix nor really a feature.
>> If there are some +1, and no opinions against, it will go in 16.11.
>> Note that some drivers would need some changes to fully benefit of
>> debug logs enabled at run-time.
> 
> Would this be easier to add a new LOG level instead say DEBUG_DATAPATH and then change the RTE_LOG to exclude the new log level?
> 
> 

The log levels are quite standard, I don't feel it would be very clear
to have a new level for that. It would also prevent to have different
log level inside data path.

Regards,
Olivier

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Wiles, Keith]

Regards,
Keith

> On Oct 3, 2016, at 10:02 AM, Olivier Matz <olivier.matz@6wind.com> wrote:
> 
> Hi Keith,
> 
> On 09/30/2016 05:48 PM, Wiles, Keith wrote:
>>> On Sep 30, 2016, at 4:33 AM, Thomas Monjalon <thomas.monjalon@6wind.com> wrote:
>>> 
>>> 2016-09-16 09:43, Olivier Matz:
>>>> Today, all logs whose level is lower than INFO are dropped at
>>>> compile-time. This prevents from enabling debug logs at runtime using
>>>> --log-level=8.
>>>> 
>>>> The rationale was to remove debug logs from the data path at
>>>> compile-time, avoiding a test at run-time.
>>>> 
>>>> This patch changes the behavior of RTE_LOG() to avoid the compile-time
>>>> optimization, and introduces the RTE_LOG_DP() macro that has the same
>>>> behavior than the previous RTE_LOG(), for the rare cases where debug
>>>> logs are in the data path.
>>>> 
>>>> So it is now possible to enable debug logs at run-time by just
>>>> specifying --log-level=8. Some drivers still have special compile-time
>>>> options to enable more debug log. Maintainers may consider to
>>>> remove/reduce them.
>>>> 
>>>> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
>>> 
>>> I think it is a good change.
>>> However I'm not sure we should take it for 16.11 as it was sent late and
>>> there is no review comment.
>>> It is neither really a fix nor really a feature.
>>> If there are some +1, and no opinions against, it will go in 16.11.
>>> Note that some drivers would need some changes to fully benefit of
>>> debug logs enabled at run-time.
>> 
>> Would this be easier to add a new LOG level instead say DEBUG_DATAPATH and then change the RTE_LOG to exclude the new log level?
>> 
>> 
> 
> The log levels are quite standard, I don't feel it would be very clear
> to have a new level for that. It would also prevent to have different
> log level inside data path.

I am not following you here. Having one more log level for DEBUG in the data path is not a big change and you can still have any other log level in the data or anyplace else for that matter.

> 
> Regards,
> Olivier

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Olivier Matz]

On 10/03/2016 05:27 PM, Wiles, Keith wrote:
> 
> Regards,
> Keith
> 
>> On Oct 3, 2016, at 10:02 AM, Olivier Matz <olivier.matz@6wind.com> wrote:
>>
>> Hi Keith,
>>
>> On 09/30/2016 05:48 PM, Wiles, Keith wrote:
>>>> On Sep 30, 2016, at 4:33 AM, Thomas Monjalon <thomas.monjalon@6wind.com> wrote:
>>>>
>>>> 2016-09-16 09:43, Olivier Matz:
>>>>> Today, all logs whose level is lower than INFO are dropped at
>>>>> compile-time. This prevents from enabling debug logs at runtime using
>>>>> --log-level=8.
>>>>>
>>>>> The rationale was to remove debug logs from the data path at
>>>>> compile-time, avoiding a test at run-time.
>>>>>
>>>>> This patch changes the behavior of RTE_LOG() to avoid the compile-time
>>>>> optimization, and introduces the RTE_LOG_DP() macro that has the same
>>>>> behavior than the previous RTE_LOG(), for the rare cases where debug
>>>>> logs are in the data path.
>>>>>
>>>>> So it is now possible to enable debug logs at run-time by just
>>>>> specifying --log-level=8. Some drivers still have special compile-time
>>>>> options to enable more debug log. Maintainers may consider to
>>>>> remove/reduce them.
>>>>>
>>>>> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
>>>>
>>>> I think it is a good change.
>>>> However I'm not sure we should take it for 16.11 as it was sent late and
>>>> there is no review comment.
>>>> It is neither really a fix nor really a feature.
>>>> If there are some +1, and no opinions against, it will go in 16.11.
>>>> Note that some drivers would need some changes to fully benefit of
>>>> debug logs enabled at run-time.
>>>
>>> Would this be easier to add a new LOG level instead say DEBUG_DATAPATH and then change the RTE_LOG to exclude the new log level?
>>>
>>>
>>
>> The log levels are quite standard, I don't feel it would be very clear
>> to have a new level for that. It would also prevent to have different
>> log level inside data path.
> 
> I am not following you here. Having one more log level for DEBUG in the data path is not a big change and you can still have any other log level in the data or anyplace else for that matter.

Adding a new log level is not a big change, you are right.
But to me it looks confusing to have DEBUG, INFO, ..., WARNING, ERROR,
plus a DEBUG_DATAPATH. For instance, how do you compare levels? Or if
your log stream forwards logs to syslog, you cannot do a 1:1 mapping
with standard syslog levels.

What makes you feel it's easier to add a log level instead of adding a
new RTE_LOG_DP() function?


Regards,
Olivier

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Wiles, Keith]

Regards,
Keith

> On Oct 3, 2016, at 10:37 AM, Olivier Matz <olivier.matz@6wind.com> wrote:
> 
> 
> 
> On 10/03/2016 05:27 PM, Wiles, Keith wrote:
>> 
>> Regards,
>> Keith
>> 
>>> On Oct 3, 2016, at 10:02 AM, Olivier Matz <olivier.matz@6wind.com> wrote:
>>> 
>>> Hi Keith,
>>> 
>>> On 09/30/2016 05:48 PM, Wiles, Keith wrote:
>>>>> On Sep 30, 2016, at 4:33 AM, Thomas Monjalon <thomas.monjalon@6wind.com> wrote:
>>>>> 
>>>>> 2016-09-16 09:43, Olivier Matz:
>>>>>> Today, all logs whose level is lower than INFO are dropped at
>>>>>> compile-time. This prevents from enabling debug logs at runtime using
>>>>>> --log-level=8.
>>>>>> 
>>>>>> The rationale was to remove debug logs from the data path at
>>>>>> compile-time, avoiding a test at run-time.
>>>>>> 
>>>>>> This patch changes the behavior of RTE_LOG() to avoid the compile-time
>>>>>> optimization, and introduces the RTE_LOG_DP() macro that has the same
>>>>>> behavior than the previous RTE_LOG(), for the rare cases where debug
>>>>>> logs are in the data path.
>>>>>> 
>>>>>> So it is now possible to enable debug logs at run-time by just
>>>>>> specifying --log-level=8. Some drivers still have special compile-time
>>>>>> options to enable more debug log. Maintainers may consider to
>>>>>> remove/reduce them.
>>>>>> 
>>>>>> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
>>>>> 
>>>>> I think it is a good change.
>>>>> However I'm not sure we should take it for 16.11 as it was sent late and
>>>>> there is no review comment.
>>>>> It is neither really a fix nor really a feature.
>>>>> If there are some +1, and no opinions against, it will go in 16.11.
>>>>> Note that some drivers would need some changes to fully benefit of
>>>>> debug logs enabled at run-time.
>>>> 
>>>> Would this be easier to add a new LOG level instead say DEBUG_DATAPATH and then change the RTE_LOG to exclude the new log level?
>>>> 
>>>> 
>>> 
>>> The log levels are quite standard, I don't feel it would be very clear
>>> to have a new level for that. It would also prevent to have different
>>> log level inside data path.
>> 
>> I am not following you here. Having one more log level for DEBUG in the data path is not a big change and you can still have any other log level in the data or anyplace else for that matter.
> 
> Adding a new log level is not a big change, you are right.
> But to me it looks confusing to have DEBUG, INFO, ..., WARNING, ERROR,
> plus a DEBUG_DATAPATH. For instance, how do you compare levels? Or if
> your log stream forwards logs to syslog, you cannot do a 1:1 mapping
> with standard syslog levels.

Doing 1:1 mapping is not a big problem unless you are trying to compare to old logs, which maybe the case the first time and after that it should not be a problem.

> 
> What makes you feel it's easier to add a log level instead of adding a
> new RTE_LOG_DP() function?

It seems to me the log levels are for displaying logs at different levels adding a new macro to not log is just a hack because we do not have a log level for data path. This is why I would like to see a log level added and not a new macro.

It also appears the new RTE_LOG() will always be in the code as you moved the test to the RTE_LOG_DP() macro. This would mean all RTE_LOG() in the code will always call rte_log(), correct?

If using a new DEBUG_DP (maybe DATAPATH is a better log level name) level we can use the same macro as before and modify the level only. This way we can remove via the compiler any log that is below the default RTE_LOG_LEVEL. I see keeping the rte_log() could be a performance problem or code blot when you really want to remove them all.

The DATAPATH log level would be above (smaller number) then DEBUG in the enum list. To remove all debug logs just set the RTE_LOG_LEVEL to RTE_LOG_DATAPATH.


> 
> 
> Regards,
> Olivier

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[David Marchand]

On Fri, Sep 16, 2016 at 9:43 AM, Olivier Matz <olivier.matz@6wind.com> wrote:
> Today, all logs whose level is lower than INFO are dropped at
> compile-time. This prevents from enabling debug logs at runtime using
> --log-level=8.
>
> The rationale was to remove debug logs from the data path at
> compile-time, avoiding a test at run-time.
>
> This patch changes the behavior of RTE_LOG() to avoid the compile-time
> optimization, and introduces the RTE_LOG_DP() macro that has the same
> behavior than the previous RTE_LOG(), for the rare cases where debug
> logs are in the data path.
>
> So it is now possible to enable debug logs at run-time by just
> specifying --log-level=8. Some drivers still have special compile-time
> options to enable more debug log. Maintainers may consider to
> remove/reduce them.
>
> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
> ---
>  config/common_base                      |  1 +
>  doc/guides/faq/faq.rst                  |  2 +-
>  drivers/net/bnxt/bnxt_txr.c             |  2 +-
>  drivers/net/nfp/nfp_net.c               |  8 +++---
>  examples/distributor/main.c             |  4 +--
>  examples/ipsec-secgw/esp.c              |  2 +-
>  examples/ipsec-secgw/ipsec.c            |  4 +--
>  examples/packet_ordering/main.c         |  6 ++--
>  examples/quota_watermark/qw/main.c      |  2 +-
>  examples/tep_termination/main.c         |  4 +--
>  examples/vhost/main.c                   | 14 +++++-----
>  examples/vhost_xen/main.c               | 20 +++++++-------
>  lib/librte_eal/common/include/rte_log.h | 49 +++++++++++++++++++++------------
>  13 files changed, 67 insertions(+), 51 deletions(-)
>
> diff --git a/config/common_base b/config/common_base
> index 7830535..04b71e9 100644
> --- a/config/common_base
> +++ b/config/common_base
> @@ -89,6 +89,7 @@ CONFIG_RTE_MAX_MEMSEG=256
>  CONFIG_RTE_MAX_MEMZONE=2560
>  CONFIG_RTE_MAX_TAILQ=32
>  CONFIG_RTE_LOG_LEVEL=RTE_LOG_INFO
> +CONFIG_RTE_LOG_DP_LEVEL=RTE_LOG_INFO
>  CONFIG_RTE_LOG_HISTORY=256
>  CONFIG_RTE_LIBEAL_USE_HPET=n
>  CONFIG_RTE_EAL_ALLOW_INV_SOCKET_ID=n

[snip]

> diff --git a/lib/librte_eal/common/include/rte_log.h b/lib/librte_eal/common/include/rte_log.h
> index 919563c..76b198f 100644
> --- a/lib/librte_eal/common/include/rte_log.h
> +++ b/lib/librte_eal/common/include/rte_log.h

[snip]

> @@ -266,6 +257,30 @@ int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
>   *   - Negative on error.
>   */
>  #define RTE_LOG(l, t, ...)                                     \
> +        rte_log(RTE_LOG_ ## l,                                 \
> +                RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__)
> +
> +/**
> + * Generates a log message for data path.
> + *
> + * Similar to RTE_LOG(), except that it is removed at compilation time
> + * if the RTE_LOG_DP_LEVEL configuration option is lower than the log
> + * level argument.
> + *
> + * @param l
> + *   Log level. A value between EMERG (1) and DEBUG (8). The short name is
> + *   expanded by the macro, so it cannot be an integer value.
> + * @param t
> + *   The log type, for example, EAL. The short name is expanded by the
> + *   macro, so it cannot be an integer value.
> + * @param ...
> + *   The fmt string, as in printf(3), followed by the variable arguments
> + *   required by the format.
> + * @return
> + *   - 0: Success.
> + *   - Negative on error.
> + */
> +#define RTE_LOG_DP(l, t, ...)                                  \
>         (void)((RTE_LOG_ ## l <= RTE_LOG_LEVEL) ?               \
>          rte_log(RTE_LOG_ ## l,                                 \
>                  RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__) :     \
> --
> 2.8.1

Hum, I suppose RTE_LOG_DP should look at RTE_LOG_DP_LEVEL.


-- 
David Marchand

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[David Marchand]

On Mon, Oct 3, 2016 at 6:27 PM, Wiles, Keith <keith.wiles@intel.com> wrote:
>> On Oct 3, 2016, at 10:37 AM, Olivier Matz <olivier.matz@6wind.com> wrote:
>> What makes you feel it's easier to add a log level instead of adding a
>> new RTE_LOG_DP() function?
>
> It seems to me the log levels are for displaying logs at different levels adding a new macro to not log is just a hack because we do not have a log level for data path. This is why I would like to see a log level added and not a new macro.
>
> It also appears the new RTE_LOG() will always be in the code as you moved the test to the RTE_LOG_DP() macro. This would mean all RTE_LOG() in the code will always call rte_log(), correct?
>
> If using a new DEBUG_DP (maybe DATAPATH is a better log level name) level we can use the same macro as before and modify the level only. This way we can remove via the compiler any log that is below the default RTE_LOG_LEVEL. I see keeping the rte_log() could be a performance problem or code blot when you really want to remove them all.
>
> The DATAPATH log level would be above (smaller number) then DEBUG in the enum list. To remove all debug logs just set the RTE_LOG_LEVEL to RTE_LOG_DATAPATH.

If I try to draw a parrallel to syslog (well, the log subsystem in eal
has always been bound to syslog ...), what you propose here is like
adding a new level in syslog while you have syslog facilities.

With the current log api, we have types and levels, can't we filter at
build time depending on the log "type" ?
Here we would strip PMD type logs > INFO.


-- 
David Marchand

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Olivier Matz]

Hi David,

On 10/04/2016 10:26 AM, David Marchand wrote:
> On Fri, Sep 16, 2016 at 9:43 AM, Olivier Matz <olivier.matz@6wind.com> wrote:
>> Today, all logs whose level is lower than INFO are dropped at
>> compile-time. This prevents from enabling debug logs at runtime using
>> --log-level=8.
>>
>> The rationale was to remove debug logs from the data path at
>> compile-time, avoiding a test at run-time.
>>
>> This patch changes the behavior of RTE_LOG() to avoid the compile-time
>> optimization, and introduces the RTE_LOG_DP() macro that has the same
>> behavior than the previous RTE_LOG(), for the rare cases where debug
>> logs are in the data path.
>>
>> So it is now possible to enable debug logs at run-time by just
>> specifying --log-level=8. Some drivers still have special compile-time
>> options to enable more debug log. Maintainers may consider to
>> remove/reduce them.
>>
>> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
>> ---
>>  config/common_base                      |  1 +
>>  doc/guides/faq/faq.rst                  |  2 +-
>>  drivers/net/bnxt/bnxt_txr.c             |  2 +-
>>  drivers/net/nfp/nfp_net.c               |  8 +++---
>>  examples/distributor/main.c             |  4 +--
>>  examples/ipsec-secgw/esp.c              |  2 +-
>>  examples/ipsec-secgw/ipsec.c            |  4 +--
>>  examples/packet_ordering/main.c         |  6 ++--
>>  examples/quota_watermark/qw/main.c      |  2 +-
>>  examples/tep_termination/main.c         |  4 +--
>>  examples/vhost/main.c                   | 14 +++++-----
>>  examples/vhost_xen/main.c               | 20 +++++++-------
>>  lib/librte_eal/common/include/rte_log.h | 49 +++++++++++++++++++++------------
>>  13 files changed, 67 insertions(+), 51 deletions(-)
>>
>> diff --git a/config/common_base b/config/common_base
>> index 7830535..04b71e9 100644
>> --- a/config/common_base
>> +++ b/config/common_base
>> @@ -89,6 +89,7 @@ CONFIG_RTE_MAX_MEMSEG=256
>>  CONFIG_RTE_MAX_MEMZONE=2560
>>  CONFIG_RTE_MAX_TAILQ=32
>>  CONFIG_RTE_LOG_LEVEL=RTE_LOG_INFO
>> +CONFIG_RTE_LOG_DP_LEVEL=RTE_LOG_INFO
>>  CONFIG_RTE_LOG_HISTORY=256
>>  CONFIG_RTE_LIBEAL_USE_HPET=n
>>  CONFIG_RTE_EAL_ALLOW_INV_SOCKET_ID=n
> 
> [snip]
> 
>> diff --git a/lib/librte_eal/common/include/rte_log.h b/lib/librte_eal/common/include/rte_log.h
>> index 919563c..76b198f 100644
>> --- a/lib/librte_eal/common/include/rte_log.h
>> +++ b/lib/librte_eal/common/include/rte_log.h
> 
> [snip]
> 
>> @@ -266,6 +257,30 @@ int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
>>   *   - Negative on error.
>>   */
>>  #define RTE_LOG(l, t, ...)                                     \
>> +        rte_log(RTE_LOG_ ## l,                                 \
>> +                RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__)
>> +
>> +/**
>> + * Generates a log message for data path.
>> + *
>> + * Similar to RTE_LOG(), except that it is removed at compilation time
>> + * if the RTE_LOG_DP_LEVEL configuration option is lower than the log
>> + * level argument.
>> + *
>> + * @param l
>> + *   Log level. A value between EMERG (1) and DEBUG (8). The short name is
>> + *   expanded by the macro, so it cannot be an integer value.
>> + * @param t
>> + *   The log type, for example, EAL. The short name is expanded by the
>> + *   macro, so it cannot be an integer value.
>> + * @param ...
>> + *   The fmt string, as in printf(3), followed by the variable arguments
>> + *   required by the format.
>> + * @return
>> + *   - 0: Success.
>> + *   - Negative on error.
>> + */
>> +#define RTE_LOG_DP(l, t, ...)                                  \
>>         (void)((RTE_LOG_ ## l <= RTE_LOG_LEVEL) ?               \
>>          rte_log(RTE_LOG_ ## l,                                 \
>>                  RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__) :     \
>> --
>> 2.8.1
> 
> Hum, I suppose RTE_LOG_DP should look at RTE_LOG_DP_LEVEL.
> 

That's correct, good catch :)
I'll send a v2 with that fix.


Olivier

Re: [dpdk-dev] [PATCH] log: do not drop debug logs at compile time

[Olivier Matz]

Hi David,

On 10/04/2016 10:28 AM, David Marchand wrote:
> On Mon, Oct 3, 2016 at 6:27 PM, Wiles, Keith <keith.wiles@intel.com> wrote:
>>> On Oct 3, 2016, at 10:37 AM, Olivier Matz <olivier.matz@6wind.com> wrote:
>>> What makes you feel it's easier to add a log level instead of adding a
>>> new RTE_LOG_DP() function?
>>
>> It seems to me the log levels are for displaying logs at different levels adding a new macro to not log is just a hack because we do not have a log level for data path. This is why I would like to see a log level added and not a new macro.
>>
>> It also appears the new RTE_LOG() will always be in the code as you moved the test to the RTE_LOG_DP() macro. This would mean all RTE_LOG() in the code will always call rte_log(), correct?
>>
>> If using a new DEBUG_DP (maybe DATAPATH is a better log level name) level we can use the same macro as before and modify the level only. This way we can remove via the compiler any log that is below the default RTE_LOG_LEVEL. I see keeping the rte_log() could be a performance problem or code blot when you really want to remove them all.
>>
>> The DATAPATH log level would be above (smaller number) then DEBUG in the enum list. To remove all debug logs just set the RTE_LOG_LEVEL to RTE_LOG_DATAPATH.
> 
> If I try to draw a parrallel to syslog (well, the log subsystem in eal
> has always been bound to syslog ...), what you propose here is like
> adding a new level in syslog while you have syslog facilities.
> 
> With the current log api, we have types and levels, can't we filter at
> build time depending on the log "type" ?
> Here we would strip PMD type logs > INFO.

I think we may have dataplane logs in other part of the code: in the
application (log type = USER), and surely in some dpdk libraries.

Moreover, as the behavior of the macro changes (in one case it is
stripped at compilation, in the other case not), I'd say having
different functions is clearer for the developer than having a different
behavior depending on log level or log type.

Regards,
Olivier

[dpdk-dev] [PATCH v2] log: do not drop debug logs at compile time

[Olivier Matz]

Today, all logs whose level is lower than INFO are dropped at
compile-time. This prevents from enabling debug logs at runtime using
--log-level=8.

The rationale was to remove debug logs from the data path at
compile-time, avoiding a test at run-time.

This patch changes the behavior of RTE_LOG() to avoid the compile-time
optimization, and introduces the RTE_LOG_DP() macro that has the same
behavior than the previous RTE_LOG(), for the rare cases where debug
logs are in the data path.

So it is now possible to enable debug logs at run-time by just
specifying --log-level=8. Some drivers still have special compile-time
options to enable more debug log. Maintainers may consider to
remove/reduce them.

Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
---
v1 -> v2:
- fix test in RTE_LOG_DP() as pointed-out by David

 config/common_base                      |  1 +
 doc/guides/faq/faq.rst                  |  2 +-
 drivers/net/bnxt/bnxt_txr.c             |  2 +-
 drivers/net/nfp/nfp_net.c               |  8 +++---
 examples/distributor/main.c             |  4 +--
 examples/ipsec-secgw/esp.c              |  2 +-
 examples/ipsec-secgw/ipsec.c            |  4 +--
 examples/packet_ordering/main.c         |  6 ++--
 examples/quota_watermark/qw/main.c      |  2 +-
 examples/tep_termination/main.c         |  4 +--
 examples/vhost/main.c                   | 14 ++++-----
 examples/vhost_xen/main.c               | 20 ++++++-------
 lib/librte_eal/common/include/rte_log.h | 51 +++++++++++++++++++++------------
 13 files changed, 68 insertions(+), 52 deletions(-)

diff --git a/config/common_base b/config/common_base
index 4bff83a..652a839 100644
--- a/config/common_base
+++ b/config/common_base
@@ -89,6 +89,7 @@ CONFIG_RTE_MAX_MEMSEG=256
 CONFIG_RTE_MAX_MEMZONE=2560
 CONFIG_RTE_MAX_TAILQ=32
 CONFIG_RTE_LOG_LEVEL=RTE_LOG_INFO
+CONFIG_RTE_LOG_DP_LEVEL=RTE_LOG_INFO
 CONFIG_RTE_LOG_HISTORY=256
 CONFIG_RTE_LIBEAL_USE_HPET=n
 CONFIG_RTE_EAL_ALLOW_INV_SOCKET_ID=n
diff --git a/doc/guides/faq/faq.rst b/doc/guides/faq/faq.rst
index 8d1ea6c..0adc549 100644
--- a/doc/guides/faq/faq.rst
+++ b/doc/guides/faq/faq.rst
@@ -101,7 +101,7 @@ Yes, the option ``--log-level=`` accepts one of these numbers:
     #define RTE_LOG_INFO 7U     /* Informational. */
     #define RTE_LOG_DEBUG 8U    /* Debug-level messages. */
 
-It is also possible to change the maximum (and default level) at compile time
+It is also possible to change the default level at compile time
 with ``CONFIG_RTE_LOG_LEVEL``.
 
 
diff --git a/drivers/net/bnxt/bnxt_txr.c b/drivers/net/bnxt/bnxt_txr.c
index 8bf8fee..0d15bb1 100644
--- a/drivers/net/bnxt/bnxt_txr.c
+++ b/drivers/net/bnxt/bnxt_txr.c
@@ -298,7 +298,7 @@ static int bnxt_handle_tx_cp(struct bnxt_tx_queue *txq)
 			if (CMP_TYPE(txcmp) == TX_CMPL_TYPE_TX_L2)
 				nb_tx_pkts++;
 			else
-				RTE_LOG(DEBUG, PMD,
+				RTE_LOG_DP(DEBUG, PMD,
 						"Unhandled CMP type %02x\n",
 						CMP_TYPE(txcmp));
 			raw_cons = NEXT_RAW_CMP(raw_cons);
diff --git a/drivers/net/nfp/nfp_net.c b/drivers/net/nfp/nfp_net.c
index 707be8b..e315dd8 100644
--- a/drivers/net/nfp/nfp_net.c
+++ b/drivers/net/nfp/nfp_net.c
@@ -1707,7 +1707,7 @@ nfp_net_recv_pkts(void *rx_queue, struct rte_mbuf **rx_pkts, uint16_t nb_pkts)
 		 * DPDK just checks the queue is lower than max queues
 		 * enabled. But the queue needs to be configured
 		 */
-		RTE_LOG(ERR, PMD, "RX Bad queue\n");
+		RTE_LOG_DP(ERR, PMD, "RX Bad queue\n");
 		return -EINVAL;
 	}
 
@@ -1720,7 +1720,7 @@ nfp_net_recv_pkts(void *rx_queue, struct rte_mbuf **rx_pkts, uint16_t nb_pkts)
 
 		rxb = &rxq->rxbufs[idx];
 		if (unlikely(rxb == NULL)) {
-			RTE_LOG(ERR, PMD, "rxb does not exist!\n");
+			RTE_LOG_DP(ERR, PMD, "rxb does not exist!\n");
 			break;
 		}
 
@@ -1740,7 +1740,7 @@ nfp_net_recv_pkts(void *rx_queue, struct rte_mbuf **rx_pkts, uint16_t nb_pkts)
 		 */
 		new_mb = rte_pktmbuf_alloc(rxq->mem_pool);
 		if (unlikely(new_mb == NULL)) {
-			RTE_LOG(DEBUG, PMD, "RX mbuf alloc failed port_id=%u "
+			RTE_LOG_DP(DEBUG, PMD, "RX mbuf alloc failed port_id=%u "
 				"queue_id=%u\n", (unsigned)rxq->port_id,
 				(unsigned)rxq->qidx);
 			nfp_net_mbuf_alloc_failed(rxq);
@@ -1771,7 +1771,7 @@ nfp_net_recv_pkts(void *rx_queue, struct rte_mbuf **rx_pkts, uint16_t nb_pkts)
 			 * responsibility of avoiding it. But we have
 			 * to give some info about the error
 			 */
-			RTE_LOG(ERR, PMD,
+			RTE_LOG_DP(ERR, PMD,
 				"mbuf overflow likely due to the RX offset.\n"
 				"\t\tYour mbuf size should have extra space for"
 				" RX offset=%u bytes.\n"
diff --git a/examples/distributor/main.c b/examples/distributor/main.c
index 537cee1..e7641d2 100644
--- a/examples/distributor/main.c
+++ b/examples/distributor/main.c
@@ -241,7 +241,7 @@ lcore_rx(struct lcore_params *p)
 		uint16_t sent = rte_ring_enqueue_burst(r, (void *)bufs, nb_ret);
 		app_stats.rx.enqueued_pkts += sent;
 		if (unlikely(sent < nb_ret)) {
-			RTE_LOG(DEBUG, DISTRAPP,
+			RTE_LOG_DP(DEBUG, DISTRAPP,
 				"%s:Packet loss due to full ring\n", __func__);
 			while (sent < nb_ret)
 				rte_pktmbuf_free(bufs[sent++]);
@@ -274,7 +274,7 @@ flush_one_port(struct output_buffer *outbuf, uint8_t outp)
 	app_stats.tx.tx_pkts += nb_tx;
 
 	if (unlikely(nb_tx < outbuf->count)) {
-		RTE_LOG(DEBUG, DISTRAPP,
+		RTE_LOG_DP(DEBUG, DISTRAPP,
 			"%s:Packet loss with tx_burst\n", __func__);
 		do {
 			rte_pktmbuf_free(outbuf->mbufs[nb_tx]);
diff --git a/examples/ipsec-secgw/esp.c b/examples/ipsec-secgw/esp.c
index ec5a2e6..9715ea9 100644
--- a/examples/ipsec-secgw/esp.c
+++ b/examples/ipsec-secgw/esp.c
@@ -78,7 +78,7 @@ esp_inbound(struct rte_mbuf *m, struct ipsec_sa *sa,
 		sizeof(struct esp_hdr) - sa->iv_len - sa->digest_len;
 
 	if ((payload_len & (sa->block_size - 1)) || (payload_len <= 0)) {
-		RTE_LOG(DEBUG, IPSEC_ESP, "payload %d not multiple of %u\n",
+		RTE_LOG_DP(DEBUG, IPSEC_ESP, "payload %d not multiple of %u\n",
 				payload_len, sa->block_size);
 		return -EINVAL;
 	}
diff --git a/examples/ipsec-secgw/ipsec.c b/examples/ipsec-secgw/ipsec.c
index f49143b..144f0aa 100644
--- a/examples/ipsec-secgw/ipsec.c
+++ b/examples/ipsec-secgw/ipsec.c
@@ -65,7 +65,7 @@ create_session(struct ipsec_ctx *ipsec_ctx __rte_unused, struct ipsec_sa *sa)
 		return -1;
 	}
 
-	RTE_LOG(DEBUG, IPSEC, "Create session for SA spi %u on cryptodev "
+	RTE_LOG_DP(DEBUG, IPSEC, "Create session for SA spi %u on cryptodev "
 			"%u qp %u\n", sa->spi,
 			ipsec_ctx->tbl[cdev_id_qp].id,
 			ipsec_ctx->tbl[cdev_id_qp].qp);
@@ -89,7 +89,7 @@ enqueue_cop(struct cdev_qp *cqp, struct rte_crypto_op *cop)
 		ret = rte_cryptodev_enqueue_burst(cqp->id, cqp->qp,
 				cqp->buf, cqp->len);
 		if (ret < cqp->len) {
-			RTE_LOG(DEBUG, IPSEC, "Cryptodev %u queue %u:"
+			RTE_LOG_DP(DEBUG, IPSEC, "Cryptodev %u queue %u:"
 					" enqueued %u crypto ops out of %u\n",
 					 cqp->id, cqp->qp,
 					 ret, cqp->len);
diff --git a/examples/packet_ordering/main.c b/examples/packet_ordering/main.c
index 3c88b86..d4dc789 100644
--- a/examples/packet_ordering/main.c
+++ b/examples/packet_ordering/main.c
@@ -229,7 +229,7 @@ flush_tx_error_callback(struct rte_mbuf **unsent, uint16_t count,
 
 	/* free the mbufs which failed from transmit */
 	app_stats.tx.ro_tx_failed_pkts += count;
-	RTE_LOG(DEBUG, REORDERAPP, "%s:Packet loss with tx_burst\n", __func__);
+	RTE_LOG_DP(DEBUG, REORDERAPP, "%s:Packet loss with tx_burst\n", __func__);
 	pktmbuf_free_bulk(unsent, count);
 
 }
@@ -410,7 +410,7 @@ rx_thread(struct rte_ring *ring_out)
 				nb_rx_pkts = rte_eth_rx_burst(port_id, 0,
 								pkts, MAX_PKTS_BURST);
 				if (nb_rx_pkts == 0) {
-					RTE_LOG(DEBUG, REORDERAPP,
+					RTE_LOG_DP(DEBUG, REORDERAPP,
 					"%s():Received zero packets\n",	__func__);
 					continue;
 				}
@@ -522,7 +522,7 @@ send_thread(struct send_thread_args *args)
 
 			if (ret == -1 && rte_errno == ERANGE) {
 				/* Too early pkts should be transmitted out directly */
-				RTE_LOG(DEBUG, REORDERAPP,
+				RTE_LOG_DP(DEBUG, REORDERAPP,
 						"%s():Cannot reorder early packet "
 						"direct enqueuing to TX\n", __func__);
 				outp = mbufs[i]->port;
diff --git a/examples/quota_watermark/qw/main.c b/examples/quota_watermark/qw/main.c
index 8ed0214..9162e28 100644
--- a/examples/quota_watermark/qw/main.c
+++ b/examples/quota_watermark/qw/main.c
@@ -81,7 +81,7 @@ static void send_pause_frame(uint8_t port_id, uint16_t duration)
     struct ether_hdr *hdr;
     struct ether_addr mac_addr;
 
-    RTE_LOG(DEBUG, USER1, "Sending PAUSE frame (duration=%d) on port %d\n",
+    RTE_LOG_DP(DEBUG, USER1, "Sending PAUSE frame (duration=%d) on port %d\n",
             duration, port_id);
 
     /* Get a mbuf from the pool */
diff --git a/examples/tep_termination/main.c b/examples/tep_termination/main.c
index 1d6d463..bd1dc96 100644
--- a/examples/tep_termination/main.c
+++ b/examples/tep_termination/main.c
@@ -567,7 +567,7 @@ virtio_tx_route(struct vhost_dev *vdev, struct rte_mbuf *m)
 	unsigned len, ret = 0;
 	const uint16_t lcore_id = rte_lcore_id();
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%d) TX: MAC address is external\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%d) TX: MAC address is external\n",
 		vdev->vid);
 
 	/* Add packet to the port tx queue */
@@ -649,7 +649,7 @@ switch_worker(__rte_unused void *arg)
 		if (unlikely(diff_tsc > drain_tsc)) {
 
 			if (tx_q->len) {
-				RTE_LOG(DEBUG, VHOST_DATA, "TX queue drained after "
+				RTE_LOG_DP(DEBUG, VHOST_DATA, "TX queue drained after "
 					"timeout with burst size %u\n",
 					tx_q->len);
 				ret = overlay_options.tx_handle(ports[0],
diff --git a/examples/vhost/main.c b/examples/vhost/main.c
index 0709859..ac1f6e2 100644
--- a/examples/vhost/main.c
+++ b/examples/vhost/main.c
@@ -832,17 +832,17 @@ virtio_tx_local(struct vhost_dev *vdev, struct rte_mbuf *m)
 		return -1;
 
 	if (vdev->vid == dst_vdev->vid) {
-		RTE_LOG(DEBUG, VHOST_DATA,
+		RTE_LOG_DP(DEBUG, VHOST_DATA,
 			"(%d) TX: src and dst MAC is same. Dropping packet.\n",
 			vdev->vid);
 		return 0;
 	}
 
-	RTE_LOG(DEBUG, VHOST_DATA,
+	RTE_LOG_DP(DEBUG, VHOST_DATA,
 		"(%d) TX: MAC address is local\n", dst_vdev->vid);
 
 	if (unlikely(dst_vdev->remove)) {
-		RTE_LOG(DEBUG, VHOST_DATA,
+		RTE_LOG_DP(DEBUG, VHOST_DATA,
 			"(%d) device is marked for removal\n", dst_vdev->vid);
 		return 0;
 	}
@@ -867,7 +867,7 @@ find_local_dest(struct vhost_dev *vdev, struct rte_mbuf *m,
 		return 0;
 
 	if (vdev->vid == dst_vdev->vid) {
-		RTE_LOG(DEBUG, VHOST_DATA,
+		RTE_LOG_DP(DEBUG, VHOST_DATA,
 			"(%d) TX: src and dst MAC is same. Dropping packet.\n",
 			vdev->vid);
 		return -1;
@@ -881,7 +881,7 @@ find_local_dest(struct vhost_dev *vdev, struct rte_mbuf *m,
 	*offset  = VLAN_HLEN;
 	*vlan_tag = vlan_tags[vdev->vid];
 
-	RTE_LOG(DEBUG, VHOST_DATA,
+	RTE_LOG_DP(DEBUG, VHOST_DATA,
 		"(%d) TX: pkt to local VM device id: (%d), vlan tag: %u.\n",
 		vdev->vid, dst_vdev->vid, *vlan_tag);
 
@@ -973,7 +973,7 @@ virtio_tx_route(struct vhost_dev *vdev, struct rte_mbuf *m, uint16_t vlan_tag)
 		}
 	}
 
-	RTE_LOG(DEBUG, VHOST_DATA,
+	RTE_LOG_DP(DEBUG, VHOST_DATA,
 		"(%d) TX: MAC address is external\n", vdev->vid);
 
 queue2nic:
@@ -1041,7 +1041,7 @@ drain_mbuf_table(struct mbuf_table *tx_q)
 	if (unlikely(cur_tsc - prev_tsc > MBUF_TABLE_DRAIN_TSC)) {
 		prev_tsc = cur_tsc;
 
-		RTE_LOG(DEBUG, VHOST_DATA,
+		RTE_LOG_DP(DEBUG, VHOST_DATA,
 			"TX queue drained after timeout with burst size %u\n",
 			tx_q->len);
 		do_drain_mbuf_table(tx_q);
diff --git a/examples/vhost_xen/main.c b/examples/vhost_xen/main.c
index f4dbaa4..af05b00 100644
--- a/examples/vhost_xen/main.c
+++ b/examples/vhost_xen/main.c
@@ -525,7 +525,7 @@ gpa_to_vva(struct virtio_net *dev, uint64_t guest_pa)
 			break;
 		}
 	}
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") GPA %p| VVA %p\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") GPA %p| VVA %p\n",
 		dev->device_fh, (void*)(uintptr_t)guest_pa, (void*)(uintptr_t)vhost_va);
 
 	return vhost_va;
@@ -555,7 +555,7 @@ virtio_dev_rx(struct virtio_net *dev, struct rte_mbuf **pkts, uint32_t count)
 	uint8_t success = 0;
 	void *userdata;
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") virtio_dev_rx()\n", dev->device_fh);
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") virtio_dev_rx()\n", dev->device_fh);
 	vq = dev->virtqueue_rx;
 	count = (count > MAX_PKT_BURST) ? MAX_PKT_BURST : count;
 	/* As many data cores may want access to available buffers, they need to be reserved. */
@@ -580,7 +580,7 @@ virtio_dev_rx(struct virtio_net *dev, struct rte_mbuf **pkts, uint32_t count)
 									res_end_idx);
 	} while (unlikely(success == 0));
 	res_cur_idx = res_base_idx;
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") Current Index %d| End Index %d\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") Current Index %d| End Index %d\n",
 		dev->device_fh, res_cur_idx, res_end_idx);
 
 	/* Prefetch available ring to retrieve indexes. */
@@ -775,7 +775,7 @@ virtio_tx_local(struct virtio_net *dev, struct rte_mbuf *m)
 
 			/* Drop the packet if the TX packet is destined for the TX device. */
 			if (dev_ll->dev->device_fh == dev->device_fh) {
-				RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
+				RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
 					"Source and destination MAC addresses are the same. "
 					"Dropping packet.\n",
 					dev_ll->dev->device_fh);
@@ -783,12 +783,12 @@ virtio_tx_local(struct virtio_net *dev, struct rte_mbuf *m)
 			}
 
 
-			RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
+			RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
 				"MAC address is local\n", dev_ll->dev->device_fh);
 
 			if (dev_ll->dev->remove) {
 				/*drop the packet if the device is marked for removal*/
-				RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") "
+				RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") "
 					"Device is marked for removal\n",
 					dev_ll->dev->device_fh);
 			} else {
@@ -829,7 +829,7 @@ virtio_tx_route(struct virtio_net* dev, struct rte_mbuf *m, struct rte_mempool *
 		return;
 	}
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") TX: "
 		"MAC address is external\n", dev->device_fh);
 
 	/*Add packet to the port tx queue*/
@@ -903,7 +903,7 @@ virtio_dev_tx(struct virtio_net* dev, struct rte_mempool *mbuf_pool)
 	if (vq->last_used_idx == avail_idx)
 		return;
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") virtio_dev_tx()\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") virtio_dev_tx()\n",
 		dev->device_fh);
 
 	/* Prefetch available ring to retrieve head indexes. */
@@ -913,7 +913,7 @@ virtio_dev_tx(struct virtio_net* dev, struct rte_mempool *mbuf_pool)
 	free_entries = avail_idx - vq->last_used_idx;
 	free_entries = unlikely(free_entries < MAX_PKT_BURST) ? free_entries : MAX_PKT_BURST;
 
-	RTE_LOG(DEBUG, VHOST_DATA, "(%" PRIu64 ") Buffers available %d\n",
+	RTE_LOG_DP(DEBUG, VHOST_DATA, "(%" PRIu64 ") Buffers available %d\n",
 		dev->device_fh, free_entries);
 	/* Retrieve all of the head indexes first to avoid caching issues. */
 	for (i = 0; i < free_entries; i++)
@@ -1003,7 +1003,7 @@ switch_worker(__attribute__((unused)) void *arg)
 		if (unlikely(diff_tsc > drain_tsc)) {
 
 			if (tx_q->len) {
-				RTE_LOG(DEBUG, VHOST_DATA,
+				RTE_LOG_DP(DEBUG, VHOST_DATA,
 					"TX queue drained after timeout with burst size %u\n",
 					tx_q->len);
 
diff --git a/lib/librte_eal/common/include/rte_log.h b/lib/librte_eal/common/include/rte_log.h
index 29f7d19..671e274 100644
--- a/lib/librte_eal/common/include/rte_log.h
+++ b/lib/librte_eal/common/include/rte_log.h
@@ -118,9 +118,8 @@ int rte_openlog_stream(FILE *f);
 /**
  * Set the global log level.
  *
- * After this call, all logs that are lower or equal than level and
- * lower or equal than the RTE_LOG_LEVEL configuration option will be
- * displayed.
+ * After this call, logs with a level lower or equal than the level
+ * passed as argument will be displayed.
  *
  * @param level
  *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
@@ -184,9 +183,8 @@ int rte_log_cur_msg_logtype(void);
  * The level argument determines if the log should be displayed or
  * not, depending on the global rte_logs variable.
  *
- * The preferred alternative is the RTE_LOG() function because debug logs may
- * be removed at compilation time if optimization is enabled. Moreover,
- * logs are automatically prefixed by type when using the macro.
+ * The preferred alternative is the RTE_LOG() because it adds the
+ * level and type in the logged string.
  *
  * @param level
  *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
@@ -217,8 +215,8 @@ int rte_log(uint32_t level, uint32_t logtype, const char *format, ...)
  * not, depending on the global rte_logs variable. A trailing
  * newline may be added if needed.
  *
- * The preferred alternative is the RTE_LOG() because debug logs may be
- * removed at compilation time.
+ * The preferred alternative is the RTE_LOG() because it adds the
+ * level and type in the logged string.
  *
  * @param level
  *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
@@ -239,15 +237,8 @@ int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
 /**
  * Generates a log message.
  *
- * The RTE_LOG() is equivalent to rte_log() with two differences:
-
- * - RTE_LOG() can be used to remove debug logs at compilation time,
- *   depending on RTE_LOG_LEVEL configuration option, and compilation
- *   optimization level. If optimization is enabled, the tests
- *   involving constants only are pre-computed. If compilation is done
- *   with -O0, these tests will be done at run time.
- * - The log level and log type names are smaller, for example:
- *   RTE_LOG(INFO, EAL, "this is a %s", "log");
+ * The RTE_LOG() is a helper that prefixes the string with the log level
+ * and type, and call rte_log().
  *
  * @param l
  *   Log level. A value between EMERG (1) and DEBUG (8). The short name is
@@ -263,7 +254,31 @@ int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
  *   - Negative on error.
  */
 #define RTE_LOG(l, t, ...)					\
-	(void)((RTE_LOG_ ## l <= RTE_LOG_LEVEL) ?		\
+	 rte_log(RTE_LOG_ ## l,					\
+		 RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__)
+
+/**
+ * Generates a log message for data path.
+ *
+ * Similar to RTE_LOG(), except that it is removed at compilation time
+ * if the RTE_LOG_DP_LEVEL configuration option is lower than the log
+ * level argument.
+ *
+ * @param l
+ *   Log level. A value between EMERG (1) and DEBUG (8). The short name is
+ *   expanded by the macro, so it cannot be an integer value.
+ * @param t
+ *   The log type, for example, EAL. The short name is expanded by the
+ *   macro, so it cannot be an integer value.
+ * @param ...
+ *   The fmt string, as in printf(3), followed by the variable arguments
+ *   required by the format.
+ * @return
+ *   - 0: Success.
+ *   - Negative on error.
+ */
+#define RTE_LOG_DP(l, t, ...)					\
+	(void)((RTE_LOG_ ## l <= RTE_LOG_DP_LEVEL) ?		\
 	 rte_log(RTE_LOG_ ## l,					\
 		 RTE_LOGTYPE_ ## t, # t ": " __VA_ARGS__) :	\
 	 0)
-- 
2.8.1

Re: [dpdk-dev] [PATCH v2] log: do not drop debug logs at compile time

[Thomas Monjalon]

2016-11-23 16:34, Olivier Matz:
> Today, all logs whose level is lower than INFO are dropped at
> compile-time. This prevents from enabling debug logs at runtime using
> --log-level=8.
> 
> The rationale was to remove debug logs from the data path at
> compile-time, avoiding a test at run-time.
> 
> This patch changes the behavior of RTE_LOG() to avoid the compile-time
> optimization, and introduces the RTE_LOG_DP() macro that has the same
> behavior than the previous RTE_LOG(), for the rare cases where debug
> logs are in the data path.
> 
> So it is now possible to enable debug logs at run-time by just
> specifying --log-level=8. Some drivers still have special compile-time
> options to enable more debug log. Maintainers may consider to
> remove/reduce them.
> 
> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>

Applied, thanks