search

Azure-Samples / cognitive-services-speech-sdk

Sample code for the Microsoft Cognitive Services Speech SDK
MIT License
2.95k stars 1.86k forks source link

Crash sdk after cancel event fired #1434

Closed 7i77an closed 2 years ago

7i77an commented 2 years ago

Describe the bug

I have a windows service which uses StartContinuousRecognitionAsync.

The service processes N concurrent interactions.

At some point, the sdk generates a cancellation event on which when the reason for the cancellation is going to be logged, a crash is generated.

There are other times where the sdk generates that cancel event and it works fine.

After sdk fired canceled event, crash logging reason for cancellation (line 490):

recognizer->Canceled.Connect([&ssresponse, &totalRecognizedTimes, &recognitionEnd, this](const IntentRecognitionCanceledEventArgs& e)

    {
        ssresponse.str("");
        switch (e.Reason)
        {
        case CancellationReason::EndOfStream:
            ssresponse << "{ \"status\": \"CANCELED\", \"data\": { \"reason\" : \"Reach the end of the file\", \"errCode\": 0}, \"totalRecognizedIntents\" : 0 , \"intents\": []}";
            break;

        case CancellationReason::Error:
==> LINE 490            ssresponse << "{ \"status\": \"CANCELED\", \"data\": { \"reason\" :\"" << e.ErrorDetails << "\", \"errCode\": " << (int)e.ErrorCode << "}, \"totalRecognizedIntents\" : 0 , \"intents\": []}";
            break;

        default:
            ssresponse << "{ \"status\": \"CANCELED\", \"data\": { \"reason\" : \"Unknown\", \"errCode\": " << (int)e.ErrorCode << "}, \"totalRecognizedIntents\" : 0 , \"intents\": []}";
            break;
        }

        totalRecognizedTimes = 0;
        m_keepRunning.clear();

    });

Version of the Cognitive Services Speech SDK SDK version 1.20

Platform, Operating System, and Programming Language

Additional context

This is the stack of crash:

FAULTING_THREAD: 00002c4c

DEFAULT_BUCKET_ID: HEAP_CORRUPTION

PRIMARY_PROBLEM_CLASS: HEAP_CORRUPTION

BUGCHECK_STR: APPLICATION_FAULT_HEAP_CORRUPTION_INVALID_POINTER_READ_WRONG_SYMBOLS

LAST_CONTROL_TRANSFER: from 77c1c6c2 to 77c18f21

STACK_TEXT:
WARNING: Stack unwind information not available. Following frames may be wrong. 04f7f63c 77c1c6c2 00000001 00000002 77c1ae43 ntdll!RtlpNtSetValueKey+0x4e1 04f7f658 77bc279e 9683a0b3 0132d6e0 01310000 ntdll!RtlpNtSetValueKey+0x3c82 04f7f688 77b82fdc 0132d6e0 00000000 00000000 ntdll!wcstok_s+0x5c5e 04f7f6e4 740797c0 01310000 00000000 0132d6e8 ntdll!RtlFreeHeap+0xac 04f7f71c 7657261b 01310000 00000000 0132d6e8 AcLayers!GetHookAPIs+0x4500 04f7f730 765725e8 0132d6e8 00000000 04f7f74c ucrtbase!free_base+0x1b 04f7f740 00d28ceb 0132d6e8 04f7f75c 00d2051a ucrtbase!free+0x18 04f7f74c 00d2051a 0132d6e8 00000080 04f7f784 inConcertCognitiveServices!operator delete+0xb [d:\agent_work\3\s\src\vctools\crt\vcstartup\src\heap\delete_scalar_size.cpp @ 31] 04f7f75c 00d24cf5 0132d6e8 00000080 00000002 inConcertCognitiveServices!std::allocator::deallocate+0x2a [c:\program files (x86)\microsoft visual studio\2017\community\vc\tools\msvc\14.16.27023\include\xmemory0 @ 992] 04f7f784 730356d5 00000034 046be0fc 00d2a54a inConcertCognitiveServices!std::basic_stringbuf<char,std::char_traits,std::allocator >::overflow+0x125 [c:\program files (x86)\microsoft visual studio\2017\community\vc\tools\msvc\14.16.27023\include\sstream @ 185] 04f7f7b0 73054260 032d56c3 00000055 00000000 msvcp140!std::basic_streambuf<char,std::char_traits >::xsputn+0xb5 04f7f7cc 00cf1518 032d5670 00000055 00000000 msvcp140!std::basic_streambuf<char,std::char_traits >::sputn+0x20 04f7f814 00d035c3 046be0f4 032d5670 00000055 inConcertCognitiveServices!std::_Insert_string<char,std::char_traits,unsigned int>+0x138 [c:\program files (x86)\microsoft visual studio\2017\community\vc\tools\msvc\14.16.27023\include\xstring_insert.h @ 46] 04f7f860 00d1170a 013565f0 9d8e230a 013565f0 inConcertCognitiveServices!::operator()+0x113 [d:\software\scm\5.5\sources\5.5\server\inconcertcognitiveservices\inconcertcognitiveservices\speechservices.cpp @ 490] 04f7f918 00d0c471 013565f0 9d8e235e 04f7fa24 inConcertCognitiveServices!Microsoft::CognitiveServices::Speech::EventSignalBase<Microsoft::CognitiveServices::Speech::RecognitionEventArgs const &>::Signal+0x14a [d:\software\scm\5.5\packages\microsoft.cognitiveservices.speech.1.20.0\build\native\include\cxx_api\speechapi_cxx_eventsignalbase.h @ 139] 04f7f94c 72942315 01391028 0136cc90 02566590 inConcertCognitiveServices!Microsoft::CognitiveServices::Speech::AsyncRecognizer<Microsoft::CognitiveServices::Speech::Intent::IntentRecognitionResult,Microsoft::CognitiveServices::Speech::Intent::IntentRecognitionEventArgs,Microsoft::CognitiveServices::Speech::Intent::IntentRecognitionCanceledEventArgs>::FireEvent_Canceled+0x101 [d:\software\scm\5.5\packages\microsoft.cognitiveservices.speech.1.20.0\build\native\include\cxx_api\speechapi_cxx_recognition_async_recognizer.h @ 415] 04f7f980 729451c0 0136cc90 0135c910 729441c0 Microsoft_CognitiveServices_Speech_core!GetModuleObject+0xc75 04f7f998 729441d7 04f7f9c8 729a0f49 04f7f9d0 Microsoft_CognitiveServices_Speech_core!GetModuleObject+0x3b20 04f7f9a0 729a0f49 04f7f9d0 2fde4982 04f7fa04 Microsoft_CognitiveServices_Speech_core!GetModuleObject+0x2b37 04f7f9c8 729a0cda 00000000 00000000 2fde4a12 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0x21859 04f7fa58 729ece02 0136cc90 0135c910 2fde4ae2 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0x215ea 04f7faa8 729eccc0 01391278 013d34ec 00000000 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0x6d712 04f7faf8 729ce218 013d34ec 02573318 032c9570 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0x6d5d0 04f7fba4 729ce7d2 013d34e4 013d34ec 00000004 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0x4eb28 04f7fc20 7299491b 025749a8 729dc310 7299491b Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0x4f0e2 04f7fc6c 72a4f02a 01374e30 01374e30 04f7fcd0 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0x1522b 04f7fc7c 72a4e592 72a4e580 72a4f5c0 2fde4c9a Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0xcf93a 04f7fcd0 72a4ebfd 04f7fd30 0545d508 2fde4d16 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0xceea2 04f7fd5c 72a50a92 0545d49c 0545d490 03351fe8 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0xcf50d 04f7fd74 72a507ce 2fde4dde 72a50770 03351fe8 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0xd13a2 04f7fd94 765807af 03351fe8 1b3ab685 76580770 Microsoft_CognitiveServices_Speech_core!pal_string_to_wstring+0xd10de 04f7fdd0 77a462c4 03270560 77a462a0 89cd761f ucrtbase!o__CIpow+0x4f 04f7fde4 77ba0779 03270560 9683a817 00000000 kernel32!BaseThreadInitThunk+0x24 04f7fe2c 77ba0744 ffffffff 77bc361b 00000000 ntdll!RtlSubscribeWnfStateChangeNotification+0x439 04f7fe3c 00000000 76580770 03270560 00000000 ntdll!RtlSubscribeWnfStateChangeNotification+0x404

SYMBOL_NAME: heap_corruption!heap_corruption

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: heap_corruption

IMAGE_NAME: heap_corruption

STACK_COMMAND: ~18s; .ecxr ; kb

FAILURE_BUCKET_ID: HEAP_CORRUPTION_c0000374_heap_corruption!heap_corruption

BUCKET_ID: APPLICATION_FAULT_HEAP_CORRUPTION_INVALID_POINTER_READ_WRONG_SYMBOLS_heap_corruption!heap_corruption

WATSON_STAGEONE_URL: http://watson.microsoft.com/StageOne/inConcertCognitiveServices_exe/1_0_0_1/62278f3d/ntdll_dll/6_2_14393_3986/5f77edb8/c0000374/000d8f21.htm?Retriage=1

chschrae commented 2 years ago

Hi there,

Thanks for reaching our. Are you able to provide any more of the code? We haven't been able to reproduce this yet.

Also is there a way you could run it with a log file set and then upload the log?

chschrae commented 2 years ago

I've been doing some testing around this and I think the issue may be related to your use of sstream within a callback and not flushing it.

What is happening is that sometimes the callback thread is freeing its variables before the stream is flushed. Then when the stream is attempting to add the args members, it throws an exception.

Can you try adding a flush to ssresponse before exiting the callback function?

7i77an commented 2 years ago

If I clear the ssresponse variable before exiting I don't have the reason why it failed. It is the purpose of the variable.

I'm going to add log to the library to see if it gives us any other clues.

Something strange that is happening to me is that with sdk 1.12, it crashed often but it correctly detected the intention in the NLU model. I have continuous speech recognition associated with an NLU model to determine its intent.

When I changed the sdk for the latest version (1.20), it stopped crashing many times (it crashes once, the one I reported to you), but it does not recognize intentions with a high %.

Most of the time it ends up returning: '{ "status": "CANCELED", "data": { "reason" : "Reach the end of the file", "errCode": 0}, "totalRecognizedIntents" : 0 , "intents": []}'

The best scenario I found is to have sdk 1.12 with max 15 concurrent interactions. With this amount of interactions, sdk 1.20 returns Reach the end of the file many times.

chschrae commented 2 years ago

@7i77an I wasn't suggesting that you clear the ssresponse variable, just to call .flush() on it so that all of the characters are written to the stream at that point and not delayed.

Streams are not by default synchronized with their output sequence and so flush must be called when using variables that may no longer be available when the synchronization occurs. https://www.cplusplus.com/reference/ostream/ostream/flush/

recognizer->Canceled.Connect([&ssresponse, &totalRecognizedTimes, &recognitionEnd, this](const IntentRecognitionCanceledEventArgs& e)
    {
        ssresponse.str("");
        switch (e.Reason)
        {
        case CancellationReason::EndOfStream:
            ssresponse << "{ \"status\": \"CANCELED\", \"data\": { \"reason\" : \"Reach the end of the file\", \"errCode\": 0}, \"totalRecognizedIntents\" : 0 , \"intents\": []}";
            break;

        case CancellationReason::Error:
                ssresponse << "{ \"status\": \"CANCELED\", \"data\": { \"reason\" :\"" << e.ErrorDetails << "\", \"errCode\": " << (int)e.ErrorCode << "}, \"totalRecognizedIntents\" : 0 , \"intents\": []}";
            break;

        default:
            ssresponse << "{ \"status\": \"CANCELED\", \"data\": { \"reason\" : \"Unknown\", \"errCode\": " << (int)e.ErrorCode << "}, \"totalRecognizedIntents\" : 0 , \"intents\": []}";
            break;
        }

        totalRecognizedTimes = 0;
        m_keepRunning.clear();
>>> ADDED LINE 
                ssresponse.flush();
    });

As for the interactions being recognized correctly/incorrectly, there have been many changes to the SDK since 1.12 and we wouldn't expect to see a large difference there, but if you can get a log by setting the SDKLogFileName property and upload that, I could take a look and see if I see anything out of the ordinary. Or share more of your code and scenario so I could try to reproduce the issue.