Received-SPF: pass (google.com: domain of linux-wireless-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Sender: Larry Finger <larry.finger@gmail.com>
Message-ID: <ef7361eb-17ce-5ecf-a46a-a9f0c5aab35b@lwfinger.net>
Date:   Thu, 3 Feb 2022 14:06:08 -0600
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101
 Thunderbird/91.5.0
Subject: Re: Funny log entries for rtw88_8821ce
Content-Language: en-US
To:     Pkshih <pkshih@realtek.com>
Cc:     "linux-wireless@vger.kernel.org" <linux-wireless@vger.kernel.org>
References: <c356d5ae-a7b3-3065-1121-64c446e70333@lwfinger.net>
 <32f2ece8acdb67f74757cb705e5467847d6bcae0.camel@realtek.com>
From:   Larry Finger <Larry.Finger@lwfinger.net>
In-Reply-To: <32f2ece8acdb67f74757cb705e5467847d6bcae0.camel@realtek.com>
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 7bit
Precedence: bulk

On 2/1/22 00:26, Pkshih wrote:
> Hi,
> 
> 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.

Larry