Search Linux Wireless

Re: Funny log entries for rtw88_8821ce

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Larry Finger <Larry.Finger@xxxxxxxxxxxx> writes:

> On 2/1/22 00:26, Pkshih wrote:
>> On Mon, 2022-01-31 at 16:53 -0600, Larry Finger wrote:
>>> Ping-Ke and list,
>>>
>>> Within the last couple of days, I was testing rtw88 with an rtl8821ce card. I
>>> noticed that whenever the device is not connected to an AP, the log is flooded
>>> with messages like the following:
>>> [130462.603539] rtw_8821ce 0000:02:00.0: stop vif ee:a4:95:4e:53:8b on port 0
>>> [130463.116843] rtw_8821ce 0000:02:00.0: start vif aa:fc:19:66:5e:e2 on port 0
>>> [130874.613430] rtw_8821ce 0000:02:00.0: stop vif aa:fc:19:66:5e:e2 on port 0
>>> [130875.122641] rtw_8821ce 0000:02:00.0: start vif d2:e6:23:ba:98:76 on port 0
>>> [131286.677828] rtw_8821ce 0000:02:00.0: stop vif d2:e6:23:ba:98:76 on port 0
>>> [131287.192108] rtw_8821ce 0000:02:00.0: start vif 82:c4:33:96:2e:c6 on port 0\
>>
>> I turn off UI network-manager, and it can show the same messages if I use
>> 'ifconfig' to up and down the interfaces. I think add_interface()/remove_interface()
>> are called by ieee80211_do_open()/ieee80211_do_stop() in my test cases.
>>
>> Please check if your network-manager does the things. If so, check syslog to
>> know why it does.
>
> Utility journalctl show the following for a couple of cycles from
> start- to stop-vif:
>
> Feb 03 12:02:10 localhost.localdomain NetworkManager[608]: <info>
> [1643911330.5997] device (wls1): supplicant interface state:
> disconnected -> 
> interface_disabled
> Feb 03 12:02:10 localhost.localdomain kernel: rtw_8821ce 0000:02:00.0:
> start vif 9a:cd:df:5f:24:13 on port 0
> Feb 03 12:02:10 localhost.localdomain NetworkManager[608]: <info>
> [1643911330.6179] device (wls1): supplicant interface state:
> interface_disabled -> disconnected
> Feb 03 12:09:02 localhost.localdomain kernel: rtw_8821ce 0000:02:00.0:
> stop vif 9a:cd:df:5f:24:13 on port 0
> Feb 03 12:09:02 localhost.localdomain NetworkManager[608]: <info>
> [1643911742.0704] device (wls1): set-hw-addr: set MAC address to
> 1A:73:93:A8:7E:9C (scanning)
> Feb 03 12:09:02 localhost.localdomain kernel: rtw_8821ce 0000:02:00.0:
> start vif 1a:73:93:a8:7e:9c on port 0
> Feb 03 12:09:02 localhost.localdomain NetworkManager[608]: <info>
> [1643911742.5891] device (wls1): supplicant interface state:
> disconnected -> 
> interface_disabled
> Feb 03 12:09:02 localhost.localdomain NetworkManager[608]: <info>
> [1643911742.5946] device (wls1): supplicant interface state:
> interface_disabled -> disconnected
> Feb 03 12:15:54 localhost.localdomain NetworkManager[608]: <info>
> [1643912154.0710] device (wls1): set-hw-addr: set MAC address to
> 42:CB:4C:C7:CB:00 (scanning)
> Feb 03 12:15:54 localhost.localdomain kernel: rtw_8821ce 0000:02:00.0:
> stop vif 1a:73:93:a8:7e:9c on port 0
>
> From these log entries, I see no reason why there should be a stop-vif
> 412 seconds after the interface is set from disabled to disconnected.
> This cycling does not cause any problems. Perhaps the statements that
> do the logging should be removed.

I did a quick check on how rtw88 uses rtw_info() and indeed that should
be cleaned up.

These should be warning or error messages:

rtw_info(rtwdev, "invalid H2C command format for debug\n");
rtw_info(rtwdev, "incorrect lna index (%d)\n", lna_idx);
rtw_info(rtwdev, "unsupported tx path 0x%x\n", antenna_tx);
rtw_info(rtwdev, "unsupported rx path 0x%x\n", antenna_rx);
rtw_info(rtwdev, "unsupported tx path 0x%x\n", antenna_tx);
rtw_info(rtwdev, "unsupported rx path 0x%x\n", antenna_rx);

Not sure if warn or debug, most likely debug:

rtw_info(rtwdev, "HW scan aborted with code: %d\n", rc);

These should be debug messages to avoid spamming the logs:

rtw_info(rtwdev, "start vif %pM on port %d\n", vif->addr, rtwvif->port);
rtw_info(rtwdev, "stop vif %pM on port %d\n", vif->addr, rtwvif->port);
rtw_info(rtwdev, "change vif %pM (%d)->(%d), p2p (%d)->(%d)\n",
rtw_info(rtwdev, "sta %pM joined with macid %d\n",
rtw_info(rtwdev, "sta %pM with macid %d left\n",
rtw_info(rtwdev, "On freq %u to %u, set SAR %d in 1/%lu dBm\n"

This is ok:

rtw_info(rtwdev, "Firmware version %u.%u.%u, H2C version %u\n",

-- 
https://patchwork.kernel.org/project/linux-wireless/list/

https://wireless.wiki.kernel.org/en/developers/documentation/submittingpatches



[Index of Archives]     [Linux Host AP]     [ATH6KL]     [Linux Wireless Personal Area Network]     [Linux Bluetooth]     [Wireless Regulations]     [Linux Netdev]     [Kernel Newbies]     [Linux Kernel]     [IDE]     [Git]     [Netfilter]     [Bugtraq]     [Yosemite Hiking]     [MIPS Linux]     [ARM Linux]     [Linux RAID]

  Powered by Linux