ethdev: decrease log level for successful API

Message ID 1533213223-24028-1-git-send-email-ktraynor@redhat.com (mailing list archive)
State Superseded, archived
Headers
Series ethdev: decrease log level for successful API |

Checks

Context Check Description
ci/Intel-compilation success Compilation OK

Commit Message

Kevin Traynor Aug. 2, 2018, 12:33 p.m. UTC
  Change log level of messages from ERR back to DEBUG where
existing API indicates that the condition is a success.

This means applications using the API in its current form will
not get new ERR logs.

Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to dynamic")

Signed-off-by: Kevin Traynor <ktraynor@redhat.com>
---
 lib/librte_ethdev/rte_ethdev.c | 12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)
  

Comments

Andrew Rybchenko Aug. 2, 2018, 12:59 p.m. UTC | #1
On 02.08.2018 15:33, Kevin Traynor wrote:
> Change log level of messages from ERR back to DEBUG where
> existing API indicates that the condition is a success.
>
> This means applications using the API in its current form will
> not get new ERR logs.
>
> Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to dynamic")
>
> Signed-off-by: Kevin Traynor <ktraynor@redhat.com>
> ---
>   lib/librte_ethdev/rte_ethdev.c | 12 ++++++------
>   1 file changed, 6 insertions(+), 6 deletions(-)
>
> diff --git a/lib/librte_ethdev/rte_ethdev.c b/lib/librte_ethdev/rte_ethdev.c
> index c7ab157..16656d2 100644
> --- a/lib/librte_ethdev/rte_ethdev.c
> +++ b/lib/librte_ethdev/rte_ethdev.c
> @@ -797,5 +797,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->rx_queue_state[rx_queue_id] != RTE_ETH_QUEUE_STATE_STOPPED) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Queue %"PRIu16" of device with port_id=%"PRIu16" already started\n",
>   			rx_queue_id, port_id);
> @@ -824,5 +824,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->rx_queue_state[rx_queue_id] == RTE_ETH_QUEUE_STATE_STOPPED) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Queue %"PRIu16" of device with port_id=%"PRIu16" already stopped\n",
>   			rx_queue_id, port_id);
> @@ -857,5 +857,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->tx_queue_state[tx_queue_id] != RTE_ETH_QUEUE_STATE_STOPPED) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Queue %"PRIu16" of device with port_id=%"PRIu16" already started\n",
>   			tx_queue_id, port_id);
> @@ -882,5 +882,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->tx_queue_state[tx_queue_id] == RTE_ETH_QUEUE_STATE_STOPPED) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Queue %"PRIu16" of device with port_id=%"PRIu16" already stopped\n",
>   			tx_queue_id, port_id);
> @@ -1287,5 +1287,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->dev_started != 0) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Device with port_id=%"PRIu16" already started\n",
>   			port_id);
> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->dev_started == 0) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Device with port_id=%"PRIu16" already stopped\n",
>   			port_id);

I would suggest to use WARNING here. Yes, it is not an error since 
nothing bad has
happened and we handle duplicate stop and duplicate start,
but I think it is bad that (buggy?) application does it. Making it debug 
we simply
hide it too much.
  
Andrew Rybchenko Aug. 2, 2018, 12:59 p.m. UTC | #2
On 02.08.2018 15:33, Kevin Traynor wrote:
> Change log level of messages from ERR back to DEBUG where
> existing API indicates that the condition is a success.
>
> This means applications using the API in its current form will
> not get new ERR logs.
>
> Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to dynamic")
>
> Signed-off-by: Kevin Traynor <ktraynor@redhat.com>
> ---
>   lib/librte_ethdev/rte_ethdev.c | 12 ++++++------
>   1 file changed, 6 insertions(+), 6 deletions(-)
>
> diff --git a/lib/librte_ethdev/rte_ethdev.c b/lib/librte_ethdev/rte_ethdev.c
> index c7ab157..16656d2 100644
> --- a/lib/librte_ethdev/rte_ethdev.c
> +++ b/lib/librte_ethdev/rte_ethdev.c
> @@ -797,5 +797,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->rx_queue_state[rx_queue_id] != RTE_ETH_QUEUE_STATE_STOPPED) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Queue %"PRIu16" of device with port_id=%"PRIu16" already started\n",
>   			rx_queue_id, port_id);
> @@ -824,5 +824,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->rx_queue_state[rx_queue_id] == RTE_ETH_QUEUE_STATE_STOPPED) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Queue %"PRIu16" of device with port_id=%"PRIu16" already stopped\n",
>   			rx_queue_id, port_id);
> @@ -857,5 +857,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->tx_queue_state[tx_queue_id] != RTE_ETH_QUEUE_STATE_STOPPED) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Queue %"PRIu16" of device with port_id=%"PRIu16" already started\n",
>   			tx_queue_id, port_id);
> @@ -882,5 +882,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->tx_queue_state[tx_queue_id] == RTE_ETH_QUEUE_STATE_STOPPED) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Queue %"PRIu16" of device with port_id=%"PRIu16" already stopped\n",
>   			tx_queue_id, port_id);
> @@ -1287,5 +1287,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->dev_started != 0) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Device with port_id=%"PRIu16" already started\n",
>   			port_id);
> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>   
>   	if (dev->data->dev_started == 0) {
> -		RTE_ETHDEV_LOG(ERR,
> +		RTE_ETHDEV_LOG(DEBUG,
>   			"Device with port_id=%"PRIu16" already stopped\n",
>   			port_id);

I would suggest to use WARNING here. Yes, it is not an error since 
nothing bad has
happened and we handle duplicate stop and duplicate start,
but I think it is bad that (buggy?) application does it. Making it debug 
we simply
hide it too much.
  
Kevin Traynor Aug. 2, 2018, 1:35 p.m. UTC | #3
On 08/02/2018 01:59 PM, Andrew Rybchenko wrote:
> On 02.08.2018 15:33, Kevin Traynor wrote:
>> Change log level of messages from ERR back to DEBUG where
>> existing API indicates that the condition is a success.
>>
>> This means applications using the API in its current form will
>> not get new ERR logs.
>>
>> Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to dynamic")
>>
>> Signed-off-by: Kevin Traynor <ktraynor@redhat.com>
>> ---
>>   lib/librte_ethdev/rte_ethdev.c | 12 ++++++------
>>   1 file changed, 6 insertions(+), 6 deletions(-)
>>
>> diff --git a/lib/librte_ethdev/rte_ethdev.c
>> b/lib/librte_ethdev/rte_ethdev.c
>> index c7ab157..16656d2 100644
>> --- a/lib/librte_ethdev/rte_ethdev.c
>> +++ b/lib/librte_ethdev/rte_ethdev.c
>> @@ -797,5 +797,5 @@ struct rte_eth_dev *
>>         if (dev->data->rx_queue_state[rx_queue_id] !=
>> RTE_ETH_QUEUE_STATE_STOPPED) {
>> -        RTE_ETHDEV_LOG(ERR,
>> +        RTE_ETHDEV_LOG(DEBUG,
>>               "Queue %"PRIu16" of device with port_id=%"PRIu16"
>> already started\n",
>>               rx_queue_id, port_id);
>> @@ -824,5 +824,5 @@ struct rte_eth_dev *
>>         if (dev->data->rx_queue_state[rx_queue_id] ==
>> RTE_ETH_QUEUE_STATE_STOPPED) {
>> -        RTE_ETHDEV_LOG(ERR,
>> +        RTE_ETHDEV_LOG(DEBUG,
>>               "Queue %"PRIu16" of device with port_id=%"PRIu16"
>> already stopped\n",
>>               rx_queue_id, port_id);
>> @@ -857,5 +857,5 @@ struct rte_eth_dev *
>>         if (dev->data->tx_queue_state[tx_queue_id] !=
>> RTE_ETH_QUEUE_STATE_STOPPED) {
>> -        RTE_ETHDEV_LOG(ERR,
>> +        RTE_ETHDEV_LOG(DEBUG,
>>               "Queue %"PRIu16" of device with port_id=%"PRIu16"
>> already started\n",
>>               tx_queue_id, port_id);
>> @@ -882,5 +882,5 @@ struct rte_eth_dev *
>>         if (dev->data->tx_queue_state[tx_queue_id] ==
>> RTE_ETH_QUEUE_STATE_STOPPED) {
>> -        RTE_ETHDEV_LOG(ERR,
>> +        RTE_ETHDEV_LOG(DEBUG,
>>               "Queue %"PRIu16" of device with port_id=%"PRIu16"
>> already stopped\n",
>>               tx_queue_id, port_id);
>> @@ -1287,5 +1287,5 @@ struct rte_eth_dev *
>>         if (dev->data->dev_started != 0) {
>> -        RTE_ETHDEV_LOG(ERR,
>> +        RTE_ETHDEV_LOG(DEBUG,
>>               "Device with port_id=%"PRIu16" already started\n",
>>               port_id);
>> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>>         if (dev->data->dev_started == 0) {
>> -        RTE_ETHDEV_LOG(ERR,
>> +        RTE_ETHDEV_LOG(DEBUG,
>>               "Device with port_id=%"PRIu16" already stopped\n",
>>               port_id);
> 
> I would suggest to use WARNING here. Yes, it is not an error since
> nothing bad has
> happened and we handle duplicate stop and duplicate start,
> but I think it is bad that (buggy?) application does it. Making it debug
> we simply
> hide it too much.
> 

I think an application following the documented API is not bad or buggy.
An application may not maintain some state and always call a stop before
a start etc. in line with the API.

I don't think an API success condition should be changed from a debug
message to anything else. Otherwise, it is trying to flag a warning
about the application which is following the API! It and will just spook
people when they see a new warning.
  
Andrew Rybchenko Aug. 2, 2018, 1:52 p.m. UTC | #4
On 02.08.2018 16:35, Kevin Traynor wrote:
> On 08/02/2018 01:59 PM, Andrew Rybchenko wrote:
>> On 02.08.2018 15:33, Kevin Traynor wrote:
>>> Change log level of messages from ERR back to DEBUG where
>>> existing API indicates that the condition is a success.
>>>
>>> This means applications using the API in its current form will
>>> not get new ERR logs.
>>>
>>> Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to dynamic")
>>>
>>> Signed-off-by: Kevin Traynor <ktraynor@redhat.com>
>>> ---
>>>    lib/librte_ethdev/rte_ethdev.c | 12 ++++++------
>>>    1 file changed, 6 insertions(+), 6 deletions(-)
>>>
>>> diff --git a/lib/librte_ethdev/rte_ethdev.c
>>> b/lib/librte_ethdev/rte_ethdev.c
>>> index c7ab157..16656d2 100644
>>> --- a/lib/librte_ethdev/rte_ethdev.c
>>> +++ b/lib/librte_ethdev/rte_ethdev.c
>>> @@ -797,5 +797,5 @@ struct rte_eth_dev *
>>>          if (dev->data->rx_queue_state[rx_queue_id] !=
>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>> -        RTE_ETHDEV_LOG(ERR,
>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>                "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>> already started\n",
>>>                rx_queue_id, port_id);
>>> @@ -824,5 +824,5 @@ struct rte_eth_dev *
>>>          if (dev->data->rx_queue_state[rx_queue_id] ==
>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>> -        RTE_ETHDEV_LOG(ERR,
>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>                "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>> already stopped\n",
>>>                rx_queue_id, port_id);
>>> @@ -857,5 +857,5 @@ struct rte_eth_dev *
>>>          if (dev->data->tx_queue_state[tx_queue_id] !=
>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>> -        RTE_ETHDEV_LOG(ERR,
>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>                "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>> already started\n",
>>>                tx_queue_id, port_id);
>>> @@ -882,5 +882,5 @@ struct rte_eth_dev *
>>>          if (dev->data->tx_queue_state[tx_queue_id] ==
>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>> -        RTE_ETHDEV_LOG(ERR,
>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>                "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>> already stopped\n",
>>>                tx_queue_id, port_id);
>>> @@ -1287,5 +1287,5 @@ struct rte_eth_dev *
>>>          if (dev->data->dev_started != 0) {
>>> -        RTE_ETHDEV_LOG(ERR,
>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>                "Device with port_id=%"PRIu16" already started\n",
>>>                port_id);
>>> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>>>          if (dev->data->dev_started == 0) {
>>> -        RTE_ETHDEV_LOG(ERR,
>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>                "Device with port_id=%"PRIu16" already stopped\n",
>>>                port_id);
>> I would suggest to use WARNING here. Yes, it is not an error since
>> nothing bad has
>> happened and we handle duplicate stop and duplicate start,
>> but I think it is bad that (buggy?) application does it. Making it debug
>> we simply
>> hide it too much.
>>
> I think an application following the documented API is not bad or buggy.

I've failed to find the place were it is documented that device/queue
may be stopped/started twice. Could you point out?
Yes, return value 0 means success, but it is a separate thing.

> An application may not maintain some state and always call a stop before
> a start etc. in line with the API.
>
> I don't think an API success condition should be changed from a debug
> message to anything else. Otherwise, it is trying to flag a warning
> about the application which is following the API! It and will just spook
> people when they see a new warning.
  
Kevin Traynor Aug. 2, 2018, 2:09 p.m. UTC | #5
On 08/02/2018 02:52 PM, Andrew Rybchenko wrote:
> On 02.08.2018 16:35, Kevin Traynor wrote:
>> On 08/02/2018 01:59 PM, Andrew Rybchenko wrote:
>>> On 02.08.2018 15:33, Kevin Traynor wrote:
>>>> Change log level of messages from ERR back to DEBUG where
>>>> existing API indicates that the condition is a success.
>>>>
>>>> This means applications using the API in its current form will
>>>> not get new ERR logs.
>>>>
>>>> Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to
>>>> dynamic")
>>>>
>>>> Signed-off-by: Kevin Traynor <ktraynor@redhat.com>
>>>> ---
>>>>    lib/librte_ethdev/rte_ethdev.c | 12 ++++++------
>>>>    1 file changed, 6 insertions(+), 6 deletions(-)
>>>>
>>>> diff --git a/lib/librte_ethdev/rte_ethdev.c
>>>> b/lib/librte_ethdev/rte_ethdev.c
>>>> index c7ab157..16656d2 100644
>>>> --- a/lib/librte_ethdev/rte_ethdev.c
>>>> +++ b/lib/librte_ethdev/rte_ethdev.c
>>>> @@ -797,5 +797,5 @@ struct rte_eth_dev *
>>>>          if (dev->data->rx_queue_state[rx_queue_id] !=
>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>> -        RTE_ETHDEV_LOG(ERR,
>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>                "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>> already started\n",
>>>>                rx_queue_id, port_id);
>>>> @@ -824,5 +824,5 @@ struct rte_eth_dev *
>>>>          if (dev->data->rx_queue_state[rx_queue_id] ==
>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>> -        RTE_ETHDEV_LOG(ERR,
>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>                "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>> already stopped\n",
>>>>                rx_queue_id, port_id);
>>>> @@ -857,5 +857,5 @@ struct rte_eth_dev *
>>>>          if (dev->data->tx_queue_state[tx_queue_id] !=
>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>> -        RTE_ETHDEV_LOG(ERR,
>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>                "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>> already started\n",
>>>>                tx_queue_id, port_id);
>>>> @@ -882,5 +882,5 @@ struct rte_eth_dev *
>>>>          if (dev->data->tx_queue_state[tx_queue_id] ==
>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>> -        RTE_ETHDEV_LOG(ERR,
>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>                "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>> already stopped\n",
>>>>                tx_queue_id, port_id);
>>>> @@ -1287,5 +1287,5 @@ struct rte_eth_dev *
>>>>          if (dev->data->dev_started != 0) {
>>>> -        RTE_ETHDEV_LOG(ERR,
>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>                "Device with port_id=%"PRIu16" already started\n",
>>>>                port_id);
>>>> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>>>>          if (dev->data->dev_started == 0) {
>>>> -        RTE_ETHDEV_LOG(ERR,
>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>                "Device with port_id=%"PRIu16" already stopped\n",
>>>>                port_id);
>>> I would suggest to use WARNING here. Yes, it is not an error since
>>> nothing bad has
>>> happened and we handle duplicate stop and duplicate start,
>>> but I think it is bad that (buggy?) application does it. Making it debug
>>> we simply
>>> hide it too much.
>>>
>> I think an application following the documented API is not bad or buggy.
> 
> I've failed to find the place were it is documented that device/queue
> may be stopped/started twice. Could you point out?
> Yes, return value 0 means success, but it is a separate thing.
> 

I was commenting directly on the API and it's documentation e.g. below
for dev start. I'm not aware of other documentation specifying how it
can/cannot be called.

 * @return
 *   - 0: Success, Ethernet device started.
 *   - <0: Error code of the driver device start function.
 */
int rte_eth_dev_start(uint16_t port_id);

int
rte_eth_dev_start(uint16_t port_id)
{
...
	if (dev->data->dev_started != 0) {
		RTE_ETHDEV_LOG(DEBUG,
			"Device with port_id=%"PRIu16" already started\n",
			port_id);
		return 0;
	}
...
}


>> An application may not maintain some state and always call a stop before
>> a start etc. in line with the API.
>>
>> I don't think an API success condition should be changed from a debug
>> message to anything else. Otherwise, it is trying to flag a warning
>> about the application which is following the API! It and will just spook
>> people when they see a new warning.
>
  
Andrew Rybchenko Aug. 2, 2018, 2:41 p.m. UTC | #6
On 02.08.2018 17:09, Kevin Traynor wrote:
> On 08/02/2018 02:52 PM, Andrew Rybchenko wrote:
>> On 02.08.2018 16:35, Kevin Traynor wrote:
>>> On 08/02/2018 01:59 PM, Andrew Rybchenko wrote:
>>>> On 02.08.2018 15:33, Kevin Traynor wrote:
>>>>> Change log level of messages from ERR back to DEBUG where
>>>>> existing API indicates that the condition is a success.
>>>>>
>>>>> This means applications using the API in its current form will
>>>>> not get new ERR logs.
>>>>>
>>>>> Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to
>>>>> dynamic")
>>>>>
>>>>> Signed-off-by: Kevin Traynor <ktraynor@redhat.com>
>>>>> ---
>>>>>     lib/librte_ethdev/rte_ethdev.c | 12 ++++++------
>>>>>     1 file changed, 6 insertions(+), 6 deletions(-)
>>>>>
>>>>> diff --git a/lib/librte_ethdev/rte_ethdev.c
>>>>> b/lib/librte_ethdev/rte_ethdev.c
>>>>> index c7ab157..16656d2 100644
>>>>> --- a/lib/librte_ethdev/rte_ethdev.c
>>>>> +++ b/lib/librte_ethdev/rte_ethdev.c
>>>>> @@ -797,5 +797,5 @@ struct rte_eth_dev *
>>>>>           if (dev->data->rx_queue_state[rx_queue_id] !=
>>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>                 "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>>> already started\n",
>>>>>                 rx_queue_id, port_id);
>>>>> @@ -824,5 +824,5 @@ struct rte_eth_dev *
>>>>>           if (dev->data->rx_queue_state[rx_queue_id] ==
>>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>                 "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>>> already stopped\n",
>>>>>                 rx_queue_id, port_id);
>>>>> @@ -857,5 +857,5 @@ struct rte_eth_dev *
>>>>>           if (dev->data->tx_queue_state[tx_queue_id] !=
>>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>                 "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>>> already started\n",
>>>>>                 tx_queue_id, port_id);
>>>>> @@ -882,5 +882,5 @@ struct rte_eth_dev *
>>>>>           if (dev->data->tx_queue_state[tx_queue_id] ==
>>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>                 "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>>> already stopped\n",
>>>>>                 tx_queue_id, port_id);
>>>>> @@ -1287,5 +1287,5 @@ struct rte_eth_dev *
>>>>>           if (dev->data->dev_started != 0) {
>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>                 "Device with port_id=%"PRIu16" already started\n",
>>>>>                 port_id);
>>>>> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>>>>>           if (dev->data->dev_started == 0) {
>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>                 "Device with port_id=%"PRIu16" already stopped\n",
>>>>>                 port_id);
>>>> I would suggest to use WARNING here. Yes, it is not an error since
>>>> nothing bad has
>>>> happened and we handle duplicate stop and duplicate start,
>>>> but I think it is bad that (buggy?) application does it. Making it debug
>>>> we simply
>>>> hide it too much.
>>>>
>>> I think an application following the documented API is not bad or buggy.
>> I've failed to find the place were it is documented that device/queue
>> may be stopped/started twice. Could you point out?
>> Yes, return value 0 means success, but it is a separate thing.
>>
> I was commenting directly on the API and it's documentation e.g. below
> for dev start. I'm not aware of other documentation specifying how it
> can/cannot be called.

I would not say so. "0: Success. Ethernet device started" means that
function managed to do the job and finally the device is started.

Never-mind it is not that important and already paid to much attention.
I've included in CC other ethdev maintainers (who should be there from
the very beginning). I don't mind if it is acked by other ethdev maintainer
and applied. It is definitely not an error as it is now. Thanks.

>   * @return
>   *   - 0: Success, Ethernet device started.
>   *   - <0: Error code of the driver device start function.
>   */
> int rte_eth_dev_start(uint16_t port_id);
>
> int
> rte_eth_dev_start(uint16_t port_id)
> {
> ...
> 	if (dev->data->dev_started != 0) {
> 		RTE_ETHDEV_LOG(DEBUG,
> 			"Device with port_id=%"PRIu16" already started\n",
> 			port_id);
> 		return 0;
> 	}
> ...
> }
>
>
>>> An application may not maintain some state and always call a stop before
>>> a start etc. in line with the API.
>>>
>>> I don't think an API success condition should be changed from a debug
>>> message to anything else. Otherwise, it is trying to flag a warning
>>> about the application which is following the API! It and will just spook
>>> people when they see a new warning.
  
Kevin Traynor Aug. 2, 2018, 2:52 p.m. UTC | #7
On 08/02/2018 03:41 PM, Andrew Rybchenko wrote:
> On 02.08.2018 17:09, Kevin Traynor wrote:
>> On 08/02/2018 02:52 PM, Andrew Rybchenko wrote:
>>> On 02.08.2018 16:35, Kevin Traynor wrote:
>>>> On 08/02/2018 01:59 PM, Andrew Rybchenko wrote:
>>>>> On 02.08.2018 15:33, Kevin Traynor wrote:
>>>>>> Change log level of messages from ERR back to DEBUG where
>>>>>> existing API indicates that the condition is a success.
>>>>>>
>>>>>> This means applications using the API in its current form will
>>>>>> not get new ERR logs.
>>>>>>
>>>>>> Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to
>>>>>> dynamic")
>>>>>>
>>>>>> Signed-off-by: Kevin Traynor <ktraynor@redhat.com>
>>>>>> ---
>>>>>>     lib/librte_ethdev/rte_ethdev.c | 12 ++++++------
>>>>>>     1 file changed, 6 insertions(+), 6 deletions(-)
>>>>>>
>>>>>> diff --git a/lib/librte_ethdev/rte_ethdev.c
>>>>>> b/lib/librte_ethdev/rte_ethdev.c
>>>>>> index c7ab157..16656d2 100644
>>>>>> --- a/lib/librte_ethdev/rte_ethdev.c
>>>>>> +++ b/lib/librte_ethdev/rte_ethdev.c
>>>>>> @@ -797,5 +797,5 @@ struct rte_eth_dev *
>>>>>>           if (dev->data->rx_queue_state[rx_queue_id] !=
>>>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>>                 "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>>>> already started\n",
>>>>>>                 rx_queue_id, port_id);
>>>>>> @@ -824,5 +824,5 @@ struct rte_eth_dev *
>>>>>>           if (dev->data->rx_queue_state[rx_queue_id] ==
>>>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>>                 "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>>>> already stopped\n",
>>>>>>                 rx_queue_id, port_id);
>>>>>> @@ -857,5 +857,5 @@ struct rte_eth_dev *
>>>>>>           if (dev->data->tx_queue_state[tx_queue_id] !=
>>>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>>                 "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>>>> already started\n",
>>>>>>                 tx_queue_id, port_id);
>>>>>> @@ -882,5 +882,5 @@ struct rte_eth_dev *
>>>>>>           if (dev->data->tx_queue_state[tx_queue_id] ==
>>>>>> RTE_ETH_QUEUE_STATE_STOPPED) {
>>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>>                 "Queue %"PRIu16" of device with port_id=%"PRIu16"
>>>>>> already stopped\n",
>>>>>>                 tx_queue_id, port_id);
>>>>>> @@ -1287,5 +1287,5 @@ struct rte_eth_dev *
>>>>>>           if (dev->data->dev_started != 0) {
>>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>>                 "Device with port_id=%"PRIu16" already started\n",
>>>>>>                 port_id);
>>>>>> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>>>>>>           if (dev->data->dev_started == 0) {
>>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>>                 "Device with port_id=%"PRIu16" already stopped\n",
>>>>>>                 port_id);
>>>>> I would suggest to use WARNING here. Yes, it is not an error since
>>>>> nothing bad has
>>>>> happened and we handle duplicate stop and duplicate start,
>>>>> but I think it is bad that (buggy?) application does it. Making it
>>>>> debug
>>>>> we simply
>>>>> hide it too much.
>>>>>
>>>> I think an application following the documented API is not bad or
>>>> buggy.
>>> I've failed to find the place were it is documented that device/queue
>>> may be stopped/started twice. Could you point out?
>>> Yes, return value 0 means success, but it is a separate thing.
>>>
>> I was commenting directly on the API and it's documentation e.g. below
>> for dev start. I'm not aware of other documentation specifying how it
>> can/cannot be called.
> 
> I would not say so. "0: Success. Ethernet device started" means that
> function managed to do the job and finally the device is started.
> 
> Never-mind it is not that important and already paid to much attention.
> I've included in CC other ethdev maintainers (who should be there from
> the very beginning). I don't mind if it is acked by other ethdev maintainer
> and applied. It is definitely not an error as it is now. Thanks.
> 

Sure, sounds good - I'm glad we agree on something :-) I'll leave it for
a day and can re-spin tomorrow.

thanks,
Kevin.

>>   * @return
>>   *   - 0: Success, Ethernet device started.
>>   *   - <0: Error code of the driver device start function.
>>   */
>> int rte_eth_dev_start(uint16_t port_id);
>>
>> int
>> rte_eth_dev_start(uint16_t port_id)
>> {
>> ...
>>     if (dev->data->dev_started != 0) {
>>         RTE_ETHDEV_LOG(DEBUG,
>>             "Device with port_id=%"PRIu16" already started\n",
>>             port_id);
>>         return 0;
>>     }
>> ...
>> }
>>
>>
>>>> An application may not maintain some state and always call a stop
>>>> before
>>>> a start etc. in line with the API.
>>>>
>>>> I don't think an API success condition should be changed from a debug
>>>> message to anything else. Otherwise, it is trying to flag a warning
>>>> about the application which is following the API! It and will just
>>>> spook
>>>> people when they see a new warning.
>
  
Stephen Hemminger Aug. 2, 2018, 3:14 p.m. UTC | #8
On Thu,  2 Aug 2018 13:33:43 +0100
Kevin Traynor <ktraynor@redhat.com> wrote:

> Change log level of messages from ERR back to DEBUG where
> existing API indicates that the condition is a success.
> 
> This means applications using the API in its current form will
> not get new ERR logs.
> 
> Fixes: bea1e0c70cfc ("ethdev: convert static log type usage to dynamic")

The expectations about level come from syslog:

       LOG_ERR        error conditions

       LOG_WARNING    warning conditions

       LOG_NOTICE     normal, but significant, condition

       LOG_INFO       informational message

       LOG_DEBUG      debug-level message

Therefore messages where an API did something wrong should be NOTICE
and messages where an API's normal action was successful should be
INFO or DEBUG.

All the "already XXX" messages should be NOTICE.
  
Thomas Monjalon Aug. 2, 2018, 4:14 p.m. UTC | #9
02/08/2018 16:52, Kevin Traynor:
> On 08/02/2018 03:41 PM, Andrew Rybchenko wrote:
> > On 02.08.2018 17:09, Kevin Traynor wrote:
> >> On 08/02/2018 02:52 PM, Andrew Rybchenko wrote:
> >>> On 02.08.2018 16:35, Kevin Traynor wrote:
> >>>> On 08/02/2018 01:59 PM, Andrew Rybchenko wrote:
> >>>>> On 02.08.2018 15:33, Kevin Traynor wrote:
> >>>>>> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
> >>>>>>           if (dev->data->dev_started == 0) {
> >>>>>> -        RTE_ETHDEV_LOG(ERR,
> >>>>>> +        RTE_ETHDEV_LOG(DEBUG,
> >>>>>>                 "Device with port_id=%"PRIu16" already stopped\n",
> >>>>>>                 port_id);
> >>>>> I would suggest to use WARNING here. Yes, it is not an error since
> >>>>> nothing bad has
> >>>>> happened and we handle duplicate stop and duplicate start,
> >>>>> but I think it is bad that (buggy?) application does it. Making it
> >>>>> debug
> >>>>> we simply
> >>>>> hide it too much.
> >>>>>
> >>>> I think an application following the documented API is not bad or
> >>>> buggy.
> >>> I've failed to find the place were it is documented that device/queue
> >>> may be stopped/started twice. Could you point out?
> >>> Yes, return value 0 means success, but it is a separate thing.
> >>>
> >> I was commenting directly on the API and it's documentation e.g. below
> >> for dev start. I'm not aware of other documentation specifying how it
> >> can/cannot be called.
> > 
> > I would not say so. "0: Success. Ethernet device started" means that
> > function managed to do the job and finally the device is started.
> > 
> > Never-mind it is not that important and already paid to much attention.
> > I've included in CC other ethdev maintainers (who should be there from
> > the very beginning). I don't mind if it is acked by other ethdev maintainer
> > and applied. It is definitely not an error as it is now. Thanks.
> > 
> 
> Sure, sounds good - I'm glad we agree on something :-) I'll leave it for
> a day and can re-spin tomorrow.

I would like to give an opinion, but unfortunately it's hard to decide.
For sure, it should not be a WARNING level (used for non-fatal errors).
What else do we have? NOTICE, INFO and DEBUG.
I think it can be INFO.
  
Andrew Rybchenko Aug. 2, 2018, 6:01 p.m. UTC | #10
On 02.08.2018 19:14, Thomas Monjalon wrote:
> 02/08/2018 16:52, Kevin Traynor:
>> On 08/02/2018 03:41 PM, Andrew Rybchenko wrote:
>>> On 02.08.2018 17:09, Kevin Traynor wrote:
>>>> On 08/02/2018 02:52 PM, Andrew Rybchenko wrote:
>>>>> On 02.08.2018 16:35, Kevin Traynor wrote:
>>>>>> On 08/02/2018 01:59 PM, Andrew Rybchenko wrote:
>>>>>>> On 02.08.2018 15:33, Kevin Traynor wrote:
>>>>>>>> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>>>>>>>>            if (dev->data->dev_started == 0) {
>>>>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>>>>                  "Device with port_id=%"PRIu16" already stopped\n",
>>>>>>>>                  port_id);
>>>>>>> I would suggest to use WARNING here. Yes, it is not an error since
>>>>>>> nothing bad has
>>>>>>> happened and we handle duplicate stop and duplicate start,
>>>>>>> but I think it is bad that (buggy?) application does it. Making it
>>>>>>> debug
>>>>>>> we simply
>>>>>>> hide it too much.
>>>>>>>
>>>>>> I think an application following the documented API is not bad or
>>>>>> buggy.
>>>>> I've failed to find the place were it is documented that device/queue
>>>>> may be stopped/started twice. Could you point out?
>>>>> Yes, return value 0 means success, but it is a separate thing.
>>>>>
>>>> I was commenting directly on the API and it's documentation e.g. below
>>>> for dev start. I'm not aware of other documentation specifying how it
>>>> can/cannot be called.
>>> I would not say so. "0: Success. Ethernet device started" means that
>>> function managed to do the job and finally the device is started.
>>>
>>> Never-mind it is not that important and already paid to much attention.
>>> I've included in CC other ethdev maintainers (who should be there from
>>> the very beginning). I don't mind if it is acked by other ethdev maintainer
>>> and applied. It is definitely not an error as it is now. Thanks.
>>>
>> Sure, sounds good - I'm glad we agree on something :-) I'll leave it for
>> a day and can re-spin tomorrow.
> I would like to give an opinion, but unfortunately it's hard to decide.
> For sure, it should not be a WARNING level (used for non-fatal errors).
> What else do we have? NOTICE, INFO and DEBUG.
> I think it can be INFO.

So, we have ERR (now), WARNING (my initial suggestion), NOTICE
(by Stephen), INFO (by Thomas) and DEBUG (by Kevin)  :)

If it is not treated as an error in application behaviour, I agree that my
suggestion of WARNING is not suitable. Typically NOTICE is the default
log level and if we consider such behaviour of apps correct, it should
be INFO to be silent by default. I really don't like DEBUG since these
messages are still important and could be simply lost in DEBUG
which could to be very-very verbose.
  
Kevin Traynor Aug. 2, 2018, 6:27 p.m. UTC | #11
On 08/02/2018 07:01 PM, Andrew Rybchenko wrote:
> On 02.08.2018 19:14, Thomas Monjalon wrote:
>> 02/08/2018 16:52, Kevin Traynor:
>>> On 08/02/2018 03:41 PM, Andrew Rybchenko wrote:
>>>> On 02.08.2018 17:09, Kevin Traynor wrote:
>>>>> On 08/02/2018 02:52 PM, Andrew Rybchenko wrote:
>>>>>> On 02.08.2018 16:35, Kevin Traynor wrote:
>>>>>>> On 08/02/2018 01:59 PM, Andrew Rybchenko wrote:
>>>>>>>> On 02.08.2018 15:33, Kevin Traynor wrote:
>>>>>>>>> @@ -1319,5 +1319,5 @@ struct rte_eth_dev *
>>>>>>>>>            if (dev->data->dev_started == 0) {
>>>>>>>>> -        RTE_ETHDEV_LOG(ERR,
>>>>>>>>> +        RTE_ETHDEV_LOG(DEBUG,
>>>>>>>>>                  "Device with port_id=%"PRIu16" already
>>>>>>>>> stopped\n",
>>>>>>>>>                  port_id);
>>>>>>>> I would suggest to use WARNING here. Yes, it is not an error since
>>>>>>>> nothing bad has
>>>>>>>> happened and we handle duplicate stop and duplicate start,
>>>>>>>> but I think it is bad that (buggy?) application does it. Making it
>>>>>>>> debug
>>>>>>>> we simply
>>>>>>>> hide it too much.
>>>>>>>>
>>>>>>> I think an application following the documented API is not bad or
>>>>>>> buggy.
>>>>>> I've failed to find the place were it is documented that device/queue
>>>>>> may be stopped/started twice. Could you point out?
>>>>>> Yes, return value 0 means success, but it is a separate thing.
>>>>>>
>>>>> I was commenting directly on the API and it's documentation e.g. below
>>>>> for dev start. I'm not aware of other documentation specifying how it
>>>>> can/cannot be called.
>>>> I would not say so. "0: Success. Ethernet device started" means that
>>>> function managed to do the job and finally the device is started.
>>>>
>>>> Never-mind it is not that important and already paid to much attention.
>>>> I've included in CC other ethdev maintainers (who should be there from
>>>> the very beginning). I don't mind if it is acked by other ethdev
>>>> maintainer
>>>> and applied. It is definitely not an error as it is now. Thanks.
>>>>
>>> Sure, sounds good - I'm glad we agree on something :-) I'll leave it for
>>> a day and can re-spin tomorrow.
>> I would like to give an opinion, but unfortunately it's hard to decide.
>> For sure, it should not be a WARNING level (used for non-fatal errors).
>> What else do we have? NOTICE, INFO and DEBUG.
>> I think it can be INFO.
> 
> So, we have ERR (now), WARNING (my initial suggestion), NOTICE
> (by Stephen), INFO (by Thomas) and DEBUG (by Kevin)  :)
> 

Well, we completed the set :-)

> If it is not treated as an error in application behaviour, I agree that my
> suggestion of WARNING is not suitable. Typically NOTICE is the default
> log level and if we consider such behaviour of apps correct, it should
> be INFO to be silent by default. I really don't like DEBUG since these
> messages are still important and could be simply lost in DEBUG
> which could to be very-very verbose.

ok, I'll update and send as INFO before someone suggests adding new log
levels to choose from.
  

Patch

diff --git a/lib/librte_ethdev/rte_ethdev.c b/lib/librte_ethdev/rte_ethdev.c
index c7ab157..16656d2 100644
--- a/lib/librte_ethdev/rte_ethdev.c
+++ b/lib/librte_ethdev/rte_ethdev.c
@@ -797,5 +797,5 @@  struct rte_eth_dev *
 
 	if (dev->data->rx_queue_state[rx_queue_id] != RTE_ETH_QUEUE_STATE_STOPPED) {
-		RTE_ETHDEV_LOG(ERR,
+		RTE_ETHDEV_LOG(DEBUG,
 			"Queue %"PRIu16" of device with port_id=%"PRIu16" already started\n",
 			rx_queue_id, port_id);
@@ -824,5 +824,5 @@  struct rte_eth_dev *
 
 	if (dev->data->rx_queue_state[rx_queue_id] == RTE_ETH_QUEUE_STATE_STOPPED) {
-		RTE_ETHDEV_LOG(ERR,
+		RTE_ETHDEV_LOG(DEBUG,
 			"Queue %"PRIu16" of device with port_id=%"PRIu16" already stopped\n",
 			rx_queue_id, port_id);
@@ -857,5 +857,5 @@  struct rte_eth_dev *
 
 	if (dev->data->tx_queue_state[tx_queue_id] != RTE_ETH_QUEUE_STATE_STOPPED) {
-		RTE_ETHDEV_LOG(ERR,
+		RTE_ETHDEV_LOG(DEBUG,
 			"Queue %"PRIu16" of device with port_id=%"PRIu16" already started\n",
 			tx_queue_id, port_id);
@@ -882,5 +882,5 @@  struct rte_eth_dev *
 
 	if (dev->data->tx_queue_state[tx_queue_id] == RTE_ETH_QUEUE_STATE_STOPPED) {
-		RTE_ETHDEV_LOG(ERR,
+		RTE_ETHDEV_LOG(DEBUG,
 			"Queue %"PRIu16" of device with port_id=%"PRIu16" already stopped\n",
 			tx_queue_id, port_id);
@@ -1287,5 +1287,5 @@  struct rte_eth_dev *
 
 	if (dev->data->dev_started != 0) {
-		RTE_ETHDEV_LOG(ERR,
+		RTE_ETHDEV_LOG(DEBUG,
 			"Device with port_id=%"PRIu16" already started\n",
 			port_id);
@@ -1319,5 +1319,5 @@  struct rte_eth_dev *
 
 	if (dev->data->dev_started == 0) {
-		RTE_ETHDEV_LOG(ERR,
+		RTE_ETHDEV_LOG(DEBUG,
 			"Device with port_id=%"PRIu16" already stopped\n",
 			port_id);