CyU3PDebugPrint glDebugLock deadlock

Tip / Sign in to post questions, reply, level up, and achieve exciting badges. Know more

cross mob
user_4770066
Level 1
Level 1
First question asked First reply posted Welcome!

Hello!

I'm building a UVC device based on the FX3 SDK 1.3.4.

My firmware prints lots of debug output via UART and hangs after a while.

Using the debugger, I found that several threads seem to be waiting for the glDebugLock mutex:

pastedImage_0.png

Some thread owns the mutex, but it does not print any new output.

I checked the source code of CyU3PDebugPrint and noticed that there is no CyU3PMutexPut call before the first return:

CyU3PReturnStatus_t

CyU3PDebugPrint (

        uint8_t priority,

        char *message,

        ...)

{

...

    CyU3PMutexGet (&glDebugLock, CYU3P_WAIT_FOREVER);

...

    stat = CyU3PDmaChannelCommitBuffer (&glDebugChanHandle, limit, 0);

    if (stat == CY_U3P_SUCCESS)

    {

        stat = CyU3PDmaChannelGetBuffer (&glDebugChanHandle, &glDebugBuf_p, glDbgTimeout);

    }

    if (stat != CY_U3P_SUCCESS)

    {

        CyU3PDebugChannelReset ();

        return stat;

    }

    glDebugBufOffset = 0;

    CyU3PMutexPut (&glDebugLock);

    return CY_U3P_SUCCESS;

}

If the CyU3PDmaChannelCommitBuffer or the CyU3PDmaChannelGetBuffer call fails, the function will exit early and the glDebugLock mutex will not be unlocked. Any future call to CyU3PDebugPrint from a different thread will block indefinitely.

Is it actually intended to return early from that function? Other functions like CyU3PDebugLogFlush do not return after calling CyU3PDebugChannelReset.

Regards,

Tobias

0 Likes
1 Solution

Hello Tobias,

Glad to hear that removing the CyU3PDebugPrint call from the DMA callback solved the problem.

For the First problem,  your understanding is correct. That is the reason the debug prints in the DMA callback fail. But this problem is generally seen in the cases where the data transfer through DMA channels are at high rate like UVC application. As in the AN75779, the DMA callback will be triggered too frequently, hence the chances of debug print API failing increases. So, in such kind of applications where the callbacks are triggered too frequently we recommend not to use CyU3PDebugPrint API / or any blocking API

For the second problem, I am trying to do some more tests to confirm the issue. I will update you on this as soon as possible.

EDITED:

After some tests and checking up internally, I can confirm that in CyU3PDebugPrint the Mutex lock should have been released when returning early from the function due to failure of CyU3PDmaChannelGetBuffer API.

Thank you for bringing the error to our notice.

I have reported this error to the respective team and the error would be fixed in the next SDK release.

Regards,

Rashi

Regards,
Rashi

View solution in original post

0 Likes
6 Replies
Rashi_Vatsa
Moderator
Moderator
Moderator
5 likes given 500 solutions authored 1000 replies posted

Hello Tobias,

As you mentioned that CyU3PDebugPrint API is called at many instances in the firmware, please let me know if CyU3PDebugPrint is called inside the DMA callback or any other callbacks

My firmware prints lots of debug output via UART and hangs after a while.

>> Please let me know approx how many bytes are written using UART debug prints from one thread and how many such threads are running in your firmware.

>> Also, let me know the return status of CyU3PDebugPrint when the UART prints hang.

Regards,

Rashi

Regards,
Rashi
0 Likes

Hello Rashi,

CyU3PDebugPrint is called in the main thread, the DMA callback, the PIB callback and the UIB callback (mainly to report errors).

The output is approximately less than 40 lines or 2kb per second

If glDebugLock is locked, CyU3PDebugPrint won't return.

I logged previous return values in an array: 0 (CY_U3P_SUCCESS), 19 (CY_U3P_ERROR_INVALID_CALLER) and 29 (CY_U3P_ERROR_MUTEX_FAILURE).

CY_U3P_SUCCESS and CY_U3P_ERROR_INVALID_CALLER can be returned by CyU3PDebugPrint.

But CY_U3P_ERROR_MUTEX_FAILURE does not appear in that function, so it must have been returned by CyU3PDmaChannelCommitBuffer or CyU3PDmaChannelGetBuffer. This means that "return stat" in line 18 (originally line 548) was executed and that glDebugLock was not released.

Regards,

Tobias

0 Likes

Hello Tobias,

We do not recommend to call CyU3PDebugPrint inside the callback function.

fx3 DmaMultiChannel Manual_Many_to_one always hang in the dma callback

How to print debug message in timer call back function.

As per section 5.17.2.2 of FX3 API guide (SDK), no blocking calls should be made from the DMA  callback function

The CyU3PDebugPrint() API can encounter a failure when invoked from a callback function. You can check the return value of the API by setting it to a global variable and reading it in the thread main loop.

Please let me know if the problem still occurs when the CyU3PDebugPrint is removed from the callback function. Meanwhile, I will try to reproduce the issue at my end.

Regards,

Rashi

Regards,
Rashi
0 Likes

Hello Rashi,

Thanks for the tips. I think my problem actually consists of two independent problems.

First problem:

I had a closer look at the call stacks again when the deadlock occurred.

  • The main thread called CyU3PDebugPrint. This function first locked the glDebugLock mutex and then called CyU3PDmaChannelGetBuffer. That function in turn called CyU3PEventGet to wait for an event in the glDebugChanHandle DMA channel.
  • The DMA callback also called CyU3PDebugPrint, but it has to wait because the glDebugLock mutex is already locked.

This is a deadlock because:

  • The main thread is waiting for the DMA thread to set an event.
  • The DMA thread is waiting for the main thread to release glDebugLock.

I removed the CyU3PDebugPrint call from the DMA callback and the deadlock seems to be solved.

You might want to update the firmware examples in the SDK, though. CyU3PDebugPrint is called in the DMA callbacks of several examples (CyFxBulkSrcSinkDmaCallback, CyFxIsoSrcSinkDmaCallback, CyFxSlFifoUtoPDmaCallback, CyFxBulkLpDmaCallback, and many more).

Second problem:

I wrote a short test for the unbalanced CyU3PMutexGet/CyU3PMutexPut calls in CyU3PDebugPrint.

#include "cyu3system.h"

#include "cyu3error.h"

#include "cyu3uart.h"

int main(void) {

    CyU3PSysClockConfig_t clkCfg = { };

    clkCfg.cpuClkDiv = 2;

    clkCfg.dmaClkDiv = 2;

    clkCfg.mmioClkDiv = 2;

    clkCfg.clkSrc = CY_U3P_SYS_CLK;

    clkCfg.setSysClk400 = CyTrue;

    clkCfg.useStandbyClk = CyFalse;

    CyU3PReturnStatus_t status = CyU3PDeviceInit(&clkCfg);

    if (status != CY_U3P_SUCCESS)

        goto handle_fatal_error;

    status = CyU3PDeviceCacheControl(CyTrue, CyFalse, CyFalse);

    if (status != CY_U3P_SUCCESS)

        goto handle_fatal_error;

    CyU3PKernelEntry();

    return 0;

    handle_fatal_error: while (1)

        CyFx3BusyWait(100);

}

void Thread_Entry(uint32_t input) {

    static int i;

    for (;;) {

        for (int j = 0; j < 10; j++)

            CyU3PDebugPrint(4, "Thread %d %d\r\n", input, i++);

        CyU3PThreadSleep(input);

    }

}

CyU3PThread thread1;

CyU3PThread thread2;

void CyFxApplicationDefine(void) {

    CyU3PIoMatrixConfig_t io_cfg = { };

    io_cfg.isDQ32Bit = CyTrue;

    io_cfg.lppMode = CY_U3P_IO_MATRIX_LPP_DEFAULT;

    io_cfg.useUart = CyTrue;

    io_cfg.useI2C = CyTrue;

    CyU3PDeviceConfigureIOMatrix(&io_cfg);

    CyU3PUartConfig_t uartConfig = { };

    uartConfig.baudRate = CY_U3P_UART_BAUDRATE_115200;

    uartConfig.stopBit = CY_U3P_UART_ONE_STOP_BIT;

    uartConfig.parity = CY_U3P_UART_NO_PARITY;

    uartConfig.txEnable = CyTrue;

    uartConfig.isDma = CyTrue;

    CyU3PUartInit();

    CyU3PUartSetConfig(&uartConfig, NULL);

    CyU3PUartTxSetBlockXfer(0xFFFFFFFF);

    CyU3PDebugInit(CY_U3P_LPP_SOCKET_UART_CONS, 8);

    CyU3PDebugSetTimeout(0);

    CyU3PDebugPreamble(CyFalse);

    CyU3PThreadCreate(&thread1, "21:thread1", Thread_Entry, 1,

            CyU3PMemAlloc(0x1000), 0x1000, 8, 8, CYU3P_NO_TIME_SLICE,

            CYU3P_AUTO_START);

    CyU3PThreadCreate(&thread2, "22:thread2", Thread_Entry, 2,

            CyU3PMemAlloc(0x1000), 0x1000, 8, 8, CYU3P_NO_TIME_SLICE,

            CYU3P_AUTO_START);

}

Only one thread can print something and the tx_mutex_ownership_count of glDebugLock increases rapidly:

pastedImage_5.png

The ownership count should never exceed 1 or maybe 2.

Regards,

Tobias

0 Likes

Hello Tobias,

Glad to hear that removing the CyU3PDebugPrint call from the DMA callback solved the problem.

For the First problem,  your understanding is correct. That is the reason the debug prints in the DMA callback fail. But this problem is generally seen in the cases where the data transfer through DMA channels are at high rate like UVC application. As in the AN75779, the DMA callback will be triggered too frequently, hence the chances of debug print API failing increases. So, in such kind of applications where the callbacks are triggered too frequently we recommend not to use CyU3PDebugPrint API / or any blocking API

For the second problem, I am trying to do some more tests to confirm the issue. I will update you on this as soon as possible.

EDITED:

After some tests and checking up internally, I can confirm that in CyU3PDebugPrint the Mutex lock should have been released when returning early from the function due to failure of CyU3PDmaChannelGetBuffer API.

Thank you for bringing the error to our notice.

I have reported this error to the respective team and the error would be fixed in the next SDK release.

Regards,

Rashi

Regards,
Rashi
0 Likes

Hello Tobias,

After some tests and checking up internally, I can confirm that in CyU3PDebugPrint the Mutex lock should have been released when returning early from the function due to failure of CyU3PDmaChannelGetBuffer API.

Thank you for bringing the error to our notice.

I have reported this error to respective team and the error would be fixed in the next SDK release.

Regards,

Rashi

Regards,
Rashi
0 Likes