espressif / esp-adf

Espressif Audio Development Framework
Other
1.49k stars 667 forks source link

No DTMF tone is heard over VoIP (AUD-5210) #1154

Closed EdwardRyu closed 4 months ago

EdwardRyu commented 4 months ago

SW/HW versions Audio development kit: ESP32-LyraT Audio kit version : v4.3 Module or chip used: ESP32-WROVER-E IDF version: v4.4.4 ADF version: v2.5

Issue : DTMF tone is not heard when the peer presses digits on keypad during a call.

When the peer presses a key pad during the call, Espressif ESP32 cannot hear the DTMF tone from the peer.

ahhfzhang commented 4 months ago

Hi @EdwardRyu ,

Our VoIP app only supports out band DTMF methods (RFC2833), which will callback to user if we receive a DTMF event from the peer, then you can play a dtmf tone in the callback.

Thanks.

EdwardRyu commented 4 months ago

Hi Michael,

It is good to know that you are supporting at least inbound DTMF. I mean it is good to know that SIP/RTP call back can detect DTMF event. My version of media doesn't seem to support it. Since when do you started supporting it? Which version of media library do I have to take it? Could you provide it?

Thanks,

ahhfzhang commented 4 months ago

Hi Edward,

The latest library I gave you already supports DTMF type (Out of band RFC-2833), In addition, I saw that twilio also uses RFC-2833 when sending DTMF.

btw, Out of band SIP INFO is not currently supported. In-band DTMF tones within the [G.711 audio stream] are passed-through in our voip app.

Thanks.

EdwardRyu commented 4 months ago

Thanks Michael,

I tested new library for both DTMF & answering event. Answering event works fine as expected.

DTMF detection also works fine, but there is a problem with delivering the event to AP (application processor, MCU). We are using AT commands over UART for the communication between AP and ESP32. I have implemented codes sending URC commands to AP inside _receive_audio() callback as follows. However, this AT commands are not delivered immediately. I see a delay about 2 to 4 seconds.

It might be related to context switching or something.

But I wonder if you can add DMTF events and pass it to application through _esp_sip_event_handler() callback as like the other RTC events. Or if you have any better idea, then please let me know.

Thanks,

static int _receive_audio(unsigned char data, int len, void ctx) { uint8_t buffer[30] = {0};

if ((len == 6) && !strncasecmp((char *)data, "DTMF-", 5)) {
    ESP_LOGI(TAG,"Receive DTMF Event ID : %d",data[5]);
    sprintf((char *)buffer, "%s%d", "+VOIPCALL:DTMF-",data[5]);
    esp_at_port_write_data(buffer, strlen((char *)buffer));
    return 0;
} else {
    av_stream_handle_t av_stream = (av_stream_handle_t) ctx;
    av_stream_frame_t frame = {0};
    frame.data = data;
    frame.len = len;
    return av_audio_dec_write(&frame, av_stream);
}

}

ahhfzhang commented 4 months ago

Hi Edward,

In order to know where this delay occurs, I think there are several directions to investigate:

  1. Is this ESP_LOGI(TAG,"Receive DTMF Event ID : %d",data[5]) printing delay very large? Because the SIP protocol stack receives the DTMF RTP packet and sends the callback to the user without delay.

  2. Is there any delay in sending DTMF from the peer?

  3. Is there any delay in esp_at_port_write_data?

  4. Does the audio sound delayed?

Thanks.

EdwardRyu commented 4 months ago

Hi Michael,

I assume that delay is happening over the UART port for AT commands. There is no delay in logs messages between SIP service task and UART task. However, only these DTMF related URCs have a delay about 3 seconds. If you have a look at the logs from AP logs and ESP32 logs below, you could see about 3 seconds gaps all the time for this DTMF related URCs. Please note that the other URCs or AT commands have no delay.

A1. No. This ESP_LOGI has no delay at all. I could see that ESP_LOGI inside _receive_audio() was sent out immediately right after seeing

A2. No. There is no delay for DTMF being delivered from the peer.

A3. esp_at_port_write_data() is called by _receive_audio(), there is no delay for this. I have added ESP_LOGI inside at_port_write_data() of at_uart_task.c . I don't see any delay between below two logs. [2024-02-28 16:47:29.164] I (570164) SIP_SERVICE: Receive DTMF Event ID : 9 [2024-02-28 16:47:29.164] I (570164) UART_TASK: at_port_write_data - len 16, data - +VOIPCALL:DTMF-9

A4. I didn't add any DTMF tone generation, but only detected DTMF event and passed it to application processor through another UART port.


Logs from ESP32 modem...

[2024-02-28 16:42:03.484] I (244479) UART_TASK: at_port_write_data - len 33, data - +VOIPCALL:RTC_AUDIO_SESSION_END [2024-02-28 16:42:03.484] I (244480) UART_TASK: at_port_write_data - len 22, data - +VOIPCALL:RTC_HANGUP [2024-02-28 16:47:05.040] I (546011) UART_TASK: at_port_write_data - len 35, data - +VOIPCALL:RTC_AUDIO_SESSION_BEGIN [2024-02-28 16:47:10.075] I (551032) UART_TASK: at_port_write_data - len 29, data - +VOIPCALL:RTC_EVENT_ON_CALL [2024-02-28 16:47:20.473] I (561487) SIP_SERVICE: Receive DTMFnt ID Eve: 0 [2024-02-28 16:47:20.473] I (561488) UART_TASK: at_port_write_data - len 16, data - +VOIPCALL:DTMF-0 [2024-02-28 16:47:29.164] I (570164) SIP_SERVICE: Receive DTMF Event ID : 9 [2024-02-28 16:47:29.164] I (570164) UART_TASK: at_port_write_data - len 16, data - +VOIPCALL:DTMF-9 [2024-02-28 16:47:38.191] I (579203) SIP_SERVICE: Receive DTMF Event ID : 1 [2024-02-28 16:47:38.191] I (579203) UART_TASK: at_port_write_data - len 16, data - +VOIPCALL:DTMF-1 [2024-02-28 16:47:48.078] I (589083) SIP_SERVICE: Receive DTMF Event ID : 2 [2024-02-28 16:47:48.078] I (589083) UART_TASK: at_port_write_data - len 16, data - +VOIPCALL:DTMF-2 [2024-02-28 16:47:55.511] I (596525) SIP_SERVICE: Receive DTMF Event ID : 3 [2024-02-28 16:47:55.511] I (596526) UART_TASK: at_port_write_data - len 16, data - +VOIPCALL:DTMF-3


Logs from application processor.....

[2024-02-28 16:42:03.526] +VOIPCALL:RTC_AUDIO_SESSION_END [2024-02-28 16:42:03.526] +VOIPCALL:RTC_HANGUP [2024-02-28 16:47:05.040] +VOIPCALL:RTC_AUDIO_SESSION_BEGIN [2024-02-28 16:47:10.040] +VOIPCALL:RTC_EVENT_ON_CALL [2024-02-28 16:47:23.481] +VOIPCALL:DTMF-0 [2024-02-28 16:47:32.150] +VOIPCALL:DTMF-9 [2024-02-28 16:47:41.194] +VOIPCALL:DTMF-1 [2024-02-28 16:47:51.081] +VOIPCALL:DTMF-2 [2024-02-28 16:47:58.527] +VOIPCALL:DTMF-3

Thanks, Edward

EdwardRyu commented 4 months ago

Thank you Michael,

The delay turned out to be my mistake. Now detecting DTMF is all good.

Will close the ticket.