CC2540: Bluetooth activity crashes if UART is active (Either Rx or Tx) when Passive Scanning in the Observer+Peripheral mode

Hello Kainoosh,

What is your configured max scan response value for the scan? Have you tried increasing the heap size?

Best wishes

Hello There,

We are currently using (1) for max scan response. I will try increasing the heap size, but our HeapSize is at 1024 while the highest memMax was 950, I will increase the size and try to reproduce the problem.

Any other ideas? Thanks again

Decreased the Heap Usage by about 120 words and the issue occured.

I stopped the debugger once the Advertising stopped, given that HeapSize is 1024, memMax was 820 and memAlo about 740.

You mention that you are characterizing the failure as " failure to capture any advertisements during the passive scanning and the advertisement stops as well"

Can you explain this more?  Does this mean you aren't receiving Device Info and /or Device Discovery events?  If so, this would be expected if you are running out of heap.

Can you add a variable to count the amount of heap allocation failures? You can do this in osal_mem_alloc as I have below with memFail.

void *osal_mem_alloc( uint16 size )
#endif /* DPRINTF_OSALHEAPTRACE */
{
…
  if ( hdr != NULL )
  {
    uint16 tmp = hdr->hdr.len - size;

    // Determine whether the threshold for splitting is met.
    if ( tmp >= OSALMEM_MIN_BLKSZ )
    {
      // Split the block before allocating it.
      osalMemHdr_t *next = (osalMemHdr_t *)((uint8 *)hdr + size);
      next->val = tmp;                     // Set 'len' & clear 'inUse' field.
      hdr->val = (size | OSALMEM_IN_USE);  // Set 'len' & 'inUse' field.

#if ( OSALMEM_METRICS )
      blkCnt++;
      if ( blkMax < blkCnt )
      {
        blkMax = blkCnt;
      }
      memAlo += size;
#endif
    }
    else
    {
#if ( OSALMEM_METRICS )
      memAlo += hdr->hdr.len;
      blkFree--;
#endif

      hdr->hdr.inUse = TRUE;
    }

#if ( OSALMEM_METRICS )
    if ( memMax < memAlo )
    {
      memMax = memAlo;
    }
#endif

#if ( OSALMEM_PROFILER )
#if !OSALMEM_PROFILER_LL
    if (osalMemStat != 0)  // Don't profile until after the LL block is filled.
#endif
    {
      uint8 idx;

      for ( idx = 0; idx < OSALMEM_PROMAX; idx++ )
      {
        if ( hdr->hdr.len <= proCnt[idx] )
        {
          break;
        }
      }
      proCur[idx]++;
      if ( proMax[idx] < proCur[idx] )
      {
        proMax[idx] = proCur[idx];
      }
      proTot[idx]++;

      /* A small-block could not be allocated in the small-block bucket.
       * When this occurs significantly frequently, increase the size of the
       * bucket in order to restore better worst case run times. Set the first
       * profiling bucket size in proCnt[] to the small-block bucket size and
       * divide proSmallBlkMiss by the corresponding proTot[] size to get % miss.
       * Best worst case time on TrasmitApp was achieved at a 0-15% miss rate
       * during steady state Tx load, 0% during idle and steady state Rx load.
       */
      if ((hdr->hdr.len <= OSALMEM_SMALL_BLKSZ) && (hdr >= (theHeap + OSALMEM_BIGBLK_IDX)))
      {
        proSmallBlkMiss++;
      }
    }

    (void)osal_memset((uint8 *)(hdr+1), OSALMEM_ALOC, (hdr->hdr.len - OSALMEM_HDRSZ));
#endif

    if ((osalMemStat != 0) && (ff1 == hdr))
    {
      ff1 = (osalMemHdr_t *)((uint8 *)hdr + hdr->hdr.len);
    }

    hdr++;
  }
  else
  {
    memFail++;
  }

Tim, 

Thanks for your response. Apologies for lack of clarity on what I am referring to as "issue" or "crash". Basically, the problem is that when we enter passive scanning, we send the scan response over uart, in that time we can have incoming uart data as well. 

During our development, we noticed that after a period of time, the passive scanning fails to capture anymore of the advertisements, we also noticed that the device also quits advertising. However, the core is active and the uart communication with the co-processor is steady continuing. We realized that if UART is active during the passive scanning, this "wireless crash" occurs. Let me know if you need more clarification, thanks. My question was that why would advertising or passive scanning quit even if we were to run out of Heap?

I will try to repeat and catch memFail and increase the Heap if that is the case. 

I will report back, thanks. 

Kianoosh

Reproduced the issue again with the memFail in place. memFail was 0. Heapsize = 1025. memMax = 947.

Any other ideas?

Kianoosh

I still don't understand the fail case. How are you deciding that "he passive scanning fails to capture anymore of the advertisements."

It still sounds like you're just running out of heap due to receiving too many advertisements and, therefore, there isn't enough heap to allocate OSAL messages to propagate advertisements up the stack to send DeviceInfo or DeviceDiscovery events.

Does the heap level decrease after scanning is completed?

You can also try running the attached python script to analyze the heap (instructions are in comments in the script). If you do this, please post the output here.

/cfs-file/__key/communityserver-discussions-components-files/538/Osalmem_5F00_analyze.7z

I apologize for lack of description.

Basically, we have another BLE device advertising very rapidly (We also use the LightBlue Device App on iOS to view the other BLE device is advertising), we command the CC2540 to enter passive scanning (it is already advertising), whenever we get an GAP_DEVICE_INFO_EVENT event, we take the data from pEvent->deviceInfo and write the data to the UART. This continues for about 15 seconds or so, before we stop getting GAP_DEVICE_INFO_EVENT events anymore, therefore my statement of "Failure to capture anymore of the advertisements", the other device is still actively advertising. The CC2540 also quits advertising when the "Failure" occurs. The maximum Scan response is set to 1. If we were to run out of Heap, would I not see the memFail get incremented? if that is the case then everytime I stop the debugger after the "crash", the memFail is 0. Interesting part is that if I restart the CC2540 and repeat the process, it begins reporting GAP_DEVICE_INFO_EVENT event before stopping after 15-30 seconds.

Thanks for the python script, I will begin using it very shortly and report back.

Hello,

As an experiment, can you also try disabling POWER_SAVINGS to see if there is a change in behavior?

Best wishes

Python Response:

Size of analyzed heap memory: 2050
Analyzing blocks; traversing the headers in memory..
No next block, at: 2048

Finding contiguous free blocks...
Contiguous free at offset 348 : 5 bytes ( 1 blocks )
Contiguous free at offset 513 : 24 bytes ( 2 blocks )
Contiguous free at offset 567 : 17 bytes ( 1 blocks )
Contiguous free at offset 586 : 21 bytes ( 2 blocks )
Contiguous free at end of heap: 1373
Total free memory: 1440

-- Heap blocks overview --
Offs 0: In use, 42 bytes,
-> Data: 00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00

Offs 42: In use, 117 bytes,
-> Data: 00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00

Offs 159: In use, 8 bytes,
-> Data: 7B:17:09:00:52:14

Offs 167: In use, 8 bytes,
-> Data: 83:17:01:00:1C:91

Offs 175: In use, 8 bytes,
-> Data: 8B:17:0B:00:38:11

Offs 183: In use, 8 bytes,
-> Data: 93:17:0A:00:28:91

Offs 191: In use, 8 bytes,
-> Data: 9B:17:04:00:96:11

Offs 199: In use, 8 bytes,
-> Data: A3:17:15:00:16:91

Offs 207: In use, 8 bytes,
-> Data: AB:17:13:00:44:12

Offs 215: In use, 8 bytes,
-> Data: B3:17:19:00:F2:90

Offs 223: In use, 8 bytes,
-> Data: BB:17:05:00:E9:11

Offs 231: In use, 8 bytes,
-> Data: C3:17:2C:00:F8:90

Offs 239: In use, 8 bytes,
-> Data: CB:17:15:00:2D:15

Offs 247: In use, 8 bytes,
-> Data: D3:17:31:00:0A:91

Offs 255: In use, 8 bytes,
-> Data: DB:17:04:00:14:12

Offs 263: In use, 8 bytes,
-> Data: E3:17:46:00:10:91

Offs 271: In use, 8 bytes,
-> Data: EB:17:06:00:CB:14

Offs 279: In use, 8 bytes,
-> Data: F3:17:4A:00:34:91

Offs 287: In use, 8 bytes,
-> Data: FB:17:25:00:FE:12

Offs 295: In use, 8 bytes,
-> Data: 03:18:50:00:2E:91

Offs 303: In use, 8 bytes,
-> Data: 00:00:05:00:29:14

Offs 311: In use, 8 bytes,
-> Data: 00:00:75:00:22:91

Offs 319: In use, 14 bytes,
-> Data: FF:00:00:00:00:00:00:00:00:00:00:00

Offs 333: In use, 15 bytes,
-> Data: 00:00:46:00:00:00:01:00:05:00:00:00:00

Offs 348: Free, 5 bytes,
-> Data: 00:00:00

Offs 353: In use, 75 bytes,
-> Data: 02:60:01:EE:3F:56:4D:7F:3F:56:4D:7F:5F:FF:BB:FD:9F:B7:EF:EF:14:CF:3D:EF:F6:BF:57:BC:0B:3D:E5:EF:0E:BE:DD:7A:C3:BF:D9:49:B1:87:E6:CB:C5:F5:1F:1F:F9:6F:EF:EF:BD:DF:E3:B6:D8:7C:9B:DF:5B:F9:A7:E4:61:CD:FB:EF:3F:BD:8F:EF:DF

Offs 428: In use, 75 bytes,
-> Data: 7E:1C:60:03:00:03:F4:50:DB:56:2A:43:D9:17:02:01:1A:07:03:0D:18:0F:18:0A:18:0B:09:4E:6F:72:F5:EA:88:CE:7F:7F:09:D0:09:A3:08:D0:08:B7:08:F2:08:53:07:CE:07:4E:08:00:20:91:E0:2D:09:94:F8:94:FF:CF:01:00:00:00:20:FF:FF:04:80

Offs 503: In use, 4 bytes,
-> Data: 06:80

Offs 507: In use, 6 bytes,
-> Data: 08:03:00:00

Offs 513: Free, 15 bytes,
-> Data: 00:00:08:00:FF:91:0E:00:0B:20:D9:18:00

Offs 528: Free, 9 bytes,
-> Data: DE:18:00:04:00:18:00

Offs 537: In use, 15 bytes,
-> Data: 08:02:00:00:00:00:00:00:00:00:07:00:00

Offs 552: In use, 15 bytes,
-> Data: 19:18:D8:01:00:00:00:40:0B:00:00:00:00

Offs 567: Free, 17 bytes,
-> Data: 00:00:08:00:FF:91:0E:00:0C:20:0F:19:00:02:00

Offs 584: In use, 2 bytes,
-> Data:

Offs 586: Free, 15 bytes,
-> Data: 00:00:08:00:FF:91:0E:00:0C:20:22:19:00

Offs 601: Free, 6 bytes,
-> Data: DB:56:2A:43

Offs 607: In use, 34 bytes,
-> Data: 18:02:01:06:11:06:DE:74:2D:F0:70:13:12:B5:44:4B:B1:C5:10:FF:95:A4:02:0A:04:00:00:00:00:00:00:00

Offs 641: In use, 34 bytes,
-> Data: 06:05:09:42:65:61:6E:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00

Offs 675: Free, 54 bytes,
-> Data: 00:00:2F:00:FF:91:3E:02:01:7A:19:00:03:F4:50:DB:56:2A:43:17:02:01:1A:07:03:0D:18:0F:18:0A:18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D:18:0A:18:0B:09:4E:6F:72:D9

Offs 729: Free, 26 bytes,
-> Data: 17:02:01:1A:07:03:0D:18:0F:18:0A:18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D

Offs 755: Free, 45 bytes,
-> Data: 00:00:26:00:FF:D0:00:0D:00:03:F4:50:DB:56:2A:43:D9:17:D3:19:02:01:1A:07:03:0D:18:0F:18:0A:18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D

Offs 800: Free, 1248 bytes,
-> Data: 18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D:D1:04:00:00:00:00:00:00:36:00:00:00:2F:00:FF:91:3E:02:01:0E:1A:00:03:ED:C9:7B:3B:72:65:17:02:01:1A:07:03:0D:18:0F:18:0A:18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D:18:0A:18:0B:09:4E:6F:72:D1:1A:00:17:02:01:1A:07:03:0D:18:0F:18:0A:18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D:2D:00:00:00:26:00:FF:D0:00:0D:00:03:ED:C9:7B:3B:72:65:D1:17:67:1A:02:01:1A:07:03:0D:18:0F:18:0A:18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D:4C:04:18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D:3D:04:00:00:2B:00:FF:D0:00:0D:03:00:B5:D2:74:03:4B:24:AA:1C:A3:1A:1B:FF:75:00:42:04:01:80:20:24:4B:03:74:D2:B5:26:4B:03:74:D2:B4:01:00:00:00:00:00:00:0B:04:E2:0D:00:AA:1B:BB:1B:FD:01:0D:C0:AA:1F:BB:09:00:1F:FF:1F:A2:17:B3:07:2D:00:00:00:26:00:FF:D0:00:0D:00:03:37:E5:CC:A5:74:43:D3:17:EE:1A:02:01:1A:07:03:0D:18:0F:18:0A:18:0B:09:4E:6F:72:64:69:63:5F:48:52:4D:11:00:0B:09:4E:6F:72:64:69:63:5F:48:52:4D:48:52:4D:12:00:E2:F7:42:2B:40:83:EE:89:FF:89:20:81:0F:8C:02:C0:A6:03:BD:D5:F5:9F:47:9D:F8:BD:F7:F5:EB:DE:F7:7D:2F:BB:F5:A6:FF:47:B7:52:FD:91:FF:E2:CF:4C:FD:5B:FF:7A:D7:6D:FF:24:3F:06:FD:3D:C3:E6:EA:C8:5B:9D:EB:FF:7D:09:0F:D1:EA:C3:55:BD:1F:59:FA:BB:FF:FB:FF:BD:FD:F4:F7:87:F5:FE:FB:6F:7F:FF:7F:F7:BE:BE:EF:7B:67:DF:1B:F7:E3:EB:47:D3:FB:D4:FF:E2:6D:30:FF:89:F6:9D:FB:00:00:D9:12:BD:A5:F3:BF:9E:4B:7B:97:5F:B9:BF:77:ED:7F:5B:FF:7B:2B:E7:67:7B:7E:DC:BF:FC:FF:73:FE:B9:DB:E5:EC:FE:DF:5D:EF:74:6F:FE:FF:07:AF:FD:31:FF:F6:D7:F9:7B:DD:4F:B7:43:DF:7A:5B:42:71:9F:9D:EF:7F:0A:3E:6F:F6:77:F7:F5:FE:DD:EE:FD:CA:72:EB:F5:BF:DF:7B:BD:77:FD:FF:DD:D5:FA:FD:AF:F5:EF:AE:DB:F7:F6:FF:B3:6F:33:BF:CF:EE:F5:BF:3F:DF:FF:FC:10:A1:5A:FF:7A:EF:39:7F:78:EC:6F:FB:8F:F7:7A:DF:1E:DB:A2:1D:13:73:BE:BB:FF:7E:73:35:F4:7E:F3:9D:FC:FF:59:D6:CF:AF:F5:B7:FE:73:FA:AB:FF:6D:F7:FB:7F:18:EE:7D:BD:FB:6B:9F:DF:B7:DF:D6:A6:99:BE:DB:F7:FB:C7:6D:2E:5D:FE:FB:C4:11:89:F6:98:EB:04:BE:C4:EE:63:CF:F4:CA:D9:5E:CF:FA:FD:FF:A3:BF:FA:FD:FF:FF:DD:A7:D4:EB:3E:D9:3F:CE:2B:FD:FD:FB:E7:7A:F3:C4:83:FF:A7:35:17:FC:DA:AB:F9:FC:A7:C7:BD:CB:ED:3F:7F:55:FE:FF:70:EF:CD:A7:3D:6D:F6:FB:88:C7:BA:DF:18:EF:B3:D5:FF:FF:EE:FF:0F:FB:2D:B5:66:FE:7F:77:F3:D7:99:FF:18:82:DF:F8:DF:FA:DF:D5:8C:8D:FB:7F:9D:BD:E7:DF:DC:BD:5C:DF:B2:6B:7D:F7:77:BF:E5:FF:4D:2F:F2:FF:EB:5C:A8:E8:63:FF:F1:FF:9E:1F:40:FB:14:19:0D:CB:67:EF:FF:FF:CF:FD:FC:D2:F5:B7:DF:2F:E3:CF:27:7C:DA:FD:D1:7E:70:B5:6F:E1:89:CE:A0:DF:FB:93:FB:AA:BF:31:34:9F:FB:57:DE:BE:D5:7E:5A:F3:FE:7D:C6:AA:2D:EF:49:FF:33:F5:DC:37:A5:FF:C7:EE:6F:F5:FC:FE:C5:FF:7B:8D:FF:FE:BF:B7:ED:B1:BF:97:8F:E8:77:B5:FF:D9:FA:EF:97:5B:FF:A8:5F:7F:5F:7F:7F:1F:FA:FE:BE:DD:B6:79:D7:DF:7D:FE:97:DB:BF:7F:D9:D4:5A:DB:FD:76:D6:E4:E8:F1:D5:FE:DB:6E:85:DA:00:7D:FE:67:5A:47:D5:DC:AE:70:F6:97:DC:F2:DF:DF:A5:F7:F7:EE:FC:E6:DA:FF:C2:97:6D:3F:EB:FF:46:F6:CF:BB:FB:7F:E2:75:DD:FC:FD:7A:7D:D7:37:F3:9B:5B:EF:6F:FC:F6:3F:E3:57:77:CF:3F:56:E7:DE:EB:6E:EF:80:BF:EF:ED:B9:7E:F3:FA:8C:27:DB:EF:79:B5:79:EC:DF:5B:F4:F6:FF:25:7E:7F:FF:FF:AE:DE:DF:A9:8F:9F:39:F7:D5:7F:AF:FF:FB:3D:F7:65:FB:DF:9D:DD:FA:7D:EE:A2:B9:73:3F:FE:2B:AC:34:BB:EC:AD:C3:69:DE:5E:FA:FF:0D:5F:EC:FD:F6:F7:5B:BA:B6:7E:CE:7F:FD:FF:1D:3F:21:9B:7F:AF:EF:4F:FC:7F:EF:CD:FF:CE:DB:3D:B4:FF:BE:4E:86:BF:36:DA:5D:AF:9F:FF:87:BF:7F:9F:FF:BB:BD:B5:58:F9:8F:AD:B7:FD:26:6B:F2:FF:5F:FF:FE:EF:6E:DE:C7:2E:7E:3B:F1:D6:74:FD:1F:BF:FE:F7:91:5F:9D:B9:DD:FF:3E:ED:3D:B5:87:2B:EE:C7:EF:3F:7F:7B:F3:C7:F9:37:BD:D1:7F:F6:FE:B6:F5:7D:EA:FD:57:DF:BF:FC:5D:EF:D6:FB:7F:7E:3F:DF:D4:B6:0D:3F:37:B3:23:F7:B7:FE:FE:E3:DB:BF:E2:9D:EA:7B:BB:6D:AB:6F:FE:F7:EC:B5:74:9E:6E:66:BA:FF:77:DE:E7:B7:FE:6F:FB:FF:BB:B7:FF:EA:FF:7D:7F:BF:BF:49:5E:D7:E1:FB:9F:F9:D3:FE:EF:DD:CA:17:BE:FF:0E:FE:EB:AF:A9:E3:FD:8E:37:DE:7B:F7:5D:7F:B8:D2:FF:B4:8D:FD:B5:FB:B3:F7:77:9F:F6:7F:DD:E5:BF:FF:3F:3B:F0:FF:E3:DE:CB:FD:7F:D3:F3:9F:39:9F:71:3F:FE:FF:5D:EA:94:3F:73:9C:7F:DF:5C:EB:FE:FF:55

Offs 2048: Free, 0 bytes,
-> Data:

Hi Kianoosh,

Thank you for confirming. I suspect this condition is due to slower start up time with your 32kHz crystal. There are two options to solve this issue:

1. Upgrade to BLE 1.4.1 (preferred)
2. Adjust (increase) HAL_SLEEP_ADJ_TICKS in hal_sleep.c until you find a value that works for your system.

Best wishes

I apologize for being late in response to this thread.

1. Upgraded to BLE 1.4.1. Issue is still occurring.

2. Disabling PowerSavings is not an option. We adjusted the HAL_SLEEP_ADJ_TICKS to be larger and the issue is still occurring. 

3. Is there any reason that CTS has to be used if using UART DMA when POWER SAVINGS is enabled? We have modified the HAL code to disable the use of CTS in HalUARTOpenDMA()

Thanks

After taking a looking at the current consumption, it appears that CC2540 does not perform any scanning unless the scanning window falls into when the device it is advertising.

Take a look at the following screen shot:

D9 is set high when we enable scanning, when D9 is low it is either we have found a response through GAP_DEVICE_INFO_EVENT or scanning has ended via GAP_DEVICE_DISCOVERY_EVENT

GAP_DEVICE_DISCOVERY_EVENT

Hello everybody,

I have a question about who has to free the dynamic memory allocated from the stack, in particular for the Observer Event Callback Function.

I am working with a SensorTag (CC2650 based) and BLE-STACK-2-1-1, using the code from:

processors.wiki.ti.com/.../CC2640_Peripheral_Observer_V2_1

In this example the stack message is free in these lines:

static void SimpleBLEPeripheral_processAppMsg(sbpEvt_t *pMsg)
{
...

case SBP_OBSERVER_STATE_CHANGE_EVT:
SimpleBLEPeripheral_processStackMsg((ICall_Hdr *)pMsg->pData);

// Free the stack message
ICall_freeMsg(pMsg->pData);
break;
}

but if you see the content of the message there are other dynamic variables, in particular:

static void SimpleBLEPeripheralObserver_processRoleEvent(gapPeripheralObserverRoleEvent_t *pEvent)
{
switch (pEvent->gap.opcode)
{
case GAP_DEVICE_INFO_EVENT:
{
pEvent->deviceInfo.pEvtData; //uint8 *pEvtData; //!< Data field of advertisement or SCAN_RSP
break;
}
case GAP_DEVICE_DISCOVERY_EVENT:
{
pEvent->discCmpl.pDevList; //gapDevRec_t *pDevList; //!< array of device records
break;
}
...
}

Do the application have to take care about that dynamic variables separatly?
Thank you,

Kind Regards,
SF