CC1352P7: Beagleplay - using coprocessor binary in 1352, configured FH, 200kbps - higher incidence of spontaneous re-joins with larger channel list.

Hi Joshua,

1. You can do a simple noise floor test with SmartRF studio, just listen to the background noise where you're doing this test, just to make sure there's no noise disturbing the test.
2. Were you able to see the disconnect reason on the sensors before the re-join? It would be useful to know if there are specific channels that are prone to disconnect.
3. Is it the same sensors each time or does it vary between all of them? If it's the same ones you can check the frequency offset on these specific devices.
4. You say you're sing the DMM example. Are you also using BLE when this happens?

Cheers,

Marie H

Marie,

1.) I've not done this yet, but will and report back.

2.) I've not seen the disconnect reason. Could you provide any info on how best to capture this? I presume maybe the sync loss callback in the sensor could be instrumented?

3.)It varies across the population of sensors.

4.) I am using only advertising, and quite infrequently. A burst of 4 advertisements every 30 seconds. I did notice that the frequency of re-connects decreased a bit when I changed from exactly every 30 seconds to every 30.25 seconds. I did this because the sensors are sending data at 20 second intervals, and I didn't want the advertisements to beat with the data reports on every other third report cycle.

Marie,

Noise measurements for the 64 channels in use. It doesn't look concerning to me, what do you think?

If is is advisable to exclude the worst channels, do you have a recommended algorithm or method to do this? Is there an example?

Regards,

Josh

It appears that the noise is a red herring in this case.

What I've observed is that with the co-processor configuration, there's a lot of incorrectly formatted messages from the co-processor, which triggers a bug in the host_collector binary. Specifically, in the file mt_msg.c, in the function mt_msg_rx, the re-starting of parsing upon a rx checksum error doesn't work correctly. The issue is that the mt_msg isn't reset once an error occurs, so when the parsing re-starts, the code thinks there's already bytes in the receive buffer, which there are not. This leads to either no recover, or a very slow recovery. The fixed code (change starting at line 25) looks like this:

/*!
 * @brief - read a message from the interface.
 * @param pMI - msg interface
 * @returns NULL if no message received, otherwise a valid msg
 */
static struct mt_msg *mt_msg_rx(struct mt_msg_interface *pMI)
{
    int r;
    int nneed;
    struct mt_msg *pMsg;

    /* do we allocate a new message? */
    if(pMI->pCurRxMsg == NULL)
    {
        pMI->pCurRxMsg = MT_MSG_alloc(-1, -1, -1);
        /* allocation error :-(*/
        if(pMI->pCurRxMsg == NULL)
        {
            return (NULL);
        }
        pMI->pCurRxMsg->pLogPrefix = _incoming_msg;
        MT_MSG_setSrcIface(pMI->pCurRxMsg, pMI);
    }

    // JVT, move this block of code down below the try_again: label, so that when
    // a checksum or other error happens, the parsing is correctly restarted.

    //else
    //{
    //    MT_MSG_resetMsg(pMI->pCurRxMsg, -1, -1, -1);
    //}
    // pMsg = pMI->pCurRxMsg;
    // LOG_printf(LOG_DBG_MT_MSG_traffic,
    //            "%s: rx-msg looking for start\n",
    //            pMI->dbg_name);

try_again:
    /* zap what we have */
    MT_MSG_resetMsg(pMI->pCurRxMsg, -1, -1, -1);

    pMsg = pMI->pCurRxMsg;

    LOG_printf(LOG_DBG_MT_MSG_traffic,
               "%s: rx-msg looking for start\n",
               pMI->dbg_name);


    /* zap the existing buffer for debug reasons */
    memset((void *)(&(pMsg->iobuf[0])), 0, pMsg->iobuf_idx_max);

    /* how many bytes should we get? */
    nneed = (
        (pMI->frame_sync ? 1 : 0) + /* sync */
        (pMI->len_2bytes ? 2 : 1) + /* len */
        1 + /* cmd0 */
        1 + /* cmd1 */
        0 + /* unknown length yet */
        (pMI->include_chksum ? 1 : 0)); /* checksum */

read_more:
    r = mt_msg_rx_bytes(pMI, nneed, pMI->intermsg_timeout_mSecs);
    if(r == 0)
    {
        LOG_printf(LOG_DBG_MT_MSG_traffic, "%s: rx-silent\n", pMI->dbg_name);
        return (NULL);
    }

    if(r < 0)
    {
        /* something is wrong */
        LOG_printf(LOG_DBG_MT_MSG_traffic, "%s: Io error?\n", pMI->dbg_name);
        return (NULL);
    }

    /* we start reading at byte 0 in the message */
    pMsg->iobuf_idx = 0;

    /* should we find a frame sync? */
    if(pMI->frame_sync)
    {
        /* hunt for the sync byte */
        /* and move the sync byte to byte 0 in the buffer */
        uint8_t *p8;

        p8 = (uint8_t *)memchr((void *)(&pMsg->iobuf[0]),
                               0xfe,
                               pMsg->iobuf_nvalid);
        if(p8 == NULL)
        {
            /* not found */
            MT_MSG_log(LOG_DBG_MT_MSG_traffic | LOG_DBG_MT_MSG_raw,
                       pMsg, "Garbage data...\n");
            goto try_again;
        }

        /* frame sync must start at zero. */
        if(p8 != pMsg->iobuf)
        {
            /* need to shift data over some */

            /* how many bytes to shift? */
            int n;
            n = (int)(&(pMsg->iobuf[pMsg->iobuf_nvalid]) - p8);
            /* shift */
            memmove((void *)(&pMsg->iobuf[0]), (void *)p8, n);
            /* zero what we deleted */
            memset((void *)(&(pMsg->iobuf[n])), 0, pMsg->iobuf_nvalid - n);
            pMsg->iobuf_nvalid = n;
            /* Do we have enough bytes? */
            if(nneed > pMsg->iobuf_nvalid)
            {
                /* No - we need more, go get more */
                goto read_more;
            }
        }
        /* DUMMY read of the sync byte */
        MT_MSG_rdU8(pMsg);
    }

    /* Found start */
    /* how big is our length? */
    if(pMI->len_2bytes)
    {
        pMsg->expected_len = MT_MSG_rdU16(pMsg);
    }
    else
    {
        pMsg->expected_len = MT_MSG_rdU8(pMsg);
    }

    pMsg->cmd0 = MT_MSG_rdU8(pMsg);
    pMsg->cmd1 = MT_MSG_rdU8(pMsg);

    nneed += pMsg->expected_len;

    /* read the data component */
    r = mt_msg_rx_bytes(pMI, nneed, pMI->intersymbol_timeout_mSecs);
    if(r != nneed)
    {
        /* something is wrong? */
        if(r > 0)
        {
            /* we got some ... but not enough .. */
            LOG_printf(LOG_DBG_MT_MSG_raw,
                "Short read ... got: %d, want: %d, try again...\n",
                nneed, r);
            goto read_more;
        }
        MT_MSG_log(LOG_ERROR, pMsg, "%s: expected: %d, got: %d\n",
            pMI->dbg_name, nneed, r);
    dump_recover:
        LOG_printf(LOG_DBG_MT_MSG_traffic, "Flushing RX stream\n");
        /* Dump all incoming data until we find a sync byte */
        STREAM_rdDump(pMI->hndl, pMI->flush_timeout_mSecs);
        goto try_again;
    }

    /* Dummy read to the end of the data. */
    /* this puts us at the checksum byte (if present) */
    MT_MSG_rdBuf(pMsg, NULL, pMsg->expected_len);

    /* do the checksum */
    if(pMI->include_chksum)
    {
        r = MT_MSG_calc_chksum(pMsg, 'f', pMsg->iobuf_nvalid);
        if(r != 0)
        {
            MT_MSG_log(LOG_ERROR, pMI->pCurRxMsg, "%s: chksum error\n",
                pMI->dbg_name);
            LOG_hexdump(!LOG_ERROR, 0, pMsg->iobuf, pMsg->iobuf_nvalid);
            goto dump_recover;
        }
        else
        {
            //LOG_printf(LOG_DBG_MT_MSG, "chksum ok, message =\n");
            LOG_hexdump(LOG_DBG_MT_MSG_traffic, 0, pMsg->iobuf, pMsg->iobuf_nvalid);
        }
    }
    /* We have a message */
    MT_MSG_set_type(pMsg, pMsg->pSrcIface);
    /* Set the iobuf_idx to the start of the payload */

    /* since we will be parsing the message... */
    /* Set the iobuf_idx to the start of the payload */
    pMsg->iobuf_idx = (
        (pMI->frame_sync ? 1 : 0) +
        (pMI->len_2bytes ? 2 : 1) +
        1 + /* cmd0 */
        1 /* cmd1 */
       );
    /* next time we need to allocate a new message */
    pMI->pCurRxMsg = NULL;

    /* return our message */
    return (pMsg);
}

I have other findings as well, about the source of the corrupted data, but I will add another reply for that.

The other finding is that there definitely seems to be a problem with the MAC co-processor, which leads to the corrupted messages, and also sometimes to crashes, and even in a few cases overwritten flash.

I'm running a mostly unmodified collector. I've added one feature to read out the free heap, status of message queues and such, and I've increased some stack sizes, but other than that, it's a stock TI project.

In my test setup, I've got 8 sensors, 3 of which are reporting at 2-10 second intervals, the remaining 5 are reporting at 100 mS intervals, and sending ~60 byte packets. When running this way, the co-processor emits a defective packet approximately once per hour, and at least last night, froze after about 5 hours of running. Because of the previously described issue with the host_collector not correctly recovering, this issue was hard to discern.

I proceeded to perform the following investigations:

1. I read out the entire flash memory using UniFlash, in this case, the only change was to the area used for non-volatile storage. In the past, I've seen the last block of flash erased.
2. I attached the debugger without resetting the target. The code did not operate correctly, and was running code in the 0x10000000 region of memory. Resetting the device with the reset pin did not restore proper operation.
3. Using the "restart" button in the debugger did restore proper operation, until the next time I reset the device via the reset pin. This suggests that something that happens very early in the startup code (that the debugger bypasses when using the reset button to restart the app) is going wrong.
4. The only thing that fully restored proper operation was a full power down of the board. Upon powering back up, with no other changes, the 1352 booted normally whenever the reset line was toggled.

All of this suggests something along the lines of a wild write to memory outside of the intended buffer, perhaps hitting some control register in the device that isn't fully re-configured on a pin reset.

Hi Joshua,

Can you test with the 50 kbps PHY and see if it's reproducible?

Cheers,

Marie H