diff mbox series

[net-next,07/11] net: hns3: adds debug messages to identify eth down cause

Message ID 1563938327-9865-8-git-send-email-tanhuazhong@huawei.com
State Changes Requested
Delegated to: David Miller
Headers show
Series net: hns3: some code optimizations & bugfixes & features | expand

Commit Message

tanhuazhong July 24, 2019, 3:18 a.m. UTC
From: Yonglong Liu <liuyonglong@huawei.com>

Some times just see the eth interface have been down/up via
dmesg, but can not know why the eth down. So adds some debug
messages to identify the cause for this.

Signed-off-by: Yonglong Liu <liuyonglong@huawei.com>
Signed-off-by: Peng Li <lipeng321@huawei.com>
Signed-off-by: Huazhong Tan <tanhuazhong@huawei.com>
---
 drivers/net/ethernet/hisilicon/hns3/hns3_enet.c    | 24 ++++++++++++++++++++
 drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c | 26 ++++++++++++++++++++++
 .../net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c | 14 ++++++++++++
 3 files changed, 64 insertions(+)

Comments

Saeed Mahameed July 24, 2019, 7:12 p.m. UTC | #1
On Wed, 2019-07-24 at 11:18 +0800, Huazhong Tan wrote:
> From: Yonglong Liu <liuyonglong@huawei.com>
> 
> Some times just see the eth interface have been down/up via
> dmesg, but can not know why the eth down. So adds some debug
> messages to identify the cause for this.
> 

I really don't like this. your default msg lvl has NETIF_MSG_IFDOWN
turned on .. dumping every single operation that happens on your device
by default to kernel log is too much ! 

We should really consider using trace buffers with well defined
structures for vendor specific events. so we can use bpf filters and
state of the art tools for netdev debugging.

> Signed-off-by: Yonglong Liu <liuyonglong@huawei.com>
> Signed-off-by: Peng Li <lipeng321@huawei.com>
> Signed-off-by: Huazhong Tan <tanhuazhong@huawei.com>
> ---
>  drivers/net/ethernet/hisilicon/hns3/hns3_enet.c    | 24
> ++++++++++++++++++++
>  drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c | 26
> ++++++++++++++++++++++
>  .../net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c | 14 ++++++++++++
>  3 files changed, 64 insertions(+)
> 
> diff --git a/drivers/net/ethernet/hisilicon/hns3/hns3_enet.c
> b/drivers/net/ethernet/hisilicon/hns3/hns3_enet.c
> index 4d58c53..cff5d59 100644
> --- a/drivers/net/ethernet/hisilicon/hns3/hns3_enet.c
> +++ b/drivers/net/ethernet/hisilicon/hns3/hns3_enet.c
> @@ -459,6 +459,10 @@ static int hns3_nic_net_open(struct net_device
> *netdev)
>  		h->ae_algo->ops->set_timer_task(priv->ae_handle, true);
>  
>  	hns3_config_xps(priv);
> +
> +	if (netif_msg_ifup(h))
> +		netdev_info(netdev, "net open\n");
> +
>  	return 0;
>  }
>  
> @@ -519,6 +523,9 @@ static int hns3_nic_net_stop(struct net_device
> *netdev)
>  	if (test_and_set_bit(HNS3_NIC_STATE_DOWN, &priv->state))
>  		return 0;
>  
> +	if (netif_msg_ifdown(h))
> +		netdev_info(netdev, "net stop\n");
> +
>  	if (h->ae_algo->ops->set_timer_task)
>  		h->ae_algo->ops->set_timer_task(priv->ae_handle,
> false);
>  
> @@ -1550,6 +1557,9 @@ static int hns3_setup_tc(struct net_device
> *netdev, void *type_data)
>  	h = hns3_get_handle(netdev);
>  	kinfo = &h->kinfo;
>  
> +	if (netif_msg_ifdown(h))
> +		netdev_info(netdev, "setup tc: num_tc=%d\n", tc);
> +
>  	return (kinfo->dcb_ops && kinfo->dcb_ops->setup_tc) ?
>  		kinfo->dcb_ops->setup_tc(h, tc, prio_tc) : -EOPNOTSUPP;
>  }
> @@ -1593,6 +1603,11 @@ static int hns3_ndo_set_vf_vlan(struct
> net_device *netdev, int vf, u16 vlan,
>  	struct hnae3_handle *h = hns3_get_handle(netdev);
>  	int ret = -EIO;
>  
> +	if (netif_msg_ifdown(h))

why msg_ifdown ? looks like netif_msg_drv is more appropriate, for many
of the cases in this patch.

> +		netdev_info(netdev,
> +			    "set vf vlan: vf=%d, vlan=%d, qos=%d,
> vlan_proto=%d\n",
> +			    vf, vlan, qos, vlan_proto);
> +
>  	if (h->ae_algo->ops->set_vf_vlan_filter)
>  		ret = h->ae_algo->ops->set_vf_vlan_filter(h, vf, vlan,
>  							  qos,
> vlan_proto);
> @@ -1611,6 +1626,10 @@ static int hns3_nic_change_mtu(struct
> net_device *netdev, int new_mtu)
>  	if (!h->ae_algo->ops->set_mtu)
>  		return -EOPNOTSUPP;
>  
> +	if (netif_msg_ifdown(h))
> +		netdev_info(netdev, "change mtu from %d to %d\n",
> +			    netdev->mtu, new_mtu);
> +
>  	ret = h->ae_algo->ops->set_mtu(h, new_mtu);
>  	if (ret)
>  		netdev_err(netdev, "failed to change MTU in hardware
> %d\n",
> @@ -4395,6 +4414,11 @@ int hns3_set_channels(struct net_device
> *netdev,
>  	if (kinfo->rss_size == new_tqp_num)
>  		return 0;
>  
> +	if (netif_msg_ifdown(h))
> +		netdev_info(netdev,
> +			    "set channels: tqp_num=%d, rxfh=%d\n",
> +			    new_tqp_num, rxfh_configured);
> +
>  	ret = hns3_reset_notify(h, HNAE3_DOWN_CLIENT);
>  	if (ret)
>  		return ret;
> diff --git a/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
> b/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
> index e71c92b..edb9845 100644
> --- a/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
> +++ b/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
> @@ -311,6 +311,9 @@ static void hns3_self_test(struct net_device
> *ndev,
>  	if (eth_test->flags != ETH_TEST_FL_OFFLINE)
>  		return;
>  
> +	if (netif_msg_ifdown(h))
> +		netdev_info(ndev, "self test start\n");
> +
>  	st_param[HNAE3_LOOP_APP][0] = HNAE3_LOOP_APP;
>  	st_param[HNAE3_LOOP_APP][1] =
>  			h->flags & HNAE3_SUPPORT_APP_LOOPBACK;
> @@ -374,6 +377,9 @@ static void hns3_self_test(struct net_device
> *ndev,
>  
>  	if (if_running)
>  		ndev->netdev_ops->ndo_open(ndev);
> +
> +	if (netif_msg_ifdown(h))
> +		netdev_info(ndev, "self test end\n");
>  }
>  
>  static int hns3_get_sset_count(struct net_device *netdev, int
> stringset)
> @@ -604,6 +610,11 @@ static int hns3_set_pauseparam(struct net_device
> *netdev,
>  {
>  	struct hnae3_handle *h = hns3_get_handle(netdev);
>  
> +	if (netif_msg_ifdown(h))
> +		netdev_info(netdev,
> +			    "set pauseparam: autoneg=%d, rx:%d,
> tx:%d\n",
> +			    param->autoneg, param->rx_pause, param-
> >tx_pause);
> +
>  	if (h->ae_algo->ops->set_pauseparam)
>  		return h->ae_algo->ops->set_pauseparam(h, param-
> >autoneg,
>  						       param->rx_pause,
> @@ -743,6 +754,13 @@ static int hns3_set_link_ksettings(struct
> net_device *netdev,
>  	if (cmd->base.speed == SPEED_1000 && cmd->base.duplex ==
> DUPLEX_HALF)
>  		return -EINVAL;
>  
> +	if (netif_msg_ifdown(handle))
> +		netdev_info(netdev,
> +			    "set link(%s): autoneg=%d, speed=%d,
> duplex=%d\n",
> +			    netdev->phydev ? "phy" : "mac",
> +			    cmd->base.autoneg, cmd->base.speed,
> +			    cmd->base.duplex);
> +
>  	/* Only support ksettings_set for netdev with phy attached for
> now */
>  	if (netdev->phydev)
>  		return phy_ethtool_ksettings_set(netdev->phydev, cmd);
> @@ -984,6 +1002,10 @@ static int hns3_nway_reset(struct net_device
> *netdev)
>  		return -EINVAL;
>  	}
>  
> +	if (netif_msg_ifdown(handle))
> +		netdev_info(netdev, "nway reset (using %s)\n",
> +			    phy ? "phy" : "mac");
> +
>  	if (phy)
>  		return genphy_restart_aneg(phy);
>  
> @@ -1308,6 +1330,10 @@ static int hns3_set_fecparam(struct net_device
> *netdev,
>  	if (!ops->set_fec)
>  		return -EOPNOTSUPP;
>  	fec_mode = eth_to_loc_fec(fec->fec);
> +
> +	if (netif_msg_ifdown(handle))
> +		netdev_info(netdev, "set fecparam: mode=%d\n",
> fec_mode);
> +
>  	return ops->set_fec(handle, fec_mode);
>  }
>  
> diff --git a/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
> b/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
> index bac4ce1..133e7c6 100644
> --- a/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
> +++ b/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
> @@ -201,6 +201,7 @@ static int hclge_client_setup_tc(struct hclge_dev
> *hdev)
>  static int hclge_ieee_setets(struct hnae3_handle *h, struct ieee_ets
> *ets)
>  {
>  	struct hclge_vport *vport = hclge_get_vport(h);
> +	struct net_device *netdev = h->kinfo.netdev;
>  	struct hclge_dev *hdev = vport->back;
>  	bool map_changed = false;
>  	u8 num_tc = 0;
> @@ -215,6 +216,9 @@ static int hclge_ieee_setets(struct hnae3_handle
> *h, struct ieee_ets *ets)
>  		return ret;
>  
>  	if (map_changed) {
> +		if (netif_msg_ifdown(h))
> +			netdev_info(netdev, "set ets\n");
> +
>  		ret = hclge_notify_client(hdev, HNAE3_DOWN_CLIENT);
>  		if (ret)
>  			return ret;
> @@ -300,6 +304,7 @@ static int hclge_ieee_getpfc(struct hnae3_handle
> *h, struct ieee_pfc *pfc)
>  static int hclge_ieee_setpfc(struct hnae3_handle *h, struct ieee_pfc
> *pfc)
>  {
>  	struct hclge_vport *vport = hclge_get_vport(h);
> +	struct net_device *netdev = h->kinfo.netdev;
>  	struct hclge_dev *hdev = vport->back;
>  	u8 i, j, pfc_map, *prio_tc;
>  
> @@ -325,6 +330,11 @@ static int hclge_ieee_setpfc(struct hnae3_handle
> *h, struct ieee_pfc *pfc)
>  	hdev->tm_info.hw_pfc_map = pfc_map;
>  	hdev->tm_info.pfc_en = pfc->pfc_en;
>  
> +	if (netif_msg_ifdown(h))
> +		netdev_info(netdev,
> +			    "set pfc: pfc_en=%d, pfc_map=%d,
> num_tc=%d\n",
> +			    pfc->pfc_en, pfc_map, hdev-
> >tm_info.num_tc);
> +
>  	hclge_tm_pfc_info_update(hdev);
>  
>  	return hclge_pause_setup_hw(hdev, false);
> @@ -345,8 +355,12 @@ static u8 hclge_getdcbx(struct hnae3_handle *h)
>  static u8 hclge_setdcbx(struct hnae3_handle *h, u8 mode)
>  {
>  	struct hclge_vport *vport = hclge_get_vport(h);
> +	struct net_device *netdev = h->kinfo.netdev;
>  	struct hclge_dev *hdev = vport->back;
>  
> +	if (netif_msg_drv(h))
> +		netdev_info(netdev, "set dcbx: mode=%d\n", mode);
> +
>  	/* No support for LLD_MANAGED modes or CEE */
>  	if ((mode & DCB_CAP_DCBX_LLD_MANAGED) ||
>  	    (mode & DCB_CAP_DCBX_VER_CEE) ||
Yonglong Liu July 25, 2019, 12:28 p.m. UTC | #2
On 2019/7/25 3:12, Saeed Mahameed wrote:
> On Wed, 2019-07-24 at 11:18 +0800, Huazhong Tan wrote:
>> From: Yonglong Liu <liuyonglong@huawei.com>
>>
>> Some times just see the eth interface have been down/up via
>> dmesg, but can not know why the eth down. So adds some debug
>> messages to identify the cause for this.
>>
> 
> I really don't like this. your default msg lvl has NETIF_MSG_IFDOWN
> turned on .. dumping every single operation that happens on your device
> by default to kernel log is too much ! 
> 
> We should really consider using trace buffers with well defined
> structures for vendor specific events. so we can use bpf filters and
> state of the art tools for netdev debugging.
> 

We do this because we can just see a link down message in dmesg, and had
take a long time to found the cause of link down, just because another
user changed the settings.

We can change the net_open/net_stop/dcbnl_ops to msg_drv (not default
turned on),  and want to keep the others default print to kernel log,
is it acceptable?

>> @@ -1593,6 +1603,11 @@ static int hns3_ndo_set_vf_vlan(struct
>> net_device *netdev, int vf, u16 vlan,
>>  	struct hnae3_handle *h = hns3_get_handle(netdev);
>>  	int ret = -EIO;
>>  
>> +	if (netif_msg_ifdown(h))
> 
> why msg_ifdown ? looks like netif_msg_drv is more appropriate, for many
> of the cases in this patch.
> 

This operation may cause link down, so we use msg_ifdown.

>> +		netdev_info(netdev,
>> +			    "set vf vlan: vf=%d, vlan=%d, qos=%d,
>> vlan_proto=%d\n",
>> +			    vf, vlan, qos, vlan_proto);
>> +
>>  	if (h->ae_algo->ops->set_vf_vlan_filter)
>>  		ret = h->ae_algo->ops->set_vf_vlan_filter(h, vf, vlan,
>>  							  qos,
>> vlan_proto);
>> @@ -1611,6 +1626,10 @@ static int hns3_nic_change_mtu(struct
>> net_device *netdev, int new_mtu)
>>  	if (!h->ae_algo->ops->set_mtu)
>>  		return -EOPNOTSUPP;
>>  
>> +	if (netif_msg_ifdown(h))
>> +		netdev_info(netdev, "change mtu from %d to %d\n",
>> +			    netdev->mtu, new_mtu);
>> +
>>  	ret = h->ae_algo->ops->set_mtu(h, new_mtu);
>>  	if (ret)
>>  		netdev_err(netdev, "failed to change MTU in hardware
>> %d\n",
>> @@ -4395,6 +4414,11 @@ int hns3_set_channels(struct net_device
>> *netdev,
>>  	if (kinfo->rss_size == new_tqp_num)
>>  		return 0;
>>  
>> +	if (netif_msg_ifdown(h))
>> +		netdev_info(netdev,
>> +			    "set channels: tqp_num=%d, rxfh=%d\n",
>> +			    new_tqp_num, rxfh_configured);
>> +
>>  	ret = hns3_reset_notify(h, HNAE3_DOWN_CLIENT);
>>  	if (ret)
>>  		return ret;
>> diff --git a/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
>> b/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
>> index e71c92b..edb9845 100644
>> --- a/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
>> +++ b/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
>> @@ -311,6 +311,9 @@ static void hns3_self_test(struct net_device
>> *ndev,
>>  	if (eth_test->flags != ETH_TEST_FL_OFFLINE)
>>  		return;
>>  
>> +	if (netif_msg_ifdown(h))
>> +		netdev_info(ndev, "self test start\n");
>> +
>>  	st_param[HNAE3_LOOP_APP][0] = HNAE3_LOOP_APP;
>>  	st_param[HNAE3_LOOP_APP][1] =
>>  			h->flags & HNAE3_SUPPORT_APP_LOOPBACK;
>> @@ -374,6 +377,9 @@ static void hns3_self_test(struct net_device
>> *ndev,
>>  
>>  	if (if_running)
>>  		ndev->netdev_ops->ndo_open(ndev);
>> +
>> +	if (netif_msg_ifdown(h))
>> +		netdev_info(ndev, "self test end\n");
>>  }
>>  
>>  static int hns3_get_sset_count(struct net_device *netdev, int
>> stringset)
>> @@ -604,6 +610,11 @@ static int hns3_set_pauseparam(struct net_device
>> *netdev,
>>  {
>>  	struct hnae3_handle *h = hns3_get_handle(netdev);
>>  
>> +	if (netif_msg_ifdown(h))
>> +		netdev_info(netdev,
>> +			    "set pauseparam: autoneg=%d, rx:%d,
>> tx:%d\n",
>> +			    param->autoneg, param->rx_pause, param-
>>> tx_pause);
>> +
>>  	if (h->ae_algo->ops->set_pauseparam)
>>  		return h->ae_algo->ops->set_pauseparam(h, param-
>>> autoneg,
>>  						       param->rx_pause,
>> @@ -743,6 +754,13 @@ static int hns3_set_link_ksettings(struct
>> net_device *netdev,
>>  	if (cmd->base.speed == SPEED_1000 && cmd->base.duplex ==
>> DUPLEX_HALF)
>>  		return -EINVAL;
>>  
>> +	if (netif_msg_ifdown(handle))
>> +		netdev_info(netdev,
>> +			    "set link(%s): autoneg=%d, speed=%d,
>> duplex=%d\n",
>> +			    netdev->phydev ? "phy" : "mac",
>> +			    cmd->base.autoneg, cmd->base.speed,
>> +			    cmd->base.duplex);
>> +
>>  	/* Only support ksettings_set for netdev with phy attached for
>> now */
>>  	if (netdev->phydev)
>>  		return phy_ethtool_ksettings_set(netdev->phydev, cmd);
>> @@ -984,6 +1002,10 @@ static int hns3_nway_reset(struct net_device
>> *netdev)
>>  		return -EINVAL;
>>  	}
>>  
>> +	if (netif_msg_ifdown(handle))
>> +		netdev_info(netdev, "nway reset (using %s)\n",
>> +			    phy ? "phy" : "mac");
>> +
>>  	if (phy)
>>  		return genphy_restart_aneg(phy);
>>  
>> @@ -1308,6 +1330,10 @@ static int hns3_set_fecparam(struct net_device
>> *netdev,
>>  	if (!ops->set_fec)
>>  		return -EOPNOTSUPP;
>>  	fec_mode = eth_to_loc_fec(fec->fec);
>> +
>> +	if (netif_msg_ifdown(handle))
>> +		netdev_info(netdev, "set fecparam: mode=%d\n",
>> fec_mode);
>> +
>>  	return ops->set_fec(handle, fec_mode);
>>  }
>>  
>> diff --git a/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
>> b/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
>> index bac4ce1..133e7c6 100644
>> --- a/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
>> +++ b/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
>> @@ -201,6 +201,7 @@ static int hclge_client_setup_tc(struct hclge_dev
>> *hdev)
>>  static int hclge_ieee_setets(struct hnae3_handle *h, struct ieee_ets
>> *ets)
>>  {
>>  	struct hclge_vport *vport = hclge_get_vport(h);
>> +	struct net_device *netdev = h->kinfo.netdev;
>>  	struct hclge_dev *hdev = vport->back;
>>  	bool map_changed = false;
>>  	u8 num_tc = 0;
>> @@ -215,6 +216,9 @@ static int hclge_ieee_setets(struct hnae3_handle
>> *h, struct ieee_ets *ets)
>>  		return ret;
>>  
>>  	if (map_changed) {
>> +		if (netif_msg_ifdown(h))
>> +			netdev_info(netdev, "set ets\n");
>> +
>>  		ret = hclge_notify_client(hdev, HNAE3_DOWN_CLIENT);
>>  		if (ret)
>>  			return ret;
>> @@ -300,6 +304,7 @@ static int hclge_ieee_getpfc(struct hnae3_handle
>> *h, struct ieee_pfc *pfc)
>>  static int hclge_ieee_setpfc(struct hnae3_handle *h, struct ieee_pfc
>> *pfc)
>>  {
>>  	struct hclge_vport *vport = hclge_get_vport(h);
>> +	struct net_device *netdev = h->kinfo.netdev;
>>  	struct hclge_dev *hdev = vport->back;
>>  	u8 i, j, pfc_map, *prio_tc;
>>  
>> @@ -325,6 +330,11 @@ static int hclge_ieee_setpfc(struct hnae3_handle
>> *h, struct ieee_pfc *pfc)
>>  	hdev->tm_info.hw_pfc_map = pfc_map;
>>  	hdev->tm_info.pfc_en = pfc->pfc_en;
>>  
>> +	if (netif_msg_ifdown(h))
>> +		netdev_info(netdev,
>> +			    "set pfc: pfc_en=%d, pfc_map=%d,
>> num_tc=%d\n",
>> +			    pfc->pfc_en, pfc_map, hdev-
>>> tm_info.num_tc);
>> +
>>  	hclge_tm_pfc_info_update(hdev);
>>  
>>  	return hclge_pause_setup_hw(hdev, false);
>> @@ -345,8 +355,12 @@ static u8 hclge_getdcbx(struct hnae3_handle *h)
>>  static u8 hclge_setdcbx(struct hnae3_handle *h, u8 mode)
>>  {
>>  	struct hclge_vport *vport = hclge_get_vport(h);
>> +	struct net_device *netdev = h->kinfo.netdev;
>>  	struct hclge_dev *hdev = vport->back;
>>  
>> +	if (netif_msg_drv(h))
>> +		netdev_info(netdev, "set dcbx: mode=%d\n", mode);
>> +
>>  	/* No support for LLD_MANAGED modes or CEE */
>>  	if ((mode & DCB_CAP_DCBX_LLD_MANAGED) ||
>>  	    (mode & DCB_CAP_DCBX_VER_CEE) ||
Saeed Mahameed July 25, 2019, 9:59 p.m. UTC | #3
On Thu, 2019-07-25 at 20:28 +0800, liuyonglong wrote:
> 
> On 2019/7/25 3:12, Saeed Mahameed wrote:
> > On Wed, 2019-07-24 at 11:18 +0800, Huazhong Tan wrote:
> > > From: Yonglong Liu <liuyonglong@huawei.com>
> > > 
> > > Some times just see the eth interface have been down/up via
> > > dmesg, but can not know why the eth down. So adds some debug
> > > messages to identify the cause for this.
> > > 
> > 
> > I really don't like this. your default msg lvl has NETIF_MSG_IFDOWN
> > turned on .. dumping every single operation that happens on your
> > device
> > by default to kernel log is too much ! 
> > 
> > We should really consider using trace buffers with well defined
> > structures for vendor specific events. so we can use bpf filters
> > and
> > state of the art tools for netdev debugging.
> > 
> 
> We do this because we can just see a link down message in dmesg, and
> had
> take a long time to found the cause of link down, just because
> another
> user changed the settings.
> 
> We can change the net_open/net_stop/dcbnl_ops to msg_drv (not default
> turned on),  and want to keep the others default print to kernel log,
> is it acceptable?
> 

acceptable as long as debug information are kept off by default and
your driver doens't spam the kernel log.

you should use dynamic debug [1] and/or "off by default" msg lvls for
debugging information..

I couldn't find any rules regarding what to put in kernel log, Maybe
someone can share ?. but i vaguely remember that the recommendation
for device drivers is to put nothing, only error/warning messages.

[1] 
https://www.kernel.org/doc/html/v4.15/admin-guide/dynamic-debug-howto.html

> > > @@ -1593,6 +1603,11 @@ static int hns3_ndo_set_vf_vlan(struct
> > > net_device *netdev, int vf, u16 vlan,
> > >  	struct hnae3_handle *h = hns3_get_handle(netdev);
> > >  	int ret = -EIO;
> > >  
> > > +	if (netif_msg_ifdown(h))
> > 
> > why msg_ifdown ? looks like netif_msg_drv is more appropriate, for
> > many
> > of the cases in this patch.
> > 
> 
> This operation may cause link down, so we use msg_ifdown.
> 

ifdown isn't link down.. 

to be honest, I couldn't find any documentation explaining how/when to
use msg lvls, (i didn't look too deep though), by looking at other
drivers, my interpretations is:

ifdup (open/boot up flow)
ifdwon (close/teardown flow)
drv (driver based or dynamic flows) 
etc .. 

-Saeed.
Jakub Kicinski July 26, 2019, 1:28 a.m. UTC | #4
On Thu, 25 Jul 2019 21:59:08 +0000, Saeed Mahameed wrote:
> I couldn't find any rules regarding what to put in kernel log, Maybe
> someone can share ?. but i vaguely remember that the recommendation
> for device drivers is to put nothing, only error/warning messages.

FWIW my understanding is also that only error/warning messages should
be printed. IOW things which should "never happen".

There are some historical exceptions. Probe logs for instance may be
useful, because its not trivial to get to the device if probe fails.

Another one is ethtool flashing, if it takes time we used to print into
logs some message like "please wait patiently". But since Jiri added
the progress messages in devlink that's no longer necessary.

For the messages which are basically printing the name of the function
or name of the function and their args - we have ftrace.

That's my $0.02 :)
Yonglong Liu July 26, 2019, 2:21 a.m. UTC | #5
We will change all of them to netif_msg_drv() which is default off
Thanks for your reply!

On 2019/7/26 5:59, Saeed Mahameed wrote:
> On Thu, 2019-07-25 at 20:28 +0800, liuyonglong wrote:
>>
>> On 2019/7/25 3:12, Saeed Mahameed wrote:
>>> On Wed, 2019-07-24 at 11:18 +0800, Huazhong Tan wrote:
>>>> From: Yonglong Liu <liuyonglong@huawei.com>
>>>>
>>>> Some times just see the eth interface have been down/up via
>>>> dmesg, but can not know why the eth down. So adds some debug
>>>> messages to identify the cause for this.
>>>>
>>>
>>> I really don't like this. your default msg lvl has NETIF_MSG_IFDOWN
>>> turned on .. dumping every single operation that happens on your
>>> device
>>> by default to kernel log is too much ! 
>>>
>>> We should really consider using trace buffers with well defined
>>> structures for vendor specific events. so we can use bpf filters
>>> and
>>> state of the art tools for netdev debugging.
>>>
>>
>> We do this because we can just see a link down message in dmesg, and
>> had
>> take a long time to found the cause of link down, just because
>> another
>> user changed the settings.
>>
>> We can change the net_open/net_stop/dcbnl_ops to msg_drv (not default
>> turned on),  and want to keep the others default print to kernel log,
>> is it acceptable?
>>
> 
> acceptable as long as debug information are kept off by default and
> your driver doens't spam the kernel log.
> 
> you should use dynamic debug [1] and/or "off by default" msg lvls for
> debugging information..
> 
> I couldn't find any rules regarding what to put in kernel log, Maybe
> someone can share ?. but i vaguely remember that the recommendation
> for device drivers is to put nothing, only error/warning messages.
> 
> [1] 
> https://www.kernel.org/doc/html/v4.15/admin-guide/dynamic-debug-howto.html
> 
>>>> @@ -1593,6 +1603,11 @@ static int hns3_ndo_set_vf_vlan(struct
>>>> net_device *netdev, int vf, u16 vlan,
>>>>  	struct hnae3_handle *h = hns3_get_handle(netdev);
>>>>  	int ret = -EIO;
>>>>  
>>>> +	if (netif_msg_ifdown(h))
>>>
>>> why msg_ifdown ? looks like netif_msg_drv is more appropriate, for
>>> many
>>> of the cases in this patch.
>>>
>>
>> This operation may cause link down, so we use msg_ifdown.
>>
> 
> ifdown isn't link down.. 
> 
> to be honest, I couldn't find any documentation explaining how/when to
> use msg lvls, (i didn't look too deep though), by looking at other
> drivers, my interpretations is:
> 
> ifdup (open/boot up flow)
> ifdwon (close/teardown flow)
> drv (driver based or dynamic flows) 
> etc .. 
> 
> -Saeed.
>
Yonglong Liu July 26, 2019, 2:33 a.m. UTC | #6
As Saeed said, we will use netif_msg_drv() which is default off, this
can be easily open with ethtool.
Thanks for your reply!

On 2019/7/26 9:28, Jakub Kicinski wrote:
> On Thu, 25 Jul 2019 21:59:08 +0000, Saeed Mahameed wrote:
>> I couldn't find any rules regarding what to put in kernel log, Maybe
>> someone can share ?. but i vaguely remember that the recommendation
>> for device drivers is to put nothing, only error/warning messages.
> 
> FWIW my understanding is also that only error/warning messages should
> be printed. IOW things which should "never happen".
> 
> There are some historical exceptions. Probe logs for instance may be
> useful, because its not trivial to get to the device if probe fails.
> 
> Another one is ethtool flashing, if it takes time we used to print into
> logs some message like "please wait patiently". But since Jiri added
> the progress messages in devlink that's no longer necessary.
> 
> For the messages which are basically printing the name of the function
> or name of the function and their args - we have ftrace.
> 
> That's my $0.02 :)
> 
> .
>
diff mbox series

Patch

diff --git a/drivers/net/ethernet/hisilicon/hns3/hns3_enet.c b/drivers/net/ethernet/hisilicon/hns3/hns3_enet.c
index 4d58c53..cff5d59 100644
--- a/drivers/net/ethernet/hisilicon/hns3/hns3_enet.c
+++ b/drivers/net/ethernet/hisilicon/hns3/hns3_enet.c
@@ -459,6 +459,10 @@  static int hns3_nic_net_open(struct net_device *netdev)
 		h->ae_algo->ops->set_timer_task(priv->ae_handle, true);
 
 	hns3_config_xps(priv);
+
+	if (netif_msg_ifup(h))
+		netdev_info(netdev, "net open\n");
+
 	return 0;
 }
 
@@ -519,6 +523,9 @@  static int hns3_nic_net_stop(struct net_device *netdev)
 	if (test_and_set_bit(HNS3_NIC_STATE_DOWN, &priv->state))
 		return 0;
 
+	if (netif_msg_ifdown(h))
+		netdev_info(netdev, "net stop\n");
+
 	if (h->ae_algo->ops->set_timer_task)
 		h->ae_algo->ops->set_timer_task(priv->ae_handle, false);
 
@@ -1550,6 +1557,9 @@  static int hns3_setup_tc(struct net_device *netdev, void *type_data)
 	h = hns3_get_handle(netdev);
 	kinfo = &h->kinfo;
 
+	if (netif_msg_ifdown(h))
+		netdev_info(netdev, "setup tc: num_tc=%d\n", tc);
+
 	return (kinfo->dcb_ops && kinfo->dcb_ops->setup_tc) ?
 		kinfo->dcb_ops->setup_tc(h, tc, prio_tc) : -EOPNOTSUPP;
 }
@@ -1593,6 +1603,11 @@  static int hns3_ndo_set_vf_vlan(struct net_device *netdev, int vf, u16 vlan,
 	struct hnae3_handle *h = hns3_get_handle(netdev);
 	int ret = -EIO;
 
+	if (netif_msg_ifdown(h))
+		netdev_info(netdev,
+			    "set vf vlan: vf=%d, vlan=%d, qos=%d, vlan_proto=%d\n",
+			    vf, vlan, qos, vlan_proto);
+
 	if (h->ae_algo->ops->set_vf_vlan_filter)
 		ret = h->ae_algo->ops->set_vf_vlan_filter(h, vf, vlan,
 							  qos, vlan_proto);
@@ -1611,6 +1626,10 @@  static int hns3_nic_change_mtu(struct net_device *netdev, int new_mtu)
 	if (!h->ae_algo->ops->set_mtu)
 		return -EOPNOTSUPP;
 
+	if (netif_msg_ifdown(h))
+		netdev_info(netdev, "change mtu from %d to %d\n",
+			    netdev->mtu, new_mtu);
+
 	ret = h->ae_algo->ops->set_mtu(h, new_mtu);
 	if (ret)
 		netdev_err(netdev, "failed to change MTU in hardware %d\n",
@@ -4395,6 +4414,11 @@  int hns3_set_channels(struct net_device *netdev,
 	if (kinfo->rss_size == new_tqp_num)
 		return 0;
 
+	if (netif_msg_ifdown(h))
+		netdev_info(netdev,
+			    "set channels: tqp_num=%d, rxfh=%d\n",
+			    new_tqp_num, rxfh_configured);
+
 	ret = hns3_reset_notify(h, HNAE3_DOWN_CLIENT);
 	if (ret)
 		return ret;
diff --git a/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c b/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
index e71c92b..edb9845 100644
--- a/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
+++ b/drivers/net/ethernet/hisilicon/hns3/hns3_ethtool.c
@@ -311,6 +311,9 @@  static void hns3_self_test(struct net_device *ndev,
 	if (eth_test->flags != ETH_TEST_FL_OFFLINE)
 		return;
 
+	if (netif_msg_ifdown(h))
+		netdev_info(ndev, "self test start\n");
+
 	st_param[HNAE3_LOOP_APP][0] = HNAE3_LOOP_APP;
 	st_param[HNAE3_LOOP_APP][1] =
 			h->flags & HNAE3_SUPPORT_APP_LOOPBACK;
@@ -374,6 +377,9 @@  static void hns3_self_test(struct net_device *ndev,
 
 	if (if_running)
 		ndev->netdev_ops->ndo_open(ndev);
+
+	if (netif_msg_ifdown(h))
+		netdev_info(ndev, "self test end\n");
 }
 
 static int hns3_get_sset_count(struct net_device *netdev, int stringset)
@@ -604,6 +610,11 @@  static int hns3_set_pauseparam(struct net_device *netdev,
 {
 	struct hnae3_handle *h = hns3_get_handle(netdev);
 
+	if (netif_msg_ifdown(h))
+		netdev_info(netdev,
+			    "set pauseparam: autoneg=%d, rx:%d, tx:%d\n",
+			    param->autoneg, param->rx_pause, param->tx_pause);
+
 	if (h->ae_algo->ops->set_pauseparam)
 		return h->ae_algo->ops->set_pauseparam(h, param->autoneg,
 						       param->rx_pause,
@@ -743,6 +754,13 @@  static int hns3_set_link_ksettings(struct net_device *netdev,
 	if (cmd->base.speed == SPEED_1000 && cmd->base.duplex == DUPLEX_HALF)
 		return -EINVAL;
 
+	if (netif_msg_ifdown(handle))
+		netdev_info(netdev,
+			    "set link(%s): autoneg=%d, speed=%d, duplex=%d\n",
+			    netdev->phydev ? "phy" : "mac",
+			    cmd->base.autoneg, cmd->base.speed,
+			    cmd->base.duplex);
+
 	/* Only support ksettings_set for netdev with phy attached for now */
 	if (netdev->phydev)
 		return phy_ethtool_ksettings_set(netdev->phydev, cmd);
@@ -984,6 +1002,10 @@  static int hns3_nway_reset(struct net_device *netdev)
 		return -EINVAL;
 	}
 
+	if (netif_msg_ifdown(handle))
+		netdev_info(netdev, "nway reset (using %s)\n",
+			    phy ? "phy" : "mac");
+
 	if (phy)
 		return genphy_restart_aneg(phy);
 
@@ -1308,6 +1330,10 @@  static int hns3_set_fecparam(struct net_device *netdev,
 	if (!ops->set_fec)
 		return -EOPNOTSUPP;
 	fec_mode = eth_to_loc_fec(fec->fec);
+
+	if (netif_msg_ifdown(handle))
+		netdev_info(netdev, "set fecparam: mode=%d\n", fec_mode);
+
 	return ops->set_fec(handle, fec_mode);
 }
 
diff --git a/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c b/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
index bac4ce1..133e7c6 100644
--- a/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
+++ b/drivers/net/ethernet/hisilicon/hns3/hns3pf/hclge_dcb.c
@@ -201,6 +201,7 @@  static int hclge_client_setup_tc(struct hclge_dev *hdev)
 static int hclge_ieee_setets(struct hnae3_handle *h, struct ieee_ets *ets)
 {
 	struct hclge_vport *vport = hclge_get_vport(h);
+	struct net_device *netdev = h->kinfo.netdev;
 	struct hclge_dev *hdev = vport->back;
 	bool map_changed = false;
 	u8 num_tc = 0;
@@ -215,6 +216,9 @@  static int hclge_ieee_setets(struct hnae3_handle *h, struct ieee_ets *ets)
 		return ret;
 
 	if (map_changed) {
+		if (netif_msg_ifdown(h))
+			netdev_info(netdev, "set ets\n");
+
 		ret = hclge_notify_client(hdev, HNAE3_DOWN_CLIENT);
 		if (ret)
 			return ret;
@@ -300,6 +304,7 @@  static int hclge_ieee_getpfc(struct hnae3_handle *h, struct ieee_pfc *pfc)
 static int hclge_ieee_setpfc(struct hnae3_handle *h, struct ieee_pfc *pfc)
 {
 	struct hclge_vport *vport = hclge_get_vport(h);
+	struct net_device *netdev = h->kinfo.netdev;
 	struct hclge_dev *hdev = vport->back;
 	u8 i, j, pfc_map, *prio_tc;
 
@@ -325,6 +330,11 @@  static int hclge_ieee_setpfc(struct hnae3_handle *h, struct ieee_pfc *pfc)
 	hdev->tm_info.hw_pfc_map = pfc_map;
 	hdev->tm_info.pfc_en = pfc->pfc_en;
 
+	if (netif_msg_ifdown(h))
+		netdev_info(netdev,
+			    "set pfc: pfc_en=%d, pfc_map=%d, num_tc=%d\n",
+			    pfc->pfc_en, pfc_map, hdev->tm_info.num_tc);
+
 	hclge_tm_pfc_info_update(hdev);
 
 	return hclge_pause_setup_hw(hdev, false);
@@ -345,8 +355,12 @@  static u8 hclge_getdcbx(struct hnae3_handle *h)
 static u8 hclge_setdcbx(struct hnae3_handle *h, u8 mode)
 {
 	struct hclge_vport *vport = hclge_get_vport(h);
+	struct net_device *netdev = h->kinfo.netdev;
 	struct hclge_dev *hdev = vport->back;
 
+	if (netif_msg_drv(h))
+		netdev_info(netdev, "set dcbx: mode=%d\n", mode);
+
 	/* No support for LLD_MANAGED modes or CEE */
 	if ((mode & DCB_CAP_DCBX_LLD_MANAGED) ||
 	    (mode & DCB_CAP_DCBX_VER_CEE) ||