CC3220SF: NWP MAC device stopped sleeping after several months causing high power consumption and premature power failure

Hi Ben,

During the time of always on MAC, does the device maintain connection to the Access Point?

Can you clarify this - (the sum of the 3 statistics returned by the above API, did not reset) - Are you saying that the values returned here were always the same? I assume MacAwake was 100%?

Mac and NWP logs are probably the best way to diagnosis what happened, but i understand you probably don't have those. Was this occurrence only on one device? Has it occurred again after you reset it? Can you provide the Service pack version you are using?

For your questions - setting the power policy to always on would be the only way to force the device to stay awake. If we could see what was going on right before the device went into the mode, it could give us an idea on what happened. If you run into this scenario again, i would suggest a sl_Stop() ->sl_Start() sequence to see if the issue clears itself.

Best Regards,

Vince 

Hi Vince,

Yes, during the time of always on MAC the device remained connected with no wlan level errors/warnings/events.

What I meant by 'not reset' is that the sum did not decrease from the previous day, they continued to increment from the previous day.  So it looks like the MAC did not stop running.  

We are running SDK 3.20.00.06, so sp_3.12.0.1_2.0.0.0_2.2.0.6.

We are trying to see how widespread the issue is, will have more info on that today.  Unfortunately acquiring the logs will be tough, we will have to reproduce it locally and we've never seen this before.

Thanks!

Ben

Hi Ben,

Any update on this? I am still a little confused on the not reset and the summing of the values. Can you share those values with me so I review?

BR,

Vince 

Hi Vince,

Yesterday we mined some of our data to determine that the MAC awake issue has happened on more than a few units.  Let me try to help clarify what this data is. 

Once a day we send usage/diagnostic data to our backend.  It contains many things, including the most recent battery voltage measured (this is how we calculate battery life) as well as percentages that each digital peripheral is not in a sleep state.  We call this the 'awake' percentage.  On this device, the CC3220SF has 3 awake percentages associated with it: MCU (we use FreeRTOS callbacks on entering and leaving sleep to calculate this), NWP (sl_DeviceStatGet), and MAC (sl_DeviceStatGet).  

Here is an example of the data from one of the units exhibiting the problem.  From Nov 30 to Jan 21, The battery is draining at a normal rate, and the awake percentages look normal.  Between Jan 21 and Jan 22, the MAC awake percentage starts to shoot up.  The battery voltage then begins to decrease very quickly.  The same thing eventually happens to the NWP on Feb 3/4. 

Date   - BatV (Bat%)- Awake Percentage per CPU
-------------------------------------------------------------------
Nov 30 - 9054 (100%)- CC32 = 0.56%, NWP = 0.35%, MAC = 0.86%
Dec 7  - 8771 (100%)- CC32 = 0.33%, NWP = 0.34%, MAC = 0.83%
Dec 14 - 8707 (100%)- Similiar to above
Dec 21 - 8649 (100%)- Similiar to above
Dec 28 - 8424 (100%)- Similiar to above
Jan 4 -  8398 (100%)- Similiar to below
Jan 11 - 7935 (90%) - CC32 = 0.33%, NWP = 0.17%, MAC = 0.76%
Jan 17 - 7974 (90%) - CC32 = 0.32%, NWP = 0.18%, MAC = 0.86%
Jan 18 - 7980 (90%) - CC32 = 0.33%, NWP = 0.51%, MAC = 0.78%
Jan 19 - 8006 (90%) - CC32 = 0.33%, NWP = 0.50%, MAC = 0.80%
Jan 20 - 7922 (90%) - CC32 = 0.33%, NWP = 0.39%, MAC = 0.82%
Jan 21 - 8000 (90%) - CC32 = 0.33%, NWP = 0.37%, MAC = 0.82%
***************   Something bad happened on MAC CPU  **********************
Jan 22 - 7697 (80%) - CC32 = 0.33%, NWP = 0.33%, MAC = ** 7.57% **
Jan 23 - 7453 (80%) - CC32 = 0.33%, NWP = 0.30%, MAC = ** 23.2% **
Jan 24 - 7376 (70%) - CC32 = 0.32%, NWP = 0.28%, MAC = ** 33.9% **
Jan 25 - 7273 (70%) - CC32 = 0.33%, NWP = 0.27%, MAC = ** 42.3% **
Jan 26 - 7209 (70%) - CC32 = 0.33%, NWP = 0.26%, MAC = ** 48.8% **
Jan 27 - 7074 (70%) - CC32 = 0.33%, NWP = 0.25%, MAC = ** 53.8% **
Jan 28 - 6996 (60%) - CC32 = 0.33%, NWP = 0.24%, MAC = ** 58.1% **
Jan 29 - 6984 (60%) - CC32 = 0.32%, NWP = 0.23%, MAC = ** 61.6% **
Jan 30 - 6758 (60%) - CC32 = 0.32%, NWP = 0.22%, MAC = ** 64.5% **
Jan 31 - 6566 (50%) - CC32 = 0.32%, NWP = 0.22%, MAC = ** 67.1% **
Feb 01 - 6424 (50%) - CC32 = 0.32%, NWP = 0.22%, MAC = ** 69.3% **
Feb 02 - 6225 (40%) - CC32 = 0.32%, NWP = 0.22%, MAC = ** 71.2% **
Feb 03 - 6225 (40%) - CC32 = 0.32%, NWP = 0.22%, MAC = ** 72.9% ***
Feb 04 - 5350 (30%) - CC32 = 0.32%, NWP = ** 9.69% **, MAC = ** 74.4% **
Feb 05 - 4077 (20%) - CC32 = 0.32%, NWP = ** 11.7% **, MAC = ** 75.7% **
Batteries died (10%) sometime that day

Since the awake percentage for the MAC cumulative since the sl_Start call, I'm pretty sure that after Jan 21, the MAC device is not sleeping at all

The calculation for awake percent for the MAC is as follows:

        SlDeviceGetPmStat_t mac_info;
        _u16 length = sizeof(SlDeviceGetPmStat_t);
        int16_t sl_retval = sl_DeviceStatGet(SL_DEVICE_STAT_PM, length, &mac_info);

        if (sl_retval == 0)
        {
            info->awake_time_ms = (((uint64_t)mac_info.PmAcc.TimeMacAwake[1] << 32) | mac_info.PmAcc.TimeMacAwake[0]) / 1000;
            info->sleep_time_ms = (((uint64_t)mac_info.PmAcc.TimeMacSleep[1] << 32) | mac_info.PmAcc.TimeMacSleep[0]) / 1000;
            info->standby_time_ms = (((uint64_t)mac_info.PmAcc.TimeMacListen11B[1] << 32) | mac_info.PmAcc.TimeMacListen11B[0]) /
                                    1000;
            info->percent = ((info->awake_time_ms + info->standby_time_ms) /
                             (float)(info->awake_time_ms + info->sleep_time_ms + info->standby_time_ms) * 100);
        }

I hope this helps to clarify things.  Let me know if you need any more info.  We are still very unsure how this is happening.  To my knowledge, I don't know of any way that the NWP and MAC 'awake' percentages could be decoupled from eachother.  It seems like if the power policy setting is

sl_WlanPolicySet(SL_WLAN_POLICY_PM, SL_WLAN_LONG_SLEEP_INTERVAL_POLICY),

the awake percentages are both <2%.  So not sure how the MAC could be ramping up while the NWP remains in a low power state.

Thanks,

Ben

Hi Vince,

Any ideas on stuff to try for this?  We have been trying to reproduce locally but have not had any success yet. 

We did put in some code to try and detect the high awake percentage state and to perform a Sl_Stop()/Sl_Start() reset sequence, but obviously we would prefer to never fall into this state in the first place.  

Will NWP logs be necessary to help determine what is going on here? 

Thanks,

Ben

Hi Ben,

NWP logs and MAC logs are really what we need to diagnose. It will be difficult to do much more without that information.

Best Regards,

Vince 

Hi Ben,

In addition, can you help me understand this issue by providing the following information?

• Does the issue appear time dependent? I see after two months this issue occurred above. Is this consistent on all devices that exhibit this behavior?
• Looks like the NWP ticked up on the last few days. Do have any thoughts on what happened there?
• Do you know which Access Point is being used on the Failing units? This will help us try to narrow down a test setup
• What other operations are occurring on the device? Can you provide a high level flow for what your software is doing?
• I assume you already have checks in all callbacks, but can you verify you check for all error cases in our callback handlers?
• Did the sl_Stop/sl_Start seem to fix the issue?

If you'd like to send me a email with your answers feel free.

Best Regards,
Vince