[BUG]Function named "freeSampleStreamingSession" called "timerQueueCancelTimer", only enter "timerQueueCancelTimer" but not exited, please confirm！ #1273

August88618 · 2021-09-17T08:35:31Z

I added printing before and after calling the function, as follows：
MUTEX_LOCK(pSampleConfiguration->configurationObjLock);
if (pSampleConfiguration->iceCandidatePairStatsTimerId != MAX_UINT32 && pSampleConfiguration->streamingSessionCount == 0 &&
pSampleConfiguration->iceCandidatePairStatsTimerId != MAX_UINT32) {
AEDA_LOG_INFO(MODULE, "CY1111:timerQueueCancelTimer begin");
CHK_LOG_ERR(timerQueueCancelTimer(pSampleConfiguration->timerQueueHandle, pSampleConfiguration->iceCandidatePairStatsTimerId,
(uint64_t)(uint32_t)pSampleConfiguration));
AEDA_LOG_INFO(MODULE, "CY1111:timerQueueCancelTimer end");
pSampleConfiguration->iceCandidatePairStatsTimerId = MAX_UINT32;
}
MUTEX_UNLOCK(pSampleConfiguration->configurationObjLock);

When our IPC is abnormal，the last time "timerQueueCancelTimer" was called, only begin but not end.The log reference is as follows
errorLog.txt
：

hassanctech · 2021-09-17T13:21:37Z

Can you please post which release/version of the SDK you're using and what platform you're on (i.e. Linux/Mac/Windows) and other important details about your platform?

hassanctech · 2021-09-17T13:27:44Z

Also what is the impact of what you are seeing do you suspect a deadlock? There is nothing blocking in timerQueueCancelTimer except for waiting to lock the executorLock, it looks like we first acquire configurationObjLock then wait for the executorLock perchance another thread is doing this in the reverse order, we will need to investigate.

August88618 · 2021-09-18T02:08:53Z

A、SDK version is webrtc-sdk-c-update-libwebsockets-4.2-stable，platform is linux，cross-compiling tool named arm-linux-gnueabihf-gcc4.9.4-uclibc1.0.31-
B、Yes，I suspect it's a deadlock，but I don't see timerQueueCancelTimer waiting for ”configurationObjLock“,because I added printing in SessionCleanupWait when it get ”configurationObjLock“，after obtaining the lock, proceed with the following process.Function call procedure：SessionCleanupWait--->...--->get sampleConfigurationObjLock(get lock success)--->...--->get streamingSessionListReadLock(get lock success)--->...--->freeSampleStreamingSession--->...--->(get lock success) timerQueueCancelTimer, only begin but not end.

ilyaikik · 2021-09-18T14:21:34Z

As I remember I've faces similar problem.

Try to add IS_VALID checker to this part of code

// De-initialize the session stats timer if there are no active sessions
    // NOTE: we need to perform this under the lock which might be acquired by
    // the running thread but it's OK as it's re-entrant
    MUTEX_LOCK(pSampleConfiguration->sampleConfigurationObjLock);
    if (pSampleConfiguration->iceCandidatePairStatsTimerId != MAX_UINT32 && pSampleConfiguration->streamingSessionCount == 0 &&
        pSampleConfiguration->iceCandidatePairStatsTimerId != MAX_UINT32) {
        CHK_LOG_ERR(timerQueueCancelTimer(pSampleConfiguration->timerQueueHandle, pSampleConfiguration->iceCandidatePairStatsTimerId,
                                          (UINT64) pSampleConfiguration));
        pSampleConfiguration->iceCandidatePairStatsTimerId = MAX_UINT32;
    }
    MUTEX_UNLOCK(pSampleConfiguration->sampleConfigurationObjLock);

to

// De-initialize the session stats timer if there are no active sessions
    // NOTE: we need to perform this under the lock which might be acquired by
    // the running thread but it's OK as it's re-entrant
    MUTEX_LOCK(pSampleConfiguration->sampleConfigurationObjLock);
    if (pSampleConfiguration->iceCandidatePairStatsTimerId != MAX_UINT32 && pSampleConfiguration->streamingSessionCount == 0 &&
        pSampleConfiguration->iceCandidatePairStatsTimerId != MAX_UINT32)
    {
        if (IS_VALID_TIMER_QUEUE_HANDLE(pSampleConfiguration->timerQueueHandle))
        {
            CHK_LOG_ERR(timerQueueCancelTimer(pSampleConfiguration->timerQueueHandle, pSampleConfiguration->iceCandidatePairStatsTimerId,
                                              (UINT64)pSampleConfiguration));
            pSampleConfiguration->iceCandidatePairStatsTimerId = MAX_UINT32;
        }
    }
    MUTEX_UNLOCK(pSampleConfiguration->sampleConfigurationObjLock);

and modify freeSampleConfiguration (sorry for debug messages):

STATUS freeSampleConfiguration(PSampleConfiguration *ppSampleConfiguration)
{
    ENTERS();
    STATUS retStatus = STATUS_SUCCESS;
    PSampleConfiguration pSampleConfiguration;
    UINT32 i;
    UINT64 data;
    StackQueueIterator iterator;
    BOOL locked = FALSE;
    printf("free 0");
    CHK(ppSampleConfiguration != NULL, STATUS_NULL_ARG);
    pSampleConfiguration = *ppSampleConfiguration;
    printf("free 1");
    CHK(pSampleConfiguration != NULL, retStatus);
    printf("free 2");

    if (IS_VALID_TIMER_QUEUE_HANDLE(pSampleConfiguration->timerQueueHandle))
    {
        if (pSampleConfiguration->iceCandidatePairStatsTimerId != MAX_UINT32)
        {
            printf("free 19\n\r");
            printf("FREE 19: %ull, %ull\n\r", pSampleConfiguration->timerQueueHandle, pSampleConfiguration->iceCandidatePairStatsTimerId);
            retStatus = timerQueueCancelTimer(pSampleConfiguration->timerQueueHandle, pSampleConfiguration->iceCandidatePairStatsTimerId,
                                              (UINT64)pSampleConfiguration);
            if (STATUS_FAILED(retStatus))
            {
                DLOGE("Failed to cancel stats timer with: 0x%08x", retStatus);
            }
            pSampleConfiguration->iceCandidatePairStatsTimerId = MAX_UINT32;
        }
        printf("free 20");
        if (pSampleConfiguration->pregenerateCertTimerId != MAX_UINT32)
        {
            printf("free 21");
            retStatus = timerQueueCancelTimer(pSampleConfiguration->timerQueueHandle, pSampleConfiguration->pregenerateCertTimerId,
                                              (UINT64)pSampleConfiguration);
            if (STATUS_FAILED(retStatus))
            {
                DLOGE("Failed to cancel certificate pre-generation timer with: 0x%08x", retStatus);
            }
            pSampleConfiguration->pregenerateCertTimerId = MAX_UINT32;
        }
        printf("free 22");
        timerQueueFree(&pSampleConfiguration->timerQueueHandle);
    }

    if (pSampleConfiguration->pPendingSignalingMessageForRemoteClient != NULL)
    {
        // Iterate and free all the pending queues
        stackQueueGetIterator(pSampleConfiguration->pPendingSignalingMessageForRemoteClient, &iterator);
        while (IS_VALID_ITERATOR(iterator))
        {
            stackQueueIteratorGetItem(iterator, &data);
            stackQueueIteratorNext(&iterator);
            printf("free 3");
            freeMessageQueue((PPendingMessageQueue)data);
        }
        printf("free 4");
        stackQueueClear(pSampleConfiguration->pPendingSignalingMessageForRemoteClient, FALSE);
        stackQueueFree(pSampleConfiguration->pPendingSignalingMessageForRemoteClient);
        pSampleConfiguration->pPendingSignalingMessageForRemoteClient = NULL;
    }
    printf("free 5");
    hashTableClear(pSampleConfiguration->pRtcPeerConnectionForRemoteClient);
    hashTableFree(pSampleConfiguration->pRtcPeerConnectionForRemoteClient);
    printf("free 6");
    if (IS_VALID_MUTEX_VALUE(pSampleConfiguration->sampleConfigurationObjLock))
    {
        MUTEX_LOCK(pSampleConfiguration->sampleConfigurationObjLock);
        locked = TRUE;
    }
    printf("free 7");
    for (i = 0; i < pSampleConfiguration->streamingSessionCount; ++i)
    {
        retStatus = gatherIceServerStats(pSampleConfiguration->sampleStreamingSessionList[i]);
        if (STATUS_FAILED(retStatus))
        {
            DLOGW("Failed to ICE Server Stats for streaming session %d: %08x", i, retStatus);
        }
        printf("free 8");
        freeSampleStreamingSession(&pSampleConfiguration->sampleStreamingSessionList[i]);
    }
    printf("free 9");
    if (locked)
    {
        MUTEX_UNLOCK(pSampleConfiguration->sampleConfigurationObjLock);
    }
    printf("free 10");
    // deinitKvsWebRtc();
    printf("free 11");
    SAFE_MEMFREE(pSampleConfiguration->pVideoFrameBuffer);
    SAFE_MEMFREE(pSampleConfiguration->pAudioFrameBuffer);
    printf("free 12");
    if (IS_VALID_CVAR_VALUE(pSampleConfiguration->cvar) && IS_VALID_MUTEX_VALUE(pSampleConfiguration->sampleConfigurationObjLock))
    {
        CVAR_BROADCAST(pSampleConfiguration->cvar);
        MUTEX_LOCK(pSampleConfiguration->sampleConfigurationObjLock);
        MUTEX_UNLOCK(pSampleConfiguration->sampleConfigurationObjLock);
    }
    printf("free 13");
    if (IS_VALID_MUTEX_VALUE(pSampleConfiguration->sampleConfigurationObjLock))
    {
        MUTEX_FREE(pSampleConfiguration->sampleConfigurationObjLock);
    }
    printf("free 14");
    if (IS_VALID_MUTEX_VALUE(pSampleConfiguration->streamingSessionListReadLock))
    {
        MUTEX_FREE(pSampleConfiguration->streamingSessionListReadLock);
    }
    printf("free 15");
    if (IS_VALID_MUTEX_VALUE(pSampleConfiguration->signalingSendMessageLock))
    {
        MUTEX_FREE(pSampleConfiguration->signalingSendMessageLock);
    }
    printf("free 16");
    if (IS_VALID_CVAR_VALUE(pSampleConfiguration->cvar))
    {
        CVAR_FREE(pSampleConfiguration->cvar);
    }
    printf("free 17");
    freeStaticCredentialProvider(&pSampleConfiguration->pCredentialProvider);
    printf("free 18");
    // if (IS_VALID_TIMER_QUEUE_HANDLE(pSampleConfiguration->timerQueueHandle)) {
    //     if (pSampleConfiguration->iceCandidatePairStatsTimerId != MAX_UINT32) {
    //         printf("free 19\n\r");
    //         printf("FREE 19: %ull, %ull\n\r", pSampleConfiguration->timerQueueHandle, pSampleConfiguration->iceCandidatePairStatsTimerId);
    //         retStatus = timerQueueCancelTimer(pSampleConfiguration->timerQueueHandle, pSampleConfiguration->iceCandidatePairStatsTimerId,
    //                                           (UINT64) pSampleConfiguration);
    //         if (STATUS_FAILED(retStatus)) {
    //             DLOGE("Failed to cancel stats timer with: 0x%08x", retStatus);
    //         }
    //         pSampleConfiguration->iceCandidatePairStatsTimerId = MAX_UINT32;
    //     }
    //     printf("free 20");
    //     if (pSampleConfiguration->pregenerateCertTimerId != MAX_UINT32) {
    //         printf("free 21");
    //         retStatus = timerQueueCancelTimer(pSampleConfiguration->timerQueueHandle, pSampleConfiguration->pregenerateCertTimerId,
    //                                           (UINT64) pSampleConfiguration);
    //         if (STATUS_FAILED(retStatus)) {
    //             DLOGE("Failed to cancel certificate pre-generation timer with: 0x%08x", retStatus);
    //         }
    //         pSampleConfiguration->pregenerateCertTimerId = MAX_UINT32;
    //     }
    //     printf("free 22");
    //     timerQueueFree(&pSampleConfiguration->timerQueueHandle);
    // }
    printf("free 23");
    if (pSampleConfiguration->pregeneratedCertificates != NULL)
    {
        stackQueueGetIterator(pSampleConfiguration->pregeneratedCertificates, &iterator);
        while (IS_VALID_ITERATOR(iterator))
        {
            stackQueueIteratorGetItem(iterator, &data);
            stackQueueIteratorNext(&iterator);
            printf("free 24");
            freeRtcCertificate((PRtcCertificate)data);
        }
        printf("free 25");
        CHK_LOG_ERR(stackQueueClear(pSampleConfiguration->pregeneratedCertificates, FALSE));
        CHK_LOG_ERR(stackQueueFree(pSampleConfiguration->pregeneratedCertificates));
        pSampleConfiguration->pregeneratedCertificates = NULL;
    }
    printf("free 26");
    MEMFREE(*ppSampleConfiguration);
    *ppSampleConfiguration = NULL;

CleanUp:
    printf("free 27");
    LEAVES();
    return retStatus;
}

The main thing is to Cancel timers before anything.

August88618 · 2021-09-22T09:06:49Z

Let me confirm it，Is this problem not located at the root cause? Do all debugging prints need to be merged? And why did you block “deinitKvsWebRtc()”?

August88618 · 2021-09-24T05:50:46Z

The problem was not solved, and it reappeared after the changes were merged.Log is the same as above，only begin but not exit.

disa6302 · 2021-09-24T05:51:46Z

@August88618 ,

I misunderstood the issue to be linked
Reopened, so this issue is still being tracked

hassanctech · 2021-09-24T13:59:51Z

Sorry it appears there was some confusion, I'm linking PRs to the issue so when the correct one is merged I will take care of closing the issue.

@August88618 can you confirm if you were able to try the change from @ilyaikik and if it worked for you? I have a PR right now with those changes but I kept deinitKvsWebRtc(); as its needed when there's a data channel to clean up libsrtp resources.

August88618 · 2021-09-26T01:31:04Z

Do you mean merge all Fix bugs #1279 changes to our branches?

ilyaikik · 2021-09-26T20:00:27Z

Let me confirm it，Is this problem not located at the root cause? Do all debugging prints need to be merged? And why did you block “deinitKvsWebRtc()”?

Didn't understand your first question, sorry.
No, no debug messages needs to be merged (sorry for that).
deinitKvsWebRtc() is blocked because I modified the code a little bit and call this function in other place. So it do not need to be blocked here.

Actually I did not expect that this code will be PRed as it is. It's better to check funtionality)
But in my case this changes except extra debug messages and blocked deinitKvsWebRtc() solve the problem of stuck in timerQueueCancelTimer.

I could clear the code, check it and prepare it for PR if needed.

hassanctech · 2021-09-27T15:16:57Z

@August88618 If you can pull the latest from the develop branch and test it should be fixe there. @ilyaikik feel free to try it as well this should be fixed there as well.

hassanctech · 2021-09-27T16:12:21Z

Closing because this should be resolved on the latest develop branch.

August88618 · 2021-10-20T11:20:50Z

The problem was not solved, and it reappeared after the changes were merged.Log is the same as above，only begin but not exit.

August88618 added the bug Something isn't working label Sep 17, 2021

hassanctech linked a pull request Sep 23, 2021 that will close this issue

fix some bugs #1277

Merged

hassanctech removed a link to a pull request Sep 23, 2021

fix some bugs #1277

Merged

disa6302 closed this as completed Sep 23, 2021

disa6302 reopened this Sep 23, 2021

hassanctech mentioned this issue Sep 24, 2021

Fix bugs #1279

Merged

hassanctech self-assigned this Sep 24, 2021

hassanctech closed this as completed Sep 27, 2021

August88618 mentioned this issue Oct 21, 2021

[BUG]Function named "freeSampleStreamingSession" called "timerQueueCancelTimer", only enter "timerQueueCancelTimer" but not exited, please confirm！ #1306

Closed

codingspirit mentioned this issue Apr 12, 2022

Fix possible dead lock when freeSampleStreamingSession #1448

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[BUG]Function named "freeSampleStreamingSession" called "timerQueueCancelTimer", only enter "timerQueueCancelTimer" but not exited, please confirm！ #1273

[BUG]Function named "freeSampleStreamingSession" called "timerQueueCancelTimer", only enter "timerQueueCancelTimer" but not exited, please confirm！ #1273

August88618 commented Sep 17, 2021

hassanctech commented Sep 17, 2021

hassanctech commented Sep 17, 2021

August88618 commented Sep 18, 2021

ilyaikik commented Sep 18, 2021

August88618 commented Sep 22, 2021

August88618 commented Sep 24, 2021

disa6302 commented Sep 24, 2021

hassanctech commented Sep 24, 2021

August88618 commented Sep 26, 2021

ilyaikik commented Sep 26, 2021

hassanctech commented Sep 27, 2021

hassanctech commented Sep 27, 2021

August88618 commented Oct 20, 2021

[BUG]Function named "freeSampleStreamingSession" called "timerQueueCancelTimer", only enter "timerQueueCancelTimer" but not exited, please confirm！ #1273

[BUG]Function named "freeSampleStreamingSession" called "timerQueueCancelTimer", only enter "timerQueueCancelTimer" but not exited, please confirm！ #1273

Comments

August88618 commented Sep 17, 2021

hassanctech commented Sep 17, 2021

hassanctech commented Sep 17, 2021

August88618 commented Sep 18, 2021

ilyaikik commented Sep 18, 2021

August88618 commented Sep 22, 2021

August88618 commented Sep 24, 2021

disa6302 commented Sep 24, 2021

hassanctech commented Sep 24, 2021

August88618 commented Sep 26, 2021

ilyaikik commented Sep 26, 2021

hassanctech commented Sep 27, 2021

hassanctech commented Sep 27, 2021

August88618 commented Oct 20, 2021