Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unable to use UGG OPUS stream in a continuous recognition using C# SDK #44027

Open
MikeAlhayek opened this issue May 14, 2024 · 5 comments
Open

Unable to use UGG OPUS stream in a continuous recognition using C# SDK #44027

MikeAlhayek opened this issue May 14, 2024 · 5 comments
Labels
Client This issue points to a problem in the data-plane of the library. Cognitive - Speech customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-team-attention Workflow: This issue needs attention from Azure service team or SDK team question The issue doesn't require a change to the product in order to be resolved. Most issues start as that Service Attention Workflow: This issue is responsible by Azure service team.

Comments

@MikeAlhayek
Copy link

MikeAlhayek commented May 14, 2024 •
edited
Loading

Type of issue

Code doesn't work

Description

I am trying to use a web-browser to record audio, transmit it using SignalR to the server, and use continuous speech recognition to transform the audio to text. However, I am running into errors while trying to use recognizer.

Here is my class that calls the recognizer

public class AzureAudioInterpreter : IDisposable
{
    private readonly AzureCognitiveSpeechOptions _options;
    private readonly ILogger _logger;

    private PushAudioInputStream _audioInputStream;
    private AudioConfig _audioConfig;
    private SpeechRecognizer _recognizer;
    private string _spokenText = string.Empty;
    private bool _initialized = false;
    private int _chucksCounter = 0;

    public AzureAudioInterpreter(
        IOptions<AzureCognitiveSpeechOptions> options,
        ILogger<AzureAudioInterpreter> logger)
    {
        _options = options.Value;
        _logger = logger;
    }

    public async Task StartContinuousRecognitionAsync(AudioInterpreterTextContext context = null)
    {
        _logger.LogDebug("Starting Continuous Recognition");

        var speechConfig = SpeechConfig.FromSubscription(_options.Key, _options.Region);

        if (context != null && context.Data.TryGetValue("Language", out var lang))
        {
            speechConfig.SpeechRecognitionLanguage = lang?.ToString();
        }
        else
        {
            speechConfig.SpeechRecognitionLanguage = "en-US";
        }

        var format = AudioStreamFormat.GetCompressedFormat(AudioStreamContainerFormat.OGG_OPUS);

        _audioInputStream = AudioInputStream.CreatePushStream(format);
        _audioConfig = AudioConfig.FromStreamInput(_audioInputStream);

        _recognizer = new SpeechRecognizer(speechConfig, _audioConfig);
        _recognizer.Recognizing += RecognizerRecognizing;
        _recognizer.Recognized += RecognizerRecognized;
        _recognizer.Canceled += RecognizerCanceled;
        _recognizer.SessionStarted += RecognizerSessionStarted;
        _recognizer.SessionStopped += RecognizerSessionStopped;

        _initialized = true;
        _chucksCounter = 0;
        await _recognizer.StartContinuousRecognitionAsync();

        _logger.LogDebug("Started Continuous Recognition");
    }

    public Task PushAudioAsync(byte[] audioChunk)
    {
        if (_audioInputStream is null)
        {
            throw new InvalidOperationException($"The method '{nameof(PushAudioAsync)}' was called before {nameof(StartContinuousRecognitionAsync)} was called. Ensure to first call the {nameof(StartContinuousRecognitionAsync)} method.");
        }

        _logger.LogDebug("Pushing audio with the length of {length} for continuous recognition.", audioChunk.Length);

        if (_chucksCounter++ == 0)
        {
           // Attempt to strip the first chunk from the headers. 47 bytes.
            var index = FindHeaderEndIndex(audioChunk);

            if (index > -1)
            {
                // At this point we know that the given chunk contain headers, remove them.
                var temp = audioChunk.AsSpan().Slice(index).ToArray();

                _audioInputStream.Write(temp);

                return Task.CompletedTask;
            }
        }

        _audioInputStream.Write(audioChunk);

        return Task.CompletedTask;
    }

    public async Task<string> StopContinuousRecognitionAsync()
    {
        if (_audioInputStream is null)
        {
            throw new InvalidOperationException($"The method '{nameof(GetTextAsync)}' was called before {nameof(StartContinuousRecognitionAsync)} was called. Ensure to first call the {nameof(StartContinuousRecognitionAsync)} method.");
        }

        _logger.LogDebug("Stopping Continuous Recognition");

        _initialized = false;

        await _recognizer.StopContinuousRecognitionAsync();

        _logger.LogDebug("Stopped Continuous Recognition");

        DisposeServices();

        return _spokenText;
    }

    private void RecognizerRecognizing(object sender, SpeechRecognitionEventArgs e)
    {
        _logger.LogDebug("RecognizerRecognizing. Result: {Result}. Reason {Reason}", e.Result?.Text, e.Result?.Reason);

        if (e.Result.Reason == ResultReason.RecognizedSpeech)
        {
            _spokenText += e.Result.Text;
        }
        else if (e.Result.Reason == ResultReason.NoMatch)
        {
            Console.WriteLine($"NOMATCH: Speech could not be recognized.");
        }
    }

    private void RecognizerRecognized(object sender, SpeechRecognitionEventArgs e)
    {
        _logger.LogDebug("RecognizerRecognized. Result: {Result}. Reason {Reason}", e.Result?.Text, e.Result?.Reason);

        if (e.Result.Reason == ResultReason.RecognizedSpeech)
        {
            _spokenText = e.Result.Text;
        }
        else if (e.Result.Reason == ResultReason.NoMatch)
        {
            Console.WriteLine($"NOMATCH: Speech could not be recognized.");
        }
    }

    private void RecognizerCanceled(object sender, SpeechRecognitionCanceledEventArgs e)
    {
        _logger.LogDebug("RecognizerCanceled. Result: {Result}. Reason {Reason}", e.Result?.Text, e.Result?.Reason);

        if (e.Reason == CancellationReason.Error)
        {
            Console.WriteLine($"CANCELED: ErrorCode={e.ErrorCode}");
            Console.WriteLine($"CANCELED: ErrorDetails={e.ErrorDetails}");
            Console.WriteLine($"CANCELED: Did you update the subscription info?");
        }
    }

    private void RecognizerSessionStarted(object sender, SessionEventArgs e)
    {
        _logger.LogDebug("RecognizerSessionStarted. Result: {Result}.", e);
    }

    private void RecognizerSessionStopped(object sender, SessionEventArgs e)
    {
        _logger.LogDebug("RecognizerSessionStopped. Result: {Result}.", e);
    }

    private static int FindHeaderEndIndex(byte[] fileBytes)
    {
        // OGG page header is 27 bytes plus segment table
        var index = 0;

        while (index < fileBytes.Length)
        {
            if (fileBytes.Length - index < 27)
            {
                return -1; // Not enough bytes for a valid OGG page header
            }

            // Check the capture pattern "OggS" at the start of the page header
            if (fileBytes[index] == 'O' && fileBytes[index + 1] == 'g' && fileBytes[index + 2] == 'g' && fileBytes[index + 3] == 'S')
            {
                // Number of segments in the segment table
                var segmentCount = fileBytes[index + 26];

                // Total length of the segment table
                var segmentTableLength = segmentCount;

                if (fileBytes.Length - index < 27 + segmentTableLength)
                {
                    return -1; // Not enough bytes for the full segment table
                }

                // Calculate the length of the entire page
                var pageLength = 27 + segmentTableLength;
                for (var i = 0; i < segmentCount; i++)
                {
                    pageLength += fileBytes[index + 27 + i];
                }

                // Move the index to the end of this OGG page
                index += pageLength;

                // Check if this page is the Opus head or comment header
                if (fileBytes.Length - index >= 8)
                {
                    var pageType = Encoding.ASCII.GetString(fileBytes, index, 8);
                    if (pageType == "OpusHead" || pageType == "OpusTags")
                    {
                        // Continue to the next page
                        continue;
                    }

                    // Found the end of the header
                    return index;
                }
            }
            else
            {
                index++;
            }
        }

        return -1; // End of the header not found
    }

    private void DisposeServices()
    {
        _logger.LogDebug("Disposing Continuous Recognition Services.");

        if (_recognizer != null)
        {
            _recognizer.Recognizing -= RecognizerRecognizing;
            _recognizer.Recognized -= RecognizerRecognized;
            _recognizer.Canceled -= RecognizerCanceled;
            _recognizer.SessionStarted -= RecognizerSessionStarted;
            _recognizer.SessionStopped -= RecognizerSessionStopped;
            _recognizer.Dispose();
        }

        _audioConfig?.Dispose();
        _audioInputStream?.Dispose();
    }

    private bool _disposed = false;

    public void Dispose()
    {
        if (_disposed)
        {
            return;
        }

        _disposed = true;
        DisposeServices();
    }
}

The SignalR hub that is calling this class is as follow

public async Task UploadStream(IAsyncEnumerable<string> stream)
{
    await _audioInterpreter.StartContinuousRecognitionAsync();
    await foreach (var base64Str in stream)
    {
        // base64StringBuilder.Append(base64Str);
        var chunk = Convert.FromBase64String(base64Str);

        await _audioInterpreter.PushAudioAsync(chunk);
    }

    var utterance = await _audioInterpreter.StopContinuousRecognitionAsync();

    // ...
}

But I keep getting the following error

Error from GStreamer: Source: oggdemux Message: Could not demultiplex stream.

Here is a dump of the trace stack

2024-05-14 15:13:50.2029|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||CloudSolutions.Speech.AzureAudioInterpreter|DEBUG|Starting Continuous Recognition 
2024-05-14 15:13:50.2200|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[546650]: 46977ms SPX_DBG_TRACE_SCOPE_ENTER:  speechapi_c_factory.cpp:160 recognizer_create_speech_recognizer_from_config
 
2024-05-14 15:13:50.2200|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[546650]: 46977ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_session_shim.cpp:10 CSpxAudioSessionShim::Init
 
2024-05-14 15:13:50.2200|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[546650]: 46977ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_session_shim.cpp:10 CSpxAudioSessionShim::Init
 
2024-05-14 15:13:50.2200|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[546650]: 46977ms SPX_DBG_TRACE_SCOPE_ENTER:  codec_adapter.cpp:43 CSpxCodecAdapter::Open
 
2024-05-14 15:13:50.5216|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[546650]: 47278ms SPX_DBG_TRACE_SCOPE_EXIT:  codec_adapter.cpp:43 CSpxCodecAdapter::Open
 
2024-05-14 15:13:50.5216|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[546650]: 47279ms SPX_DBG_TRACE_SCOPE_ENTER:  recognizer.cpp:30 CSpxRecognizer::CSpxRecognizer
 
2024-05-14 15:13:50.5216|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[546650]: 47279ms SPX_DBG_TRACE_SCOPE_EXIT:  recognizer.cpp:30 CSpxRecognizer::CSpxRecognizer
 
2024-05-14 15:13:50.5216|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[546650]: 47279ms SPX_DBG_TRACE_SCOPE_EXIT:  speechapi_c_factory.cpp:160 recognizer_create_speech_recognizer_from_config
 
2024-05-14 15:13:50.5216||DEBUG|[167299]: 47283ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1119 *** CSpxAudioStreamSession::StartRecognitionAsync kicked-off THREAD started ***
 
2024-05-14 15:13:50.5216||DEBUG|[167299]: 47283ms SPX_TRACE_INFO:  thread_service.cpp:96 Started thread Background with ID [79573ll]
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47283ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1176 CSpxAudioStreamSession::StartRecognizing
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47288ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:3163 CSpxAudioStreamSession::StartAudioPump
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47288ms SPX_TRACE_INFO:  thread_service.cpp:96 Started thread User with ID [106138ll]
 
2024-05-14 15:13:50.5307||DEBUG|[106138]: 47288ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1724 DispatchEvent task started...
 
2024-05-14 15:13:50.5307||DEBUG|[603632]: 47289ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_pump.cpp:173 *** AudioPump THREAD started! ***
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47296ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:3163 CSpxAudioStreamSession::StartAudioPump
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47296ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1176 CSpxAudioStreamSession::StartRecognizing
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47296ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:3397 CSpxAudioStreamSession::InformAdapterSetFormatStarting
 
2024-05-14 15:13:50.5307||DEBUG|[167299]: 47296ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1119 *** CSpxAudioStreamSession::StartRecognitionAsync kicked-off THREAD stopped ***
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47296ms SPX_DBG_TRACE_SCOPE_ENTER:  usp_reco_engine_adapter_retry.cpp:19 CSpxUspRecoEngineAdapterRetry::InitDelegatePtr
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47297ms SPX_DBG_TRACE_SCOPE_ENTER:  usp_reco_engine_adapter.cpp:49 CSpxUspRecoEngineAdapter::CSpxUspRecoEngineAdapter
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47297ms SPX_DBG_TRACE_SCOPE_EXIT:  usp_reco_engine_adapter.cpp:49 CSpxUspRecoEngineAdapter::CSpxUspRecoEngineAdapter
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47297ms SPX_DBG_TRACE_SCOPE_ENTER:  usp_reco_engine_adapter.cpp:63 CSpxUspRecoEngineAdapter::Init
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47297ms SPX_DBG_TRACE_SCOPE_EXIT:  usp_reco_engine_adapter.cpp:63 CSpxUspRecoEngineAdapter::Init
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47297ms SPX_DBG_TRACE_SCOPE_EXIT:  usp_reco_engine_adapter_retry.cpp:19 CSpxUspRecoEngineAdapterRetry::InitDelegatePtr
 
2024-05-14 15:13:50.5307||||CloudSolutions.Speech.AzureAudioInterpreter|DEBUG|RecognizerSessionStarted. Result: SessionId: 9e88c00d204e44bd8872582c03c0fad8.. 
2024-05-14 15:13:50.5307|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||CloudSolutions.Speech.AzureAudioInterpreter|DEBUG|Started Continuous Recognition 
2024-05-14 15:13:50.5307||DEBUG|[106138]: 47297ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1724 DispatchEvent task complete!
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47297ms SPX_DBG_TRACE_SCOPE_ENTER:  usp_reco_engine_adapter.cpp:230 CSpxUspRecoEngineAdapter::SetFormat
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47297ms SPX_TRACE_INFO:  usp_reco_engine_adapter.cpp:1110 SpeechServiceConnection_LanguageIdMode not set or has invalid value .
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47297ms SPX_TRACE_INFO:  usp_connection.cpp:485 Microsoft::CognitiveServices::Speech::USP::CSpxUspConnection::Connect: entering...
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_INFO:  usp_connection.cpp:502 Adding subscription key headers
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_INFO:  usp_connection.cpp:537 Set a user defined HTTP header 'User-agent':'SpeechSDK-C#/1.37.0 Windows Client 10'
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_INFO:  usp_connection.cpp:552 connectionUrl=wss://eastus.stt.speech.microsoft.com/speech/universal/v2
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_DBG_TRACE_SCOPE_ENTER:  web_socket.cpp:216 CSpxWebSocket::CSpxWebSocket
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_DBG_TRACE_SCOPE_EXIT:  web_socket.cpp:216 CSpxWebSocket::CSpxWebSocket
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:31 WebSocketAdapter::UwsWebSocket::UwsWebSocket
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:31 WebSocketAdapter::UwsWebSocket::UwsWebSocket
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:43 WebSocketAdapter::UwsWebSocket::Initialize
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:43 WebSocketAdapter::UwsWebSocket::Initialize
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:221 WebSocketAdapter::UwsWebSocket::SetRequestHeader
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:221 WebSocketAdapter::UwsWebSocket::SetRequestHeader
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:221 WebSocketAdapter::UwsWebSocket::SetRequestHeader
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:221 WebSocketAdapter::UwsWebSocket::SetRequestHeader
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:221 WebSocketAdapter::UwsWebSocket::SetRequestHeader
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:221 WebSocketAdapter::UwsWebSocket::SetRequestHeader
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_INFO:  usp_connection.cpp:787 Create requestId  for messageType 0
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_DBG_TRACE_SCOPE_EXIT:  usp_reco_engine_adapter.cpp:230 CSpxUspRecoEngineAdapter::SetFormat
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:3397 CSpxAudioStreamSession::InformAdapterSetFormatStarting
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_INFO:  web_socket.cpp:800 CSpxWebSocket::DoWork: open transport.
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_INFO:  web_socket.cpp:479 Start to open websocket. WebSocket: 0x65dd23b0, wsio handle: 0x5c53f7b0
 
2024-05-14 15:13:50.5307||DEBUG|[79573]: 47298ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:149 WebSocketAdapter::UwsWebSocket::Open
 
2024-05-14 15:13:50.6982||DEBUG|[79573]: 47455ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:149 WebSocketAdapter::UwsWebSocket::Open
 
2024-05-14 15:13:50.7410||DEBUG|[603632]: 47498ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:50.9418||DEBUG|[603632]: 47698ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:51.0279||DEBUG|[79573]: 47785ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:247 WebSocketAdapter::UwsWebSocket::OnWebSocketOpened
 
2024-05-14 15:13:51.0279||DEBUG|[79573]: 47785ms SPX_TRACE_INFO:  web_socket.cpp:880 Opening websocket completed. TransportRequest: 0x65dd23b0, wsio handle: 0x5c53f7b0, time: 2024-05-14T22:13:51.0280226Z
 
2024-05-14 15:13:51.0279||DEBUG|[79573]: 47785ms SPX_TRACE_INFO:  usp_connection.cpp:902 TS:487, OnConnected: connection:0x5c9ac720
 
2024-05-14 15:13:51.0279||DEBUG|[79573]: 47785ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:247 WebSocketAdapter::UwsWebSocket::OnWebSocketOpened
 
2024-05-14 15:13:51.0279||DEBUG|[106138]: 47785ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1724 DispatchEvent task started...
 
2024-05-14 15:13:51.0279||DEBUG|[106138]: 47785ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1724 DispatchEvent task complete!
 
2024-05-14 15:13:51.1438||DEBUG|[603632]: 47900ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:51.1918|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||CloudSolutions.Speech.AzureAudioInterpreter|DEBUG|Pushing audio with the length of 12768 for continuous recognition. 
2024-05-14 15:13:51.3458||DEBUG|[603632]: 48102ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:51.5467||DEBUG|[603632]: 48303ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:51.7468||DEBUG|[603632]: 48503ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:51.9472||DEBUG|[603632]: 48704ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:52.0844|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||CloudSolutions.Speech.AzureAudioInterpreter|DEBUG|Stopping Continuous Recognition 
2024-05-14 15:13:52.1004||DEBUG|[79573]: 48857ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1155 *** CSpxAudioStreamSession::StopRecognitionAsync kicked-off THREAD started ***
 
2024-05-14 15:13:52.1004||DEBUG|[79573]: 48857ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1277 CSpxAudioStreamSession::StopRecognizing
 
2024-05-14 15:13:52.1004||DEBUG|[79573]: 48857ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_pump.cpp:132 CSpxAudioPump::StopPump() ...
 
2024-05-14 15:13:52.1004|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher|DEBUG|Stream '1' closed with error 'Failed to bind Stream message. KeyNotFoundException: No stream with id '1' could be found.'. 
2024-05-14 15:13:52.1492||DEBUG|[603632]: 48906ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:52.3012||DEBUG|[79573]: 49058ms SPX_TRACE_WARNING: audio_pump.cpp:534 [0000016C650032C0]CSpxAudioPump::WaitForPumpIdle(): Unexpected: state != State::Idle; state='Processing'
 
2024-05-14 15:13:52.3012||DEBUG|[79573]: 49058ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_pump.cpp:132 CSpxAudioPump::StopPump ... Done!
 
2024-05-14 15:13:52.3502||DEBUG|[603632]: 49107ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:52.5512||DEBUG|[603632]: 49308ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:52.7522||DEBUG|[603632]: 49509ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:52.8032||DEBUG|[79573]: 49560ms SPX_DBG_TRACE_SCOPE_ENTER:  codec_adapter.cpp:189 CSpxCodecAdapter::Close
 
2024-05-14 15:13:52.8032||DEBUG|[79573]: 49560ms SPX_DBG_TRACE_SCOPE_EXIT:  codec_adapter.cpp:189 CSpxCodecAdapter::Close
 
2024-05-14 15:13:52.8032||DEBUG|[79573]: 49560ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1277 CSpxAudioStreamSession::StopRecognizing
 
2024-05-14 15:13:52.8032||DEBUG|[79573]: 49560ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1155 *** CSpxAudioStreamSession::StopRecognitionAsync kicked-off THREAD stopped ***
 
2024-05-14 15:13:52.8032||DEBUG|[763123]: 49560ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:808 CSpxAudioStreamSession::WaitForIdle
 
2024-05-14 15:13:52.9532||DEBUG|[603632]: 49710ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:53.1542||DEBUG|[603632]: 49911ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:53.3547||DEBUG|[603632]: 50111ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:53.5552||DEBUG|[603632]: 50312ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:53.7555||DEBUG|[603632]: 50512ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:53.9560||DEBUG|[603632]: 50713ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:54.1565||DEBUG|[603632]: 50913ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:54.3568||DEBUG|[603632]: 51114ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:54.5578||DEBUG|[603632]: 51314ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:54.7587||DEBUG|[603632]: 51515ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:54.9608||DEBUG|[603632]: 51717ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:55.1618||DEBUG|[603632]: 51918ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:55.3622||DEBUG|[603632]: 52119ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:55.5627||DEBUG|[603632]: 52319ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:55.7628||DEBUG|[603632]: 52520ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:55.9632||DEBUG|[603632]: 52720ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:56.1637||DEBUG|[603632]: 52920ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:56.3646||DEBUG|[603632]: 53121ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:56.5651||DEBUG|[603632]: 53322ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:56.7656||DEBUG|[603632]: 53522ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:56.9666||DEBUG|[603632]: 53723ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:57.1686||DEBUG|[603632]: 53925ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:57.3699||DEBUG|[603632]: 54127ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:57.5709||DEBUG|[603632]: 54328ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:57.7717||DEBUG|[603632]: 54528ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:57.9722||DEBUG|[603632]: 54729ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:58.1753||DEBUG|[603632]: 54932ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:58.3767||DEBUG|[603632]: 55133ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:58.5777||DEBUG|[603632]: 55334ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:58.7788||DEBUG|[603632]: 55535ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:58.9798||DEBUG|[603632]: 55736ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:59.1807||DEBUG|[603632]: 55937ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:59.3809||DEBUG|[603632]: 56138ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:59.5818||DEBUG|[603632]: 56338ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:59.7830||DEBUG|[603632]: 56540ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:13:59.9840||DEBUG|[603632]: 56741ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:00.1850||DEBUG|[603632]: 56942ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:00.3860||DEBUG|[603632]: 57143ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:00.5865||DEBUG|[603632]: 57343ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:00.7875||DEBUG|[603632]: 57544ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:00.9885||DEBUG|[603632]: 57745ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:01.1891||DEBUG|[603632]: 57946ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:01.3900||DEBUG|[603632]: 58147ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:01.5906||DEBUG|[603632]: 58347ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:01.7911||DEBUG|[603632]: 58548ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:01.9917||DEBUG|[603632]: 58748ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:02.1928||DEBUG|[603632]: 58949ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:02.3930||DEBUG|[603632]: 59150ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:02.5939||DEBUG|[603632]: 59351ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:02.7944||DEBUG|[603632]: 59551ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59561ms SPX_TRACE_WARNING: audio_stream_session.cpp:827 [0000012BC4325400]CSpxAudioStreamSession::WaitForIdle: Timeout happened during waiting for Idle
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59561ms SPX_DBG_TRACE_SCOPE_ENTER:  usp_reco_engine_adapter.cpp:97 Terminating CSpxUspRecoEngineAdapter...
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59561ms SPX_DBG_TRACE_SCOPE_ENTER:  usp_connection.cpp:146 Microsoft::CognitiveServices::Speech::USP::CSpxUspConnection::~CSpxUspConnection
 
2024-05-14 15:14:02.7944||DEBUG|[106138]: 59561ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1724 DispatchEvent task started...
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59561ms SPX_DBG_TRACE_SCOPE_EXIT:  usp_connection.cpp:146 Microsoft::CognitiveServices::Speech::USP::CSpxUspConnection::~CSpxUspConnection
 
2024-05-14 15:14:02.7944||DEBUG|[106138]: 59562ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1724 DispatchEvent task complete!
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59562ms SPX_DBG_TRACE_SCOPE_EXIT:  usp_reco_engine_adapter.cpp:97 Terminating CSpxUspRecoEngineAdapter... Done!
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59562ms SPX_DBG_TRACE_SCOPE_ENTER:  usp_reco_engine_adapter.cpp:55 CSpxUspRecoEngineAdapter::~CSpxUspRecoEngineAdapter
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59562ms SPX_DBG_TRACE_SCOPE_EXIT:  usp_reco_engine_adapter.cpp:55 CSpxUspRecoEngineAdapter::~CSpxUspRecoEngineAdapter
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59562ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:3498 *** CSpxAudioStreamSession::AdapterCompletedSetFormatStop kicked-off THREAD started ***
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59562ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:3498 *** CSpxAudioStreamSession::AdapterCompletedSetFormatStop kicked-off THREAD stopped ***
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59562ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:808 CSpxAudioStreamSession::WaitForIdle
 
2024-05-14 15:14:02.7944|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||CloudSolutions.Speech.AzureAudioInterpreter|DEBUG|Stopped Continuous Recognition 
2024-05-14 15:14:02.7944|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||CloudSolutions.Speech.AzureAudioInterpreter|DEBUG|Disposing Continuous Recognition Services. 
2024-05-14 15:14:02.7944||DEBUG|[79573]: 59563ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1155 *** CSpxAudioStreamSession::StopRecognitionAsync kicked-off THREAD started ***
 
2024-05-14 15:14:02.7944||DEBUG|[79573]: 59563ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:1277 CSpxAudioStreamSession::StopRecognizing
 
2024-05-14 15:14:02.7944||DEBUG|[79573]: 59563ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1277 CSpxAudioStreamSession::StopRecognizing
 
2024-05-14 15:14:02.7944||DEBUG|[79573]: 59563ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:1155 *** CSpxAudioStreamSession::StopRecognitionAsync kicked-off THREAD stopped ***
 
2024-05-14 15:14:02.7944||DEBUG|[763123]: 59563ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:808 CSpxAudioStreamSession::WaitForIdle
 
2024-05-14 15:14:02.8125||DEBUG|[79573]: 59569ms SPX_DBG_TRACE_SCOPE_ENTER:  web_socket.cpp:221 CSpxWebSocket::~CSpxWebSocket
 
2024-05-14 15:14:02.8125||DEBUG|[79573]: 59569ms SPX_TRACE_INFO:  web_socket.cpp:425 CSpxWebSocket::Disconnect: start the close handshake.
 
2024-05-14 15:14:02.8125||DEBUG|[79573]: 59569ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:165 WebSocketAdapter::UwsWebSocket::Close
 
2024-05-14 15:14:02.9006||DEBUG|[854145]: 59657ms SPX_TRACE_INFO: AZ_LOG_INFO:  uws_client.c:1496 on_underlying_io_bytes_received: Close frame received
 
2024-05-14 15:14:02.9006||DEBUG|[854145]: 59657ms SPX_TRACE_INFO: AZ_LOG_INFO:  uws_client.c:1574 on_underlying_io_bytes_received: closing underlying io.
 
2024-05-14 15:14:02.9006||DEBUG|[854145]: 59657ms SPX_TRACE_INFO: AZ_LOG_INFO:  uws_client.c:939 on_underlying_io_close_complete: uws_state: 6.
 
2024-05-14 15:14:02.9006||DEBUG|[854145]: 59657ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:283 WebSocketAdapter::UwsWebSocket::OnWebSocketClosed
 
2024-05-14 15:14:02.9006||DEBUG|[854145]: 59657ms SPX_TRACE_INFO:  web_socket.cpp:1013 CSpxWebSocket::OnWebSocketClosed: context=0000016C65DD23B0
 
2024-05-14 15:14:02.9006||DEBUG|[854145]: 59657ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:283 WebSocketAdapter::UwsWebSocket::OnWebSocketClosed
 
2024-05-14 15:14:02.9115||DEBUG|[79573]: 59668ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:165 WebSocketAdapter::UwsWebSocket::Close
 
2024-05-14 15:14:02.9115||DEBUG|[79573]: 59668ms SPX_TRACE_INFO:  web_socket.cpp:427 CSpxWebSocket::Disconnect: isOpen: false
 
2024-05-14 15:14:02.9115||DEBUG|[79573]: 59668ms SPX_TRACE_INFO:  web_socket.cpp:430 CSpxWebSocket::Disconnect: destroying uwsclient.
 
2024-05-14 15:14:02.9115||DEBUG|[79573]: 59668ms SPX_TRACE_SCOPE_ENTER:  uws_web_socket.cpp:36 WebSocketAdapter::UwsWebSocket::~UwsWebSocket
 
2024-05-14 15:14:02.9115||DEBUG|[79573]: 59668ms SPX_TRACE_SCOPE_EXIT:  uws_web_socket.cpp:36 WebSocketAdapter::UwsWebSocket::~UwsWebSocket
 
2024-05-14 15:14:02.9115||DEBUG|[79573]: 59668ms SPX_DBG_TRACE_SCOPE_EXIT:  web_socket.cpp:221 CSpxWebSocket::~CSpxWebSocket
 
2024-05-14 15:14:02.9945||DEBUG|[603632]: 59751ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:03.1949||DEBUG|[603632]: 59952ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:03.3959||DEBUG|[603632]: 60153ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:03.5980||DEBUG|[603632]: 60355ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:03.7999||DEBUG|[603632]: 60557ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:04.0010||DEBUG|[603632]: 60758ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:04.2019||DEBUG|[603632]: 60959ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:04.4029||DEBUG|[603632]: 61160ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:04.6034||DEBUG|[603632]: 61360ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:04.8055||DEBUG|[603632]: 61562ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:05.0059||DEBUG|[603632]: 61763ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:05.2070||DEBUG|[603632]: 61964ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:05.4090||DEBUG|[603632]: 62166ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:05.6829||DEBUG|[603632]: 62440ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:05.8839||DEBUG|[603632]: 62641ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:06.0849||DEBUG|[603632]: 62842ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:06.2869||DEBUG|[603632]: 63044ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:06.4890||DEBUG|[603632]: 63246ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:06.6900||DEBUG|[603632]: 63447ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:06.8905||DEBUG|[603632]: 63647ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:07.0913||DEBUG|[603632]: 63848ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:07.2923||DEBUG|[603632]: 64049ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:07.4933||DEBUG|[603632]: 64250ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:07.6944||DEBUG|[603632]: 64451ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:07.8953||DEBUG|[603632]: 64652ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:08.0964||DEBUG|[603632]: 64853ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:08.2973||DEBUG|[603632]: 65054ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:08.4984||DEBUG|[603632]: 65255ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:08.6993||DEBUG|[603632]: 65456ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:08.9003||DEBUG|[603632]: 65657ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:09.1008||DEBUG|[603632]: 65858ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:09.3014||DEBUG|[603632]: 66058ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:09.5023||DEBUG|[603632]: 66259ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:09.7034||DEBUG|[603632]: 66460ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:09.9053||DEBUG|[603632]: 66662ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:10.1059||DEBUG|[603632]: 66863ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:10.3064||DEBUG|[603632]: 67063ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:10.5070||DEBUG|[603632]: 67264ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:10.7089||DEBUG|[603632]: 67466ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:10.9095||DEBUG|[603632]: 67666ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:11.1100||DEBUG|[603632]: 67867ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:11.3115||DEBUG|[603632]: 68068ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:11.5124||DEBUG|[603632]: 68269ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:11.7145||DEBUG|[603632]: 68471ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:11.9148||DEBUG|[603632]: 68671ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:12.1159||DEBUG|[603632]: 68873ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:12.3168||DEBUG|[603632]: 69073ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:12.5178||DEBUG|[603632]: 69274ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:12.7180||DEBUG|[603632]: 69475ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:12.8072||DEBUG|[763123]: 69564ms SPX_TRACE_WARNING: audio_stream_session.cpp:827 [0000012BC4325400]CSpxAudioStreamSession::WaitForIdle: Timeout happened during waiting for Idle
 
2024-05-14 15:14:12.8072||DEBUG|[763123]: 69564ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:3498 *** CSpxAudioStreamSession::AdapterCompletedSetFormatStop kicked-off THREAD started ***
 
2024-05-14 15:14:12.8072||DEBUG|[763123]: 69564ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:3498 *** CSpxAudioStreamSession::AdapterCompletedSetFormatStop kicked-off THREAD stopped ***
 
2024-05-14 15:14:12.8072||DEBUG|[763123]: 69564ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:808 CSpxAudioStreamSession::WaitForIdle
 
2024-05-14 15:14:12.8072|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69564ms SPX_DBG_TRACE_SCOPE_ENTER:  recognizer.cpp:35 CSpxRecognizer::~CSpxRecognizer
 
2024-05-14 15:14:12.8072|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69564ms SPX_DBG_TRACE_SCOPE_ENTER:  recognizer.cpp:394 CSpxRecognizer::TermDefaultSession
 
2024-05-14 15:14:12.8072|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69564ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_stream_session.cpp:196 CSpxAudioStreamSession::Term
 
2024-05-14 15:14:12.8072|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69564ms SPX_DBG_TRACE_SCOPE_ENTER:  thread_service.cpp:45 CSpxThreadService::Term
 
2024-05-14 15:14:12.8072|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69565ms SPX_DBG_TRACE_SCOPE_EXIT:  thread_service.cpp:45 CSpxThreadService::Term
 
2024-05-14 15:14:12.8108|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69566ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_session_shim.cpp:17 CSpxAudioSessionShim::Term
 
2024-05-14 15:14:12.8108|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69568ms SPX_DBG_TRACE_SCOPE_ENTER:  audio_pump.cpp:132 CSpxAudioPump::StopPump() ...
 
2024-05-14 15:14:12.9190||DEBUG|[603632]: 69676ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:13.0145|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69771ms SPX_TRACE_WARNING: audio_pump.cpp:534 [0000016C650032C0]CSpxAudioPump::WaitForPumpIdle(): Unexpected: state != State::Idle; state='Processing'
 
2024-05-14 15:14:13.0145|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 69771ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_pump.cpp:132 CSpxAudioPump::StopPump ... Done!
 
2024-05-14 15:14:13.1210||DEBUG|[603632]: 69878ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:13.3215||DEBUG|[603632]: 70078ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=false ...
 
2024-05-14 15:14:13.5150|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 70272ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_session_shim.cpp:17 CSpxAudioSessionShim::Term
 
2024-05-14 15:14:13.5150|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 70272ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_stream_session.cpp:196 CSpxAudioStreamSession::Term
 
2024-05-14 15:14:13.5150|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 70272ms SPX_DBG_TRACE_SCOPE_EXIT:  recognizer.cpp:394 CSpxRecognizer::TermDefaultSession
 
2024-05-14 15:14:13.5150|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 70272ms SPX_DBG_TRACE_SCOPE_EXIT:  recognizer.cpp:35 CSpxRecognizer::~CSpxRecognizer
 
2024-05-14 15:14:13.5150|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||CloudSolutions.Speech.AzureAudioInterpreter|DEBUG|Disposing Continuous Recognition Services. 
2024-05-14 15:14:13.5150|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 70277ms SPX_THROW_HR_IF:  handle_table.h:154 (0x005) = 0x5
 
2024-05-14 15:14:13.5150||DEBUG|[172322]: 70273ms SPX_TRACE_INFO:  base_gstreamer.cpp:288 END-OF-STREAM signaled
 
2024-05-14 15:14:13.5150||DEBUG|[172322]: 70277ms SPX_TRACE_SCOPE_ENTER:  base_gstreamer.cpp:186 BaseGstreamer::HandleGstMessageError
 
2024-05-14 15:14:13.5150||DEBUG|[172322]: 70277ms SPX_TRACE_ERROR:  base_gstreamer.cpp:211 Error from GStreamer: Source: oggdemux
Message: Could not demultiplex stream.
DebugInfo: ../ext/ogg/gstoggdemux.c(4776): gst_ogg_demux_send_event (): /GstPipeline:pipeline/GstOggDemux:oggdemux:
EOS before finding a chain

 
2024-05-14 15:14:13.5150||DEBUG|[603632]: 70277ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=true ...
 
2024-05-14 15:14:13.5150||DEBUG|[172322]: 70278ms SPX_TRACE_SCOPE_EXIT:  base_gstreamer.cpp:186 BaseGstreamer::HandleGstMessageError
 
2024-05-14 15:14:13.5150||DEBUG|[603632]: 70278ms SPX_TRACE_ERROR:  create_object_helpers.h:21 site does not support ISpxObjectFactory
 
2024-05-14 15:14:13.5150||DEBUG|[603632]: 70278ms SPX_THROW_HR:  create_object_helpers.h:22 hr = 0x14
 
2024-05-14 15:14:14.8785|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 71635ms SPX_TRACE_ERROR:  exception.cpp:123 About to throw Exception with an error code: 0x5 (SPXERR_INVALID_ARG) 
[CALL STACK BEGIN]

    > GetModuleObject
    - GetModuleObject
    - GetModuleObject
    - 00007FFD5F1ACF29 (SymFromAddr() error: The specified module could not be found.)

[CALL STACK END]


 
2024-05-14 15:14:14.8785|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 71636ms SPX_RETURN_ON_FAIL:  event_helpers.cpp:62 hr = 0x16c65daad20
 
2024-05-14 15:14:14.8785|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 71636ms SPX_THROW_HR_IF:  handle_table.h:154 (0x005) = 0x5
 
2024-05-14 15:14:16.4097||DEBUG|[603632]: 73166ms SPX_TRACE_ERROR:  exception.cpp:123 About to throw Exception with an error code: 0x14 (SPXERR_UNEXPECTED_CREATE_OBJECT_FAILURE) 
[CALL STACK BEGIN]

    > audio_config_get_audio_processing_options
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - configthreadlocale
    - BaseThreadInitThunk
    - RtlUserThreadStart

[CALL STACK END]


 
2024-05-14 15:14:16.4097||DEBUG|[603632]: 73167ms SPX_DBG_TRACE_SCOPE_ENTER:  thread_service.cpp:45 CSpxThreadService::Term
 
2024-05-14 15:14:16.4097||DEBUG|[603632]: 73167ms SPX_DBG_TRACE_SCOPE_EXIT:  thread_service.cpp:45 CSpxThreadService::Term
 
2024-05-14 15:14:16.4097||DEBUG|[603632]: 73167ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_pump.cpp:173 *** AudioPump THREAD stopped! ***
 
2024-05-14 15:14:16.4097||DEBUG|[603632]: 73167ms SPX_TRACE_ERROR:  audio_pump.cpp:472 [0000016C650032C0]CSpxAudioPump::PumpThread(): exception caught during pumping, Exception with an error code: 0x14 (SPXERR_UNEXPECTED_CREATE_OBJECT_FAILURE)
 
2024-05-14 15:14:16.4097||DEBUG|[603632]: 73167ms SPX_TRACE_ERROR:  create_object_helpers.h:21 site does not support ISpxObjectFactory
 
2024-05-14 15:14:16.4097||DEBUG|[603632]: 73168ms SPX_THROW_HR:  create_object_helpers.h:22 hr = 0x14
 
2024-05-14 15:14:17.8571|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 74614ms SPX_TRACE_ERROR:  exception.cpp:123 About to throw Exception with an error code: 0x5 (SPXERR_INVALID_ARG) 
[CALL STACK BEGIN]

    > GetModuleObject
    - GetModuleObject
    - GetModuleObject
    - 00007FFD5F1ACF29 (SymFromAddr() error: The specified module could not be found.)

[CALL STACK END]


 
2024-05-14 15:14:17.8571|coaching1|00-12e4b06f9dee8b9762cc022d6764c1b6-bb042b73133479f8-00||Microsoft.CognitiveServices.Speech|DEBUG|[520332]: 74614ms SPX_RETURN_ON_FAIL:  event_helpers.cpp:62 hr = 0x16c65da7ee0
 
2024-05-14 15:14:19.2997||DEBUG|[603632]: 76056ms SPX_TRACE_ERROR:  exception.cpp:123 About to throw Exception with an error code: 0x14 (SPXERR_UNEXPECTED_CREATE_OBJECT_FAILURE) 
[CALL STACK BEGIN]

    > audio_config_get_audio_processing_options
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - configthreadlocale

[CALL STACK END]


 
2024-05-14 15:14:19.2997||DEBUG|[603632]: 76057ms SPX_TRACE_ERROR:  audio_pump.cpp:499 [0000016C650032C0]CSpxAudioPump::PumpThread(): pISpxAudioProcessor->SetFormat(nullptr) thrown exception, Exception with an error code: 0x14 (SPXERR_UNEXPECTED_CREATE_OBJECT_FAILURE)

Page URL

https://learn.microsoft.com/en-us/dotnet/api/microsoft.cognitiveservices.speech?view=azure-dotnet

Content source URL

https://github.com/Azure/azure-docs-sdk-dotnet/blob/master/xml/ns-Microsoft.CognitiveServices.Speech.xml

Document Version Independent Id

87dd50dc-6504-1ab9-2e94-0d784fc4a563

Article author

@azure-sdk

Metadata

  • ID: d8cbf3cf-3443-ae5d-3819-beaa088ad999
  • Service: azure-ai-services
@github-actions github-actions bot added customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-triage Workflow: This is a new issue that needs to be triaged to the appropriate team. question The issue doesn't require a change to the product in order to be resolved. Most issues start as that labels May 14, 2024
@jsquire jsquire added Service Attention Workflow: This issue is responsible by Azure service team. Client This issue points to a problem in the data-plane of the library. needs-team-attention Workflow: This issue needs attention from Azure service team or SDK team Cognitive - Speech and removed needs-triage Workflow: This is a new issue that needs to be triaged to the appropriate team. labels May 15, 2024
@github-actions GitHub Actions
Copy link

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @robch.

@MikeAlhayek
Copy link
Author

MikeAlhayek commented May 15, 2024 •
edited
Loading

@robch here is how the recording is captured using JavaScript and send to the SignalR hub to call the service above

navigator.mediaDevices.getUserMedia({ audio: true })
    .then(stream => {
        const mediaRecorder = new MediaRecorder(stream, {
            mimeType: "audio/ogg; codecs=opus",
        });

        const subject = new signalR.Subject();

        mediaRecorder.addEventListener("dataavailable", async e => {
            // convert blob to base64 to send to the SignalR as string
            const uint8Array = new Uint8Array(await e.data.arrayBuffer());

            const binaryString = uint8Array.reduce((str, byte) => str + String.fromCharCode(byte), '');

            var base64 = btoa(binaryString);
            subject.next(base64);
        });

        // When the recording stops, complete the request for the SignalR hub so that the StopContinuousRecognitionAsync is called.
        mediaRecorder.addEventListener("stop", () => {
            subject.complete();
        });

        // when the recording starts, send the subject to the SignalR hub/server
        mediaRecorder.addEventListener("start", () => {
            connection.send('UploadStream', sessionId, currentRecordingId, subject);
        });

        // start recording when the record button is clicked
        recordButton.addEventListener("click", () => {
            if (mediaRecorder.state == "recording") {
                mediaRecorder.stop();
            } else {
                mediaRecorder.start(1000);
            }
        });

    }).catch(err => {
        // If the user denies permission to record audio, then display an error.
        console.log('Error: ' + err);
        alert('You must allow Microphone access to use this feature.');
    });

@MikeAlhayek
Copy link
Author

Alternatively, I tried to use RecognizeOnceAsync() instead of continuous recognizer as you can see in code below. The request times out every time.

public async Task<string> GetTextAsync(Stream stream, AudioInterpreterTextContext context = null)
{
    ArgumentNullException.ThrowIfNull(stream);

    stream.Position = 0;
    byte[] bytes = null;

    if (stream is not MemoryStream memoryStream)
    {
        memoryStream = new MemoryStream();
        await stream.CopyToAsync(memoryStream);
        bytes = memoryStream.ToArray();

        memoryStream.Dispose();
    }

    bytes ??= memoryStream.ToArray();

    var index = FindHeaderEndIndex(bytes);

    if (index > -1)
    {
        stream.Position = index + 1;
    }
    else
    {
        stream.Position = 0;
    }

    var format = AudioStreamFormat.GetCompressedFormat(AudioStreamContainerFormat.OGG_OPUS);

    using var audioStream = AudioInputStream.CreatePushStream(format);

    // Do we have to write the bytes in chunks here? Not sure why can't we do audioStream.Write(bytes) instead of the next 14 lines.
    using (var binaryReader = new BinaryReader(stream, Encoding.UTF8, leaveOpen: true))
    {
        byte[] readBytes;
        do
        {
            readBytes = binaryReader.ReadBytes(_bufferSize);

            if (readBytes.Length == 0)
            {
                break;
            }
            audioStream.Write(readBytes, readBytes.Length);
        } while (readBytes.Length > 0);
    }

    var speechConfig = SpeechConfig.FromSubscription(_options.Key, _options.Region);

    if (context != null && context.Data.TryGetValue("Language", out var lang))
    {
        speechConfig.SpeechRecognitionLanguage = lang?.ToString();
    }

    using var audioConfig = AudioConfig.FromStreamInput(audioStream);
    using var speechRecognizer = new SpeechRecognizer(speechConfig, audioConfig);

    var speechRecognitionResult = await speechRecognizer.RecognizeOnceAsync();

    if (speechRecognitionResult.Reason == ResultReason.RecognizedSpeech)
    {
        return speechRecognitionResult.Text;
    }

    LogErrors(speechRecognitionResult);

    return null;
}

Here is the debug trace for the above approach

024-05-15 08:14:35.1589||||Microsoft.CognitiveServices.Speech|DEBUG|[491387]: 211125ms SPX_TRACE_ERROR:  base_gstreamer.cpp:211 Error from GStreamer: Source: oggdemux
Message: Could not demultiplex stream.
DebugInfo: ../ext/ogg/gstoggdemux.c(4776): gst_ogg_demux_send_event (): /GstPipeline:pipeline/GstOggDemux:oggdemux:
EOS before finding a chain

 
2024-05-15 08:14:35.1589||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 211125ms SPX_TRACE_INFO:  blocking_read_write_buffer.h:127 WaitUntilBytesAvailable: available=0; required=3200 writeZero=true ...
 
2024-05-15 08:14:35.1589||||Microsoft.CognitiveServices.Speech|DEBUG|[491387]: 211125ms SPX_TRACE_SCOPE_EXIT:  base_gstreamer.cpp:186 BaseGstreamer::HandleGstMessageError
 
2024-05-15 08:14:35.1589||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 211125ms SPX_TRACE_ERROR:  create_object_helpers.h:21 site does not support ISpxObjectFactory
 
2024-05-15 08:14:35.1589||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 211125ms SPX_THROW_HR:  create_object_helpers.h:22 hr = 0x14
 
2024-05-15 08:14:36.5001||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 212461ms SPX_TRACE_ERROR:  exception.cpp:123 About to throw Exception with an error code: 0x14 (SPXERR_UNEXPECTED_CREATE_OBJECT_FAILURE) 
[CALL STACK BEGIN]

    > audio_config_get_audio_processing_options
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - pal_string_to_wstring
    - configthreadlocale
    - BaseThreadInitThunk
    - RtlUserThreadStart

[CALL STACK END]

2024-05-15 08:14:36.5001||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 212462ms SPX_DBG_TRACE_SCOPE_ENTER:  thread_service.cpp:45 CSpxThreadService::Term
 
2024-05-15 08:14:36.5001||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 212462ms SPX_DBG_TRACE_SCOPE_EXIT:  thread_service.cpp:45 CSpxThreadService::Term
 
2024-05-15 08:14:36.5001||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 212462ms SPX_DBG_TRACE_SCOPE_EXIT:  audio_pump.cpp:173 *** AudioPump THREAD stopped! ***
 
2024-05-15 08:14:36.5001||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 212462ms SPX_TRACE_ERROR:  audio_pump.cpp:472 [0000025BF2822E90]CSpxAudioPump::PumpThread(): exception caught during pumping, Exception with an error code: 0x14 (SPXERR_UNEXPECTED_CREATE_OBJECT_FAILURE)
 
2024-05-15 08:14:36.5001||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 212462ms SPX_TRACE_ERROR:  create_object_helpers.h:21 site does not support ISpxObjectFactory
 
2024-05-15 08:14:36.5001||||Microsoft.CognitiveServices.Speech|DEBUG|[187895]: 212462ms SPX_THROW_HR:  create_object_helpers.h:22 hr = 0x14

@MikeAlhayek
Copy link
Author

MikeAlhayek commented May 15, 2024 •
edited
Loading

I changed the recorder settings for testing purpuses by passing the following object to the navigator.mediaDevices.getUserMedia object.

{
  audio: {
    autoGainControl: false,
    channelCount: 1,
    echoCancellation: false,
    latency: 0,
    noiseSuppression: false,
    sampleSize: 16
}, video: false
}

I am able to write the bites to a local file and I am able to play the file with no problem. Here are the metadata info for the saved file

file_type: OPUS
file_type_extension: opus
mime_type: audio/ogg
opus_version: 1
audio_channels: 1
sample_rate: 16000
output_gain: 1 
codec_name: opus
codec_long_name: Opus (Opus Interactive Audio Codec) 
sample_rate: 48000 
channels: 1
channel_layout: mono 
duration: 4.76
size: 8648
bit_rate: 14534

Still with no success into converting the audio bytes to test using the SDK.

@MikeAlhayek MikeAlhayek mentioned this issue May 24, 2024
Open
@MikeAlhayek
Copy link
Author

I provided a repo for this issue Azure-Samples/cognitive-services-speech-sdk#2387 . Also, this repo can provide a good sample once I get it to work.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Client This issue points to a problem in the data-plane of the library. Cognitive - Speech customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-team-attention Workflow: This issue needs attention from Azure service team or SDK team question The issue doesn't require a change to the product in order to be resolved. Most issues start as that Service Attention Workflow: This issue is responsible by Azure service team.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@jsquire @MikeAlhayek