SimpleLink driver 1.0.1.6 blocks very rarely on sl_Stop() / SL_DRV_SYNC_OBJ_WAIT_TIMEOUT / _SlDrvRxHdrRead

Hello Achim!

How are you verifying that this is happening in a call to sl_Stop()? Can you elaborate on what the overall application you are working with is doing before you see it get blocked?

Based on your description of what you see on success, this doesn't match up with the result of a call to sl_Stop() -

The "0xBEDCCDAB" you are seeing would be the SYNC pattern and the next four bytes ("0x0714") are the opcode, with the lower byte first. So this would translate to an opcode of 0x1407 which is defined as SL_OPCODE_SOCKET_SELECTRESPONSE in protocol.h. You would not see that on a response from the NWP after a call to sl_Stop().

Best Regards,
Ben Moore

Hello Ben,

I added some "printf" in my code, which leads me closer to the problem.

Then, when the "driver thread" stucks at _SlDrvRxHdrRead,

while ( *(_u32 *)&pBuf[0] == *(_u32 *)&pBuf[4])
{
NWP_IF_READ_CHECK(g_pCB->FD, &pBuf[4], 4);
}

I just checked, where my application thread stucks and it was sl_Stop(),

SL_DRV_SYNC_OBJ_WAIT_TIMEOUT(&g_pCB->ObjPool[ObjIdx].SyncObj, STOP_DEVICE_TIMEOUT, SL_DRIVER_API_DEVICE_SL_STOP);

Thinking on your answer, I get aware, that my data for the "success case" is not that of "sl_Stop()", I just toke the data of "any other " successfull message sync. With that aware, I repeat my analysis and the data in sl_Stop success is:

"BFDCCDAB 73000800" SL_OPCODE_DEVICE_STOP_ASYNC_RESPONSE

But by the way, though the app thread and the driver thread are asynchron, the _SlDrvRxHdrRead, when blocking, may be related to anything else and with "02000000 02000000" there is no clear indicator, just that this is no message sync.

My context, was:

sl_NetCfgSet(SL_IPV4_STA_P2P_CL_DHCP_ENABLE,IPCONFIG_MODE_ENABLE_IPV4,1,&val);
sl_Stop(255);
sl_Start(NULL,NULL,NULL);

and "sl_Stop(255)" doesn't return and the driver stucks at "_SlDrvRxHdrRead" in that loop.

And therefore my question:

/* 2. Read 8 bytes (protocol aligned) - expected to be the sync pattern */
NWP_IF_READ_CHECK(g_pCB->FD, &pBuf[0], 8);
_SL_DBG_SYNC_LOG(SyncCnt,pBuf);

/* read while first 4 bytes are different than last 4 bytes */
while ( *(_u32 *)&pBuf[0] == *(_u32 *)&pBuf[4])
{
NWP_IF_READ_CHECK(g_pCB->FD, &pBuf[4], 4);
}

How is that code related to the specified message synchronization?

Hello Ben,

after testing a little more:

sl_Stop() is not be blocked, it is just "starving"!

When, after
1. "VERIFY_RET_OK(_SlDrvCmdOp((_SlCmdCtrl_t *)&_SlStopCmdCtrl, &Msg, NULL));" and receiving
2. "BFDCCDAB 73000800" SL_OPCODE_DEVICE_STOP_ASYNC_RESPONSE

an additional "IRQ" is triggerd (accidently), the _SlDrvRxHdrRead blocks in

while ( *(_u32 *)&pBuf[0] == *(_u32 *)&pBuf[4])
{
NWP_IF_READ_CHECK(g_pCB->FD, &pBuf[4], 4);
}

When "forcing that" (without real IRQ) I got a stuck with "06000000 06000000". I clear my SPI buffer, so I believe the "stopped" WiFi module will answer with "06000000" repeatly.

So, why does _SlDrvRxHdrRead not ensure to read back the "BxDCCDAB"?
This would not block. Are there modules, which are known not to use that sync pattern?

Hi Achim,

Your analysis is exact.

The protocol verification for comparing first 4 bytes with later 4 bytes is used to detect SYNC and then payload (of opcode and length).

In case of false IRQ, it seems the 4 bytes pattern repeats itself and thus causing the device to get stuck.

Although a false interrupt should not occur, it still needs to be protected. I agree.

Please note that statistics would get much better if the code would look for the pattern but failing case as you describe would still be possible (if the bytes remaining on the SPI lines would match the SYNC).

I need to take it with R&D to understand more the possible fixes.

Regards,

Shlomi

also please let me know if you are using CC3200 or CC3100

CC3100R
CHIP 0x4000000
MAC 31.1.4.0.1
PHY 1.0.3.34
NWP 2.6.0.5
ROM 0x3333
HOST 1.0.1.6

so it's a CC3100R

Hi,

You are describing a case in which a false host IRQ triggers the driver and makes it gets stuck.

You cannot check for SYNC pattern in this case since it would still be stuck. You can see that you get the same pattern in case of false IRQ so how would asking for SYNC pattern help? Please note that in a good case, you send a SYNC from host to NWP and waits for SYNC from NWP.

In any case, the only way to recover here is to use the timeout mechanism on commands. In case of sl_stop(), the long timeout of 64 seconds is used for waiting on async response. You can change it to a few seconds and in case you fall in timeout, just procede as usual and deassert the enable line to the device.

The code section is inside sl_stop():

sl_IfRegIntHdlr(NULL, NULL);
sl_DeviceDisable();
RetVal = sl_IfClose(g_pCB->FD);

(void)_SlDrvDriverCBDeinit();

Shlomi

Hi,

as long, as the "spawn task" executes the "endless loop",

while ( *(_u32 *)&pBuf[0] == *(_u32 *)&pBuf[4])
    {
         NWP_IF_READ_CHECK(g_pCB->FD, &pBuf[4], 4);
    }

I don't see a solution.

So as far as I understand, this while loop should be limited somw how (counter?).

Without that, the "spawn task" must be killed and recreate, including mutex and so on.

best regards

Achim

Hi Achim,

I agree, however, the new timeout mechanism that is going to be introduced soon to the host driver is implemented upon any transaction with the device.

So timeout would be part of any command complete as well as timeout on the time from host interrupt to first reading SYNC pattern.

I need to verify when this drop is going to be published.

Shlomi

Hi Shlomi,

Do you have an update when the fix for this is going to be published? I'm seeing the same thing with host 1.0.0.10 combined with the MAC/PHY/NWP versions from above.

Thanks,
-Ed

Hi Shlomi/Achim,

I also wanted to ask, do you know why the unexpected host interrupt occurs? In our case, the unexpected interrupt always occurs just before the host reads out the 4 bytes associated with the beginning of the SL_OPCODE_DEVICE_STOP_ASYNC_RESPONSE message (i.e. the bytes read after the unexpected interrupt are 0x73, 0x00, 0x08, 0x00). The really odd thing about our failure scenario is that it seems to happen for awhile with fresh serial flash parts, but after awhile, the issue stops happening. May be a red herring, but it's happened with 3 boards in a row.

Thanks,
-Ed

Hi Ed,

unfortunately, I don't have direct access to our hardware lab and so I simply wait also on their verification :-) .
As far as I could analyse it (software only, debugger and with long testing hours/days), it mainly occurs on that SL_OPCODE_DEVICE_STOP_ASYNC_RESPONSE, but also sometimes on restartup and on a device of my colleague,
even on "sl_select"!

So my countermeasure:
- ensure, that sl_IfMaskIntHdlr and sl_IfUnmaskIntHdlr are implemented proper
- clear pending interrupts on reenable
- limit the loop and ignore, if it expires (instead of processing it as failure).

With that our devices are able to run much longer.

best regards
Achim

Hi Ed,

Unexpected interrupts from the NWP itself should not occur. If it was a valid interrupt, it would contain valid pattern and metadata so it would not get stuck.

However, false host IRQ can happen in systems and should be handled and as I mentioned before, a timeout mechanism should handle it.

Unfortunatelly, host driver which introduce this mechanism is not out yet. As soon as I have more info, will let you know.

Shlomi

Hi Achim,

Thanks for the reply. As for your countermeasure, is your host interrupt edge triggered or level triggered? The reason I ask is the user.h file indicates that nothing needs to be implemented for sl_IfMaskIntHdlr() and sl_IfUnmaskIntHdlr() if the host interrupt is edge triggered (which it is in our system). And when I look at the timing of the sl_Stop() SPI traffic, we are getting a host interrupt just after reading the message header containing SL_OPCODE_DEVICE_STOP_RESPONSE. So if we were to mask the host interrupt, we wouldn't spawn any task to read the SL_OPCODE_DEVICE_STOP_ASYNC_RESPONSE, and the device would still be stuck (unless we also implemented the loop limit you mentioned).

I'll try implementing the loop limit that you did and see what happens.

Thanks!

-Ed

Hi Ed,

we're also using edge triggered interrupts.

We're using (host) driver version "1.0.1.6" and the in the "template_user.h" I didn't read that hint (at least I can't find it nearby the proting macros).

But even if I would have read it, I would have implemented the unmask/masking stuff:

- because I'm in doubt, if perhaps "additional noise" made it trought the "noise canceler"

- especially in shutdown/restart of the WiFi Module, the WiFi Module may unintentially emit also such noise

- debugger shows a difference more then 1 between "RxDoneCnt is 217 and  RxIrqCnt is 219".

And yes, the mask/unmask alone will no work, the loop limit seems to be required.

Hi Achim,

You are correct that the information about not needing to implement sl_IfMaskIntHdlr() and sl_IfUnmaskIntHdlr() is not in the template user.h file - someone added it to our user.h file. However, the comment about that can be found here: http://processors.wiki.ti.com/index.php/CC31xx_Host_Interface.

We are using host driver 1.0.0.10, so this may not apply to you, but it looks to me like you can't mask HOST_INT, because sl_Stop() would not receive the interrupt associated with the SL_OPCODE_DEVICE_STOP_ASYNC_RESPONSE. Here is a logic analyzer capture of a typical call to sl_Stop():

The signal labelled HOST_INT is the host interrupt signal from the CC3100. The signal TP23 is set at the beginning of _SlDrvMsgRead(), and is cleared just before the call to sl_IfUnMaskIntHdlr() at the end of _SlDrvMsgRead(). As can be seen, the second HOST_INT in this capture would be missed if it was masked. I'm not sure if this is the behavior you would see on your hardware or not. Either way, we both seem to eventually fail for exactly the same reason.

HI Ed,

I think, this depends on the "exact" definition of mask and unmask an IRQ. I searched for that defintion but couldn't find more information within the simple link stuff.

I see two variants:
1. mask stops IRQ processing, but events are stills stored in the flags. After unmask, the set flag then triggers the interrupt immediatly.
2. mask stops IRQ processing and events are not stored in the flags. After unmask, all past events are ignored and only new events will trigger the interrupt.

For me the 2. behaviour is more a disable/enable interrupt. So my hope is, that TI meant the 1 behaviour. But this may depend on the specification of the host mcu.

Hi Achim,

That's a good point. Shlomi - can you comment on this?

1) If the host is using edge triggered interrupts, do sl_IfMaskIntHdlr and sl_IfUnMaskIntHdlr need to be implemented?

2) If sl_IfMaskIntHdlr and sl_IfUnMaskIntHdlr do need to be implemented for edge triggered interrupts, does option 1 or option 2 in Achim's previous post describe the expected implementation?

Thanks!

-Ed