[dpdk-dev,5/5] ixgbe: silence noisy log messages

Message ID 1431709707-5281-6-git-send-email-stephen@networkplumber.org (mailing list archive)
State Superseded, archived
Headers

Commit Message

Stephen Hemminger May 15, 2015, 5:08 p.m. UTC
  The ixgbe driver likes to be far to chatty in the system log
which is good for the original developer but not good for a production
product. All the normal messages should be changed from INFO to DEBUG.

Signed-off-by: Stephen Hemminger <stephen@networkplumber.org>
---
 lib/librte_pmd_ixgbe/ixgbe_ethdev.c | 14 +++++++-------
 lib/librte_pmd_ixgbe/ixgbe_rxtx.c   | 20 ++++++++++----------
 2 files changed, 17 insertions(+), 17 deletions(-)
  

Comments

Bruce Richardson May 18, 2015, 9:32 a.m. UTC | #1
On Fri, May 15, 2015 at 10:08:27AM -0700, Stephen Hemminger wrote:
> The ixgbe driver likes to be far to chatty in the system log
> which is good for the original developer but not good for a production
> product. All the normal messages should be changed from INFO to DEBUG.
> 
> Signed-off-by: Stephen Hemminger <stephen@networkplumber.org>

For the most part, this looks fine. However, I'm unsure about changing the log
level of the messages stating what the RX and TX burst functions in use are. I
would view this as important information that should generally be displayed as
the performance impacts of using a sub-optimal RX/TX code path are large.

/Bruce

> ---
>  lib/librte_pmd_ixgbe/ixgbe_ethdev.c | 14 +++++++-------
>  lib/librte_pmd_ixgbe/ixgbe_rxtx.c   | 20 ++++++++++----------
>  2 files changed, 17 insertions(+), 17 deletions(-)
> 
> diff --git a/lib/librte_pmd_ixgbe/ixgbe_ethdev.c b/lib/librte_pmd_ixgbe/ixgbe_ethdev.c
> index 7e75382..bb24a17 100644
> --- a/lib/librte_pmd_ixgbe/ixgbe_ethdev.c
> +++ b/lib/librte_pmd_ixgbe/ixgbe_ethdev.c
> @@ -568,7 +568,7 @@ ixgbe_dev_queue_stats_mapping_set(struct rte_eth_dev *eth_dev,
>  		(hw->mac.type != ixgbe_mac_X550EM_x))
>  		return -ENOSYS;
>  
> -	PMD_INIT_LOG(INFO, "Setting port %u, %s queue_id %d to stat index %d",
> +	PMD_INIT_LOG(DEBUG, "Setting port %u, %s queue_id %d to stat index %d",
>  		     eth_dev->data->port_id, is_rx ? "RX" : "TX",
>  		     queue_id, stat_idx);
>  
> @@ -594,20 +594,20 @@ ixgbe_dev_queue_stats_mapping_set(struct rte_eth_dev *eth_dev,
>  	else
>  		stat_mappings->rqsmr[n] |= qsmr_mask;
>  
> -	PMD_INIT_LOG(INFO, "Set port %u, %s queue_id %d to stat index %d",
> +	PMD_INIT_LOG(DEBUG, "Set port %u, %s queue_id %d to stat index %d",
>  		     eth_dev->data->port_id, is_rx ? "RX" : "TX",
>  		     queue_id, stat_idx);
> -	PMD_INIT_LOG(INFO, "%s[%d] = 0x%08x", is_rx ? "RQSMR" : "TQSM", n,
> +	PMD_INIT_LOG(DEBUG, "%s[%d] = 0x%08x", is_rx ? "RQSMR" : "TQSM", n,
>  		     is_rx ? stat_mappings->rqsmr[n] : stat_mappings->tqsm[n]);
>  
>  	/* Now write the mapping in the appropriate register */
>  	if (is_rx) {
> -		PMD_INIT_LOG(INFO, "Write 0x%x to RX IXGBE stat mapping reg:%d",
> +		PMD_INIT_LOG(DEBUG, "Write 0x%x to RX IXGBE stat mapping reg:%d",
>  			     stat_mappings->rqsmr[n], n);
>  		IXGBE_WRITE_REG(hw, IXGBE_RQSMR(n), stat_mappings->rqsmr[n]);
>  	}
>  	else {
> -		PMD_INIT_LOG(INFO, "Write 0x%x to TX IXGBE stat mapping reg:%d",
> +		PMD_INIT_LOG(DEBUG, "Write 0x%x to TX IXGBE stat mapping reg:%d",
>  			     stat_mappings->tqsm[n], n);
>  		IXGBE_WRITE_REG(hw, IXGBE_TQSM(n), stat_mappings->tqsm[n]);
>  	}
> @@ -751,7 +751,7 @@ eth_ixgbe_dev_init(struct rte_eth_dev *eth_dev)
>  			ixgbe_set_tx_function(eth_dev, txq);
>  		} else {
>  			/* Use default TX function if we get here */
> -			PMD_INIT_LOG(INFO, "No TX queues configured yet. "
> +			PMD_INIT_LOG(DEBUG, "No TX queues configured yet. "
>  			                   "Using default TX function.");
>  		}
>  
> @@ -2275,7 +2275,7 @@ ixgbe_dev_interrupt_get_status(struct rte_eth_dev *dev)
>  
>  	/* read-on-clear nic registers here */
>  	eicr = IXGBE_READ_REG(hw, IXGBE_EICR);
> -	PMD_DRV_LOG(INFO, "eicr %x", eicr);
> +	PMD_DRV_LOG(DEBUG, "eicr %x", eicr);
>  
>  	intr->flags = 0;
>  	if (eicr & IXGBE_EICR_LSC) {
> diff --git a/lib/librte_pmd_ixgbe/ixgbe_rxtx.c b/lib/librte_pmd_ixgbe/ixgbe_rxtx.c
> index 57c9430..08830bf 100644
> --- a/lib/librte_pmd_ixgbe/ixgbe_rxtx.c
> +++ b/lib/librte_pmd_ixgbe/ixgbe_rxtx.c
> @@ -1871,23 +1871,23 @@ ixgbe_set_tx_function(struct rte_eth_dev *dev, struct ixgbe_tx_queue *txq)
>  	/* Use a simple Tx queue (no offloads, no multi segs) if possible */
>  	if (((txq->txq_flags & IXGBE_SIMPLE_FLAGS) == IXGBE_SIMPLE_FLAGS)
>  			&& (txq->tx_rs_thresh >= RTE_PMD_IXGBE_TX_MAX_BURST)) {
> -		PMD_INIT_LOG(INFO, "Using simple tx code path");
> +		PMD_INIT_LOG(DEBUG, "Using simple tx code path");
>  #ifdef RTE_IXGBE_INC_VECTOR
>  		if (txq->tx_rs_thresh <= RTE_IXGBE_TX_MAX_FREE_BUF_SZ &&
>  				(rte_eal_process_type() != RTE_PROC_PRIMARY ||
>  					ixgbe_txq_vec_setup(txq) == 0)) {
> -			PMD_INIT_LOG(INFO, "Vector tx enabled.");
> +			PMD_INIT_LOG(DEBUG, "Vector tx enabled.");
>  			dev->tx_pkt_burst = ixgbe_xmit_pkts_vec;
>  		} else
>  #endif
>  		dev->tx_pkt_burst = ixgbe_xmit_pkts_simple;
>  	} else {
> -		PMD_INIT_LOG(INFO, "Using full-featured tx code path");
> -		PMD_INIT_LOG(INFO,
> +		PMD_INIT_LOG(DEBUG, "Using full-featured tx code path");
> +		PMD_INIT_LOG(DEBUG,
>  				" - txq_flags = %lx " "[IXGBE_SIMPLE_FLAGS=%lx]",
>  				(unsigned long)txq->txq_flags,
>  				(unsigned long)IXGBE_SIMPLE_FLAGS);
> -		PMD_INIT_LOG(INFO,
> +		PMD_INIT_LOG(DEBUG,
>  				" - tx_rs_thresh = %lu " "[RTE_PMD_IXGBE_TX_MAX_BURST=%lu]",
>  				(unsigned long)txq->tx_rs_thresh,
>  				(unsigned long)RTE_PMD_IXGBE_TX_MAX_BURST);
> @@ -3761,11 +3761,11 @@ void ixgbe_set_rx_function(struct rte_eth_dev *dev)
>  	 */
>  	if (dev->data->lro) {
>  		if (adapter->rx_bulk_alloc_allowed) {
> -			PMD_INIT_LOG(INFO, "LRO is requested. Using a bulk "
> +			PMD_INIT_LOG(DEBUG, "LRO is requested. Using a bulk "
>  					   "allocation version");
>  			dev->rx_pkt_burst = ixgbe_recv_pkts_lro_bulk_alloc;
>  		} else {
> -			PMD_INIT_LOG(INFO, "LRO is requested. Using a single "
> +			PMD_INIT_LOG(DEBUG, "LRO is requested. Using a single "
>  					   "allocation version");
>  			dev->rx_pkt_burst = ixgbe_recv_pkts_lro_single_alloc;
>  		}
> @@ -3781,7 +3781,7 @@ void ixgbe_set_rx_function(struct rte_eth_dev *dev)
>  
>  			dev->rx_pkt_burst = ixgbe_recv_scattered_pkts_vec;
>  		} else if (adapter->rx_bulk_alloc_allowed) {
> -			PMD_INIT_LOG(INFO, "Using a Scattered with bulk "
> +			PMD_INIT_LOG(DEBUG, "Using a Scattered with bulk "
>  					   "allocation callback (port=%d).",
>  				     dev->data->port_id);
>  			dev->rx_pkt_burst = ixgbe_recv_pkts_lro_bulk_alloc;
> @@ -3803,7 +3803,7 @@ void ixgbe_set_rx_function(struct rte_eth_dev *dev)
>  	 *    - Single buffer allocation (the simplest one)
>  	 */
>  	} else if (adapter->rx_vec_allowed) {
> -		PMD_INIT_LOG(INFO, "Vector rx enabled, please make sure RX "
> +		PMD_INIT_LOG(DEBUG, "Vector rx enabled, please make sure RX "
>  				   "burst size no less than 32.");
>  
>  		dev->rx_pkt_burst = ixgbe_recv_pkts_vec;
> @@ -3961,7 +3961,7 @@ ixgbe_set_rsc(struct rte_eth_dev *dev)
>  
>  	dev->data->lro = 1;
>  
> -	PMD_INIT_LOG(INFO, "enabling LRO mode");
> +	PMD_INIT_LOG(DEBUG, "enabling LRO mode");
>  
>  	return 0;
>  }
> -- 
> 2.1.4
>
  
Stephen Hemminger May 18, 2015, 4:39 p.m. UTC | #2
On Mon, 18 May 2015 10:32:01 +0100
Bruce Richardson <bruce.richardson@intel.com> wrote:

> For the most part, this looks fine. However, I'm unsure about changing the log
> level of the messages stating what the RX and TX burst functions in use are. I
> would view this as important information that should generally be displayed as
> the performance impacts of using a sub-optimal RX/TX code path are large.
> 
> /Bruce


At INFO level it shows up in log files that customers read.
This is an issue where DPDK has to grow up and be ready for real world
use, rather than being developer friendly.

Our customers ask about every log message (believe me). So if there
is no problem the drivers must be absolutely silent (STFU)
  
David Marchand May 19, 2015, 7:46 a.m. UTC | #3
On Mon, May 18, 2015 at 6:39 PM, Stephen Hemminger <
stephen@networkplumber.org> wrote:

> On Mon, 18 May 2015 10:32:01 +0100
> Bruce Richardson <bruce.richardson@intel.com> wrote:
>
> > For the most part, this looks fine. However, I'm unsure about changing
> the log
> > level of the messages stating what the RX and TX burst functions in use
> are. I
> > would view this as important information that should generally be
> displayed as
> > the performance impacts of using a sub-optimal RX/TX code path are large.
> >
> > /Bruce
>
>
> At INFO level it shows up in log files that customers read.
> This is an issue where DPDK has to grow up and be ready for real world
> use, rather than being developer friendly.
>
> Our customers ask about every log message (believe me). So if there
> is no problem the drivers must be absolutely silent (STFU)
>

Are there messages at INFO level you want to keep ?
Or can't you just set the log level (the runtime option not the build one)
to something like WARNING or ERR ?
  
Stephen Hemminger May 19, 2015, 2:40 p.m. UTC | #4
We need info messages about topology etc from other components.

On Tue, May 19, 2015 at 12:46 AM, David Marchand <david.marchand@6wind.com>
wrote:

> On Mon, May 18, 2015 at 6:39 PM, Stephen Hemminger <
> stephen@networkplumber.org> wrote:
>
>> On Mon, 18 May 2015 10:32:01 +0100
>> Bruce Richardson <bruce.richardson@intel.com> wrote:
>>
>> > For the most part, this looks fine. However, I'm unsure about changing
>> the log
>> > level of the messages stating what the RX and TX burst functions in use
>> are. I
>> > would view this as important information that should generally be
>> displayed as
>> > the performance impacts of using a sub-optimal RX/TX code path are
>> large.
>> >
>> > /Bruce
>>
>>
>> At INFO level it shows up in log files that customers read.
>> This is an issue where DPDK has to grow up and be ready for real world
>> use, rather than being developer friendly.
>>
>> Our customers ask about every log message (believe me). So if there
>> is no problem the drivers must be absolutely silent (STFU)
>>
>
> Are there messages at INFO level you want to keep ?
> Or can't you just set the log level (the runtime option not the build one)
> to something like WARNING or ERR ?
>
>
> --
> David Marchand
>
>
  

Patch

diff --git a/lib/librte_pmd_ixgbe/ixgbe_ethdev.c b/lib/librte_pmd_ixgbe/ixgbe_ethdev.c
index 7e75382..bb24a17 100644
--- a/lib/librte_pmd_ixgbe/ixgbe_ethdev.c
+++ b/lib/librte_pmd_ixgbe/ixgbe_ethdev.c
@@ -568,7 +568,7 @@  ixgbe_dev_queue_stats_mapping_set(struct rte_eth_dev *eth_dev,
 		(hw->mac.type != ixgbe_mac_X550EM_x))
 		return -ENOSYS;
 
-	PMD_INIT_LOG(INFO, "Setting port %u, %s queue_id %d to stat index %d",
+	PMD_INIT_LOG(DEBUG, "Setting port %u, %s queue_id %d to stat index %d",
 		     eth_dev->data->port_id, is_rx ? "RX" : "TX",
 		     queue_id, stat_idx);
 
@@ -594,20 +594,20 @@  ixgbe_dev_queue_stats_mapping_set(struct rte_eth_dev *eth_dev,
 	else
 		stat_mappings->rqsmr[n] |= qsmr_mask;
 
-	PMD_INIT_LOG(INFO, "Set port %u, %s queue_id %d to stat index %d",
+	PMD_INIT_LOG(DEBUG, "Set port %u, %s queue_id %d to stat index %d",
 		     eth_dev->data->port_id, is_rx ? "RX" : "TX",
 		     queue_id, stat_idx);
-	PMD_INIT_LOG(INFO, "%s[%d] = 0x%08x", is_rx ? "RQSMR" : "TQSM", n,
+	PMD_INIT_LOG(DEBUG, "%s[%d] = 0x%08x", is_rx ? "RQSMR" : "TQSM", n,
 		     is_rx ? stat_mappings->rqsmr[n] : stat_mappings->tqsm[n]);
 
 	/* Now write the mapping in the appropriate register */
 	if (is_rx) {
-		PMD_INIT_LOG(INFO, "Write 0x%x to RX IXGBE stat mapping reg:%d",
+		PMD_INIT_LOG(DEBUG, "Write 0x%x to RX IXGBE stat mapping reg:%d",
 			     stat_mappings->rqsmr[n], n);
 		IXGBE_WRITE_REG(hw, IXGBE_RQSMR(n), stat_mappings->rqsmr[n]);
 	}
 	else {
-		PMD_INIT_LOG(INFO, "Write 0x%x to TX IXGBE stat mapping reg:%d",
+		PMD_INIT_LOG(DEBUG, "Write 0x%x to TX IXGBE stat mapping reg:%d",
 			     stat_mappings->tqsm[n], n);
 		IXGBE_WRITE_REG(hw, IXGBE_TQSM(n), stat_mappings->tqsm[n]);
 	}
@@ -751,7 +751,7 @@  eth_ixgbe_dev_init(struct rte_eth_dev *eth_dev)
 			ixgbe_set_tx_function(eth_dev, txq);
 		} else {
 			/* Use default TX function if we get here */
-			PMD_INIT_LOG(INFO, "No TX queues configured yet. "
+			PMD_INIT_LOG(DEBUG, "No TX queues configured yet. "
 			                   "Using default TX function.");
 		}
 
@@ -2275,7 +2275,7 @@  ixgbe_dev_interrupt_get_status(struct rte_eth_dev *dev)
 
 	/* read-on-clear nic registers here */
 	eicr = IXGBE_READ_REG(hw, IXGBE_EICR);
-	PMD_DRV_LOG(INFO, "eicr %x", eicr);
+	PMD_DRV_LOG(DEBUG, "eicr %x", eicr);
 
 	intr->flags = 0;
 	if (eicr & IXGBE_EICR_LSC) {
diff --git a/lib/librte_pmd_ixgbe/ixgbe_rxtx.c b/lib/librte_pmd_ixgbe/ixgbe_rxtx.c
index 57c9430..08830bf 100644
--- a/lib/librte_pmd_ixgbe/ixgbe_rxtx.c
+++ b/lib/librte_pmd_ixgbe/ixgbe_rxtx.c
@@ -1871,23 +1871,23 @@  ixgbe_set_tx_function(struct rte_eth_dev *dev, struct ixgbe_tx_queue *txq)
 	/* Use a simple Tx queue (no offloads, no multi segs) if possible */
 	if (((txq->txq_flags & IXGBE_SIMPLE_FLAGS) == IXGBE_SIMPLE_FLAGS)
 			&& (txq->tx_rs_thresh >= RTE_PMD_IXGBE_TX_MAX_BURST)) {
-		PMD_INIT_LOG(INFO, "Using simple tx code path");
+		PMD_INIT_LOG(DEBUG, "Using simple tx code path");
 #ifdef RTE_IXGBE_INC_VECTOR
 		if (txq->tx_rs_thresh <= RTE_IXGBE_TX_MAX_FREE_BUF_SZ &&
 				(rte_eal_process_type() != RTE_PROC_PRIMARY ||
 					ixgbe_txq_vec_setup(txq) == 0)) {
-			PMD_INIT_LOG(INFO, "Vector tx enabled.");
+			PMD_INIT_LOG(DEBUG, "Vector tx enabled.");
 			dev->tx_pkt_burst = ixgbe_xmit_pkts_vec;
 		} else
 #endif
 		dev->tx_pkt_burst = ixgbe_xmit_pkts_simple;
 	} else {
-		PMD_INIT_LOG(INFO, "Using full-featured tx code path");
-		PMD_INIT_LOG(INFO,
+		PMD_INIT_LOG(DEBUG, "Using full-featured tx code path");
+		PMD_INIT_LOG(DEBUG,
 				" - txq_flags = %lx " "[IXGBE_SIMPLE_FLAGS=%lx]",
 				(unsigned long)txq->txq_flags,
 				(unsigned long)IXGBE_SIMPLE_FLAGS);
-		PMD_INIT_LOG(INFO,
+		PMD_INIT_LOG(DEBUG,
 				" - tx_rs_thresh = %lu " "[RTE_PMD_IXGBE_TX_MAX_BURST=%lu]",
 				(unsigned long)txq->tx_rs_thresh,
 				(unsigned long)RTE_PMD_IXGBE_TX_MAX_BURST);
@@ -3761,11 +3761,11 @@  void ixgbe_set_rx_function(struct rte_eth_dev *dev)
 	 */
 	if (dev->data->lro) {
 		if (adapter->rx_bulk_alloc_allowed) {
-			PMD_INIT_LOG(INFO, "LRO is requested. Using a bulk "
+			PMD_INIT_LOG(DEBUG, "LRO is requested. Using a bulk "
 					   "allocation version");
 			dev->rx_pkt_burst = ixgbe_recv_pkts_lro_bulk_alloc;
 		} else {
-			PMD_INIT_LOG(INFO, "LRO is requested. Using a single "
+			PMD_INIT_LOG(DEBUG, "LRO is requested. Using a single "
 					   "allocation version");
 			dev->rx_pkt_burst = ixgbe_recv_pkts_lro_single_alloc;
 		}
@@ -3781,7 +3781,7 @@  void ixgbe_set_rx_function(struct rte_eth_dev *dev)
 
 			dev->rx_pkt_burst = ixgbe_recv_scattered_pkts_vec;
 		} else if (adapter->rx_bulk_alloc_allowed) {
-			PMD_INIT_LOG(INFO, "Using a Scattered with bulk "
+			PMD_INIT_LOG(DEBUG, "Using a Scattered with bulk "
 					   "allocation callback (port=%d).",
 				     dev->data->port_id);
 			dev->rx_pkt_burst = ixgbe_recv_pkts_lro_bulk_alloc;
@@ -3803,7 +3803,7 @@  void ixgbe_set_rx_function(struct rte_eth_dev *dev)
 	 *    - Single buffer allocation (the simplest one)
 	 */
 	} else if (adapter->rx_vec_allowed) {
-		PMD_INIT_LOG(INFO, "Vector rx enabled, please make sure RX "
+		PMD_INIT_LOG(DEBUG, "Vector rx enabled, please make sure RX "
 				   "burst size no less than 32.");
 
 		dev->rx_pkt_burst = ixgbe_recv_pkts_vec;
@@ -3961,7 +3961,7 @@  ixgbe_set_rsc(struct rte_eth_dev *dev)
 
 	dev->data->lro = 1;
 
-	PMD_INIT_LOG(INFO, "enabling LRO mode");
+	PMD_INIT_LOG(DEBUG, "enabling LRO mode");
 
 	return 0;
 }