search

espressif / esp-adf

Espressif Audio Development Framework
Other
1.52k stars 669 forks source link

voip app has no voice (AUD-4746) #1037

Open Bruce213 opened 1 year ago

Bruce213 commented 1 year ago

idf version:4.4.5 adf version:master board: esp32-lyrt

l can call esp32 from phone, but when i call esp_rtc_answer(esp_sip)，_audio_dec() task will crash because no data recv from rtp. below is releated log : thanks in advance！

I (3752) ESP_RTC_CORE: esp_rtc ver: 1.1.0 compile date: Jun 8 2023-12:29:28 I (3752) SIP: Conecting... I (3762) ESP_RTC_CORE: esp_rtc_init done W (3762) SIP: CHANGE STATE FROM 0, TO 1, :func: sip_connect:1834 I (3772) SIP: [1970-01-01/00:00:01]=======WRITE 0592 bytes>> I (3772) SIP:

REGISTER sip:192.168.2.218:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.2.16:17730;branch=z9hG4bK-2001598745;rport From: sip:107@192.168.2.218:5060;tag=-2008977675 To: sip:107@192.168.2.218:5060 Contact: sip:107@192.168.2.16:17730;transport=UDP Max-Forwards: 70 Call-ID: 1C27471EC69B321EA4314587C03A2A3BC075920DECB2 CSeq: 1 REGISTER Expires: 3600 User-Agent: ESP32 SIP/2.0 Content-Length: 0 Allow: INVITE, ACK, CANCEL, BYE, UPDATE, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri Allow-Events: presence, kpml

I (3832) SIP: [1970-01-01/00:00:01]=======================>> I (3852) SIP: [1970-01-01/00:00:01]<<=====READ 0397 bytes== I (3852) SIP:

SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.2.16:17730;rport;branch=z9hG4bK-2001598745 To: sip:107@192.168.2.218:5060;tag=d7b81d5c From: sip:107@192.168.2.218:5060;tag=-2008977675 Call-ID: 1C27471EC69B321EA4314587C03A2A3BC075920DECB2 CSeq: 1 REGISTER WWW-Authenticate: Digest algorithm=MD5,nonce="2D51C62E38FAFA5F76995E2F104A62524E81B42E",realm="newrocktech" Content-Length: 0

I (3882) SIP: [1970-01-01/00:00:01]<<====================== I (3892) SIP: Required authentication I (3892) SIP: [1970-01-01/00:00:01]=======WRITE 0790 bytes>> I (3902) SIP:

REGISTER sip:192.168.2.218:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.2.16:17730;branch=z9hG4bK--1138121571;rport From: sip:107@192.168.2.218:5060;tag=115674838 To: sip:107@192.168.2.218:5060 Contact: sip:107@192.168.2.16:17730;transport=UDP Max-Forwards: 70 Call-ID: 1C27471EC69B321EA4314587C03A2A3BC075920DECB2 CSeq: 2 REGISTER Expires: 3600 User-Agent: ESP32 SIP/2.0 Content-Length: 0 Allow: INVITE, ACK, CANCEL, BYE, UPDATE, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri Allow-Events: presence, kpml Authorization: Digest username="107", realm="newrocktech", nonce="2D51C62E38FAFA5F76995E2F104A62524E81B42E", uri="sip:192.168.2.218:5060", response="1800ea413e06c5ae168cf4434562f4ed", algorithm=MD5

I (3972) SIP: [1970-01-01/00:00:01]=======================>> I (3992) SIP: [1970-01-01/00:00:01]<<=====READ 0411 bytes== I (3992) SIP:

SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.2.16:17730;rport;branch=z9hG4bK--1138121571 To: sip:107@192.168.2.218:5060;tag=a0b40d24 From: sip:107@192.168.2.218:5060;tag=115674838 Date: Wed, 19 Jul 2023 16:12:00 GMT Call-ID: 1C27471EC69B321EA4314587C03A2A3BC075920DECB2 CSeq: 2 REGISTER Server: OM20G(Rev 2.1.5.192) Contact: sip:107@192.168.2.16:17730;transport=UDP;expires=3600 Content-Length: 0

I (4032) SIP: [1970-01-01/00:00:01]<<====================== I (4042) SIP_SERVICE: ESP_RTC_EVENT_REGISTERED W (4042) SIP: CHANGE STATE FROM 1, TO 2, :func: sip_register:1862 I (28612) SIP: [1970-01-01/00:00:13]<<=====READ 0869 bytes== I (28612) SIP:

INVITE sip:107@localhost SIP/2.0 Via: SIP/2.0/UDP 192.168.2.218:5060;rport;branch=z9hG4bK-63735993616897831441689442077 To: sip:107@localhost From: sip:200@localhost:5060;tag=16897831441689442076-1 Call-ID: 1689783144503237589-0@192.168.2.218 CSeq: 101140 INVITE Max-Forwards: 70 Expires: 60000 Contact: sip:200@192.168.2.218:5060 Allow: INVITE,ACK,CANCEL,BYE,OPTIONS,INFO,REFER,PRACK,UPDATE User-Agent: NewRockTech OM20G-2S/2 VER.2.1.5.192/UA 2.0 Content-Type: application/sdp Content-Length: 350

v=0 o=- 1689783144 835535 IN IP4 192.168.2.218 s=- c=IN IP4 192.168.2.218 t=0 0 m=audio 10122 RTP/AVP 0 8 18 104 9 101 a=ptime:20 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:104 AMR/8000 a=fmtp:104 mode-change-capability=2;max-red=220 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15

I (28692) SIP: [1970-01-01/00:00:13]<<====================== I (28692) SIP: Expires = 60000 I (28702) SIP: Remote ARTP port=10122 I (28702) SIP: Remote RTP addr=192.168.2.218 I (28712) SIP: call from 200 I (28712) SIP: [1970-01-01/00:00:13]=======WRITE 0413 bytes>> I (28722) SIP:

SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.2.218:5060;rport;branch=z9hG4bK-63735993616897831441689442077 Contact: sip:107@192.168.2.16:17730 From: sip:200@localhost:5060;tag=16897831441689442076-1 To: sip:107@localhost;tag=-762387864 Call-ID: 1689783144503237589-0@192.168.2.218 CSeq: 101140 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (28762) SIP: [1970-01-01/00:00:13]=======================>> I (28762) SIP: [1970-01-01/00:00:13]=======WRITE 0414 bytes>> I (28772) SIP:

SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.2.218:5060;rport;branch=z9hG4bK-63735993616897831441689442077 Contact: sip:107@192.168.2.16:17730 From: sip:200@localhost:5060;tag=16897831441689442076-1 To: sip:107@localhost;tag=-984350894 Call-ID: 1689783144503237589-0@192.168.2.218 CSeq: 101140 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (28812) SIP: [1970-01-01/00:00:13]=======================>> W (28822) SIP: CHANGE STATE FROM 2, TO 16, :func: _sip_uas_process_req_invite:1002 I (29922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (30922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (31922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (32922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (33922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (34922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (35922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (36022) SIP: Sending keep-alive to server I (36922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (37922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (38922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (39922) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (40762) ESP_AUDIO_CTRL: Enter media_ctrl_stop procedure, src:0, type:0, st:UNKNOWN, phase:0 W (40762) ESP_AUDIO_CTRL: [media_ctrl_stop]-Already stopped, status is UNKNOWN, phase:0 I (40822) SIP: [1970-01-01/00:00:19]=======WRITE 0596 bytes>> I (40822) SIP:

SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.2.218:5060;rport;branch=z9hG4bK-63735993616897831441689442077 Contact: sip:107@192.168.2.16:17730 From: sip:200@localhost:5060;tag=16897831441689442076-1 To: sip:107@localhost;tag=819454335 Call-ID: 1689783144503237589-0@192.168.2.218 CSeq: 101140 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 155 Content-Type: application/sdp

v=0 o=Z 0 3 IN IP4 192.168.2.16 s=Z t=0 0 c=IN IP4 192.168.2.16 m=audio 33625 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000

I (40872) SIP: [1970-01-01/00:00:19]=======================>> I (40892) SIP: [1970-01-01/00:00:19]<<=====READ 0368 bytes== I (40892) SIP:

ACK sip:107@192.168.2.16:17730 SIP/2.0 Via: SIP/2.0/UDP 192.168.2.218:5060;rport;branch=z9hG4bK-63735993616897831571689442078 To: sip:107@localhost;tag=819454335 From: sip:200@localhost:5060;tag=16897831441689442076-1 Call-ID: 1689783144503237589-0@192.168.2.218 CSeq: 101140 ACK Max-Forwards: 70 Contact: sip:200@192.168.2.218:5060 Content-Length: 0

I (40922) SIP: [1970-01-01/00:00:19]<<====================== I (40932) SIP_SERVICE: ESP_RTC_EVENT_AUDIO_SESSION_BEGIN I (40942) AUDIO_PIPELINE: link el->rb, el:0x3f80c760, tag:algo, rb:0x3f80d0c0 I (40942) AUDIO_THREAD: The algo task allocate stack on external memory I (40952) AUDIO_ELEMENT: [algo-0x3f80c760] Element task created I (40962) AUDIO_ELEMENT: [raw-0x3f80c608] Element task created I (40962) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:4351151 Bytes, Inter:264691 Bytes, Dram:224091 Bytes

I (40982) AUDIO_ELEMENT: [algo] AEL_MSG_CMD_RESUME,state:1 I (40982) AFE_VC: afe interface for voice communication

I (40992) AFE_VC: AFE version: VC_V220727

I (40992) AFE_VC: Initial auido front-end, total channel: 2, mic num: 1, ref num: 1

I (41002) AFE_VC: aec_init: 1, se_init: 1, vad_init: 0

I (41012) AFE_VC: wakenet_init: 0, voice_communication_agc_init: 0

I (41042) AUDIO_PIPELINE: Pipeline started I (41042) AUDIO_THREAD: The _audio_enc task allocate stack on external memory I (41042) AV_STREAM: audio_enc started I (41052) AUDIO_THREAD: The _audio_dec task allocate stack on external memory I (41062) AV_STREAM: audio_dec started W (41062) SIP: CHANGE STATE FROM 16, TO 32, :func: sip_uas_process_req:1077 I (41142) AFE_VC: mode: 1, (Nov 1 2022 17:16:15)

I (41142) AUDIO_THREAD: The algo_fetch task allocate stack on external memory E (46072) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time: E (46072) task_wdt: - IDLE (CPU 1) E (46072) task_wdt: Tasks currently running: E (46072) task_wdt: CPU 0: IDLE E (46072) task_wdt: CPU 1: _audio_dec E (46072) task_wdt: Print CPU 0 (current core) backtrace

Backtrace: 0x40133392:0x3FFB0BF0 0x40084619:0x3FFB0C10 0x401BDFC3:0x3FFB7C90 0x400D3F15:0x3FFB7CB0 0x40090CBC:0x3FFB7CD0

E (46072) task_wdt: Print CPU 1 backtrace

Backtrace: 0x400878C5:0x3FFB11F0 0x40084619:0x3FFB1210 0x4000BFED:0x3F823660 0x40092CF1:0x3F823670 0x40087916:0x3F823690 0x4008793D:0x3F8236B0 0x40091E21:0x3F8236D0 0x400E16FA:0x3F8236F0

E (51072) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time: E (51072) task_wdt: - IDLE (CPU 1) E (51072) task_wdt: Tasks currently running: E (51072) task_wdt: CPU 0: _audio_enc E (51072) task_wdt: CPU 1: _audio_dec E (51072) task_wdt: Print CPU 0 (current core) backtrace

Backtrace: 0x40133392:0x3FFB0BF0 0x40084619:0x3FFB0C10 0x400DDE6E:0x3F820010 0x400DE0A1:0x3F820030 0x400DB8A7:0x3F820060 0x400DEE69:0x3F820090 0x400E146F:0x3F8200B0

E (51072) task_wdt: Print CPU 1 backtrace

Backtrace: 0x400878C5:0x3FFB11F0 0x40084619:0x3FFB1210 0x4008793D:0x3F8236B0 0x40091E21:0x3F8236D0 0x400E16FA:0x3F8236F0

E (56072) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time: E (56072) task_wdt: - IDLE (CPU 1) E (56072) task_wdt: Tasks currently running: E (56072) task_wdt: CPU 0: IDLE E (56072) task_wdt: CPU 1: _audio_dec E (56072) task_wdt: Print CPU 0 (current core) backtrace

Backtrace: 0x40133392:0x3FFB0BF0 0x40084619:0x3FFB0C10 0x401BDFC3:0x3FFB7C90 0x400D3F15:0x3FFB7CB0 0x40090CBC:0x3FFB7CD0

E (56072) task_wdt: Print CPU 1 backtrace

Backtrace: 0x400878C5:0x3FFB11F0 0x40084619:0x3FFB1210 0x4008793D:0x3F8236B0 0x40091E21:0x3F8236D0 0x400E16FA:0x3F8236F0

I (57852) SIP: [1970-01-01/00:00:28]<<=====READ 0368 bytes== I (57862) SIP:

BYE sip:107@192.168.2.16:17730 SIP/2.0 Via: SIP/2.0/UDP 192.168.2.218:5060;rport;branch=z9hG4bK-63735993616897831741689442079 To: sip:107@localhost;tag=819454335 From: sip:200@localhost:5060;tag=16897831441689442076-1 Call-ID: 1689783144503237589-0@192.168.2.218 CSeq: 101141 BYE Max-Forwards: 70 Contact: sip:200@192.168.2.218:5060 Content-Length: 0

I (57892) SIP: [1970-01-01/00:00:28]<<====================== I (57902) SIP_SERVICE: ESP_RTC_EVENT_AUDIO_SESSION_END I (57912) AV_STREAM: _audio_enc task stoped W (57922) AUDIO_ELEMENT: OUT-[algo] AEL_IO_ABORT I (57922) ALGORITHM_STREAM: _algo_fetch_task is stopped I (57932) AFE_VC: afe_se_task quit

I (57932) AFE_VC: afe task destroy finished

I (57942) AFE_VC: exit function: afe_destory

W (57942) AUDIO_PIPELINE: There are no listener registered I (57942) AUDIO_PIPELINE: audio_pipeline_unlinked W (57952) AUDIO_ELEMENT: [algo] Element has not create when AUDIO_ELEMENT_TERMINATE W (57962) AUDIO_ELEMENT: [raw] Element has not create when AUDIO_ELEMENT_TERMINATE I (57972) AV_STREAM: _audio_dec task stoped I (57972) SIP_SERVICE: ESP_RTC_EVENT_HANGUP W (57982) SIP: CHANGE STATE FROM 32, TO 2, :func: sip_uas_process_req:1041 I (57982) SIP: [1970-01-01/00:00:28]=======WRITE 0421 bytes>> I (57992) SIP:

SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.2.218:5060;rport;branch=z9hG4bK-63735993616897831741689442079 Contact: sip:107@192.168.2.16:17730 From: sip:200@localhost:5060;tag=16897831441689442076-1 To: sip:107@localhost;tag=819454335;tag=-1809214522 Call-ID: 1689783144503237589-0@192.168.2.218 CSeq: 101141 BYE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

Bruce213 commented 1 year ago

when esp32 device call esp_rtc_answer() , the peer telephone can not recv 200 ACK, so it still keeping calling state ,have anyone help to check the problem?thanks.

ahhfzhang commented 12 months ago
  1. From esp32 device side , it is completely normal, because we already sent 200 and server gave us an ACK
  2. Peer cannot reveive 200, you should check whether the server send this 200 to peer
  3. Maybe you can try the lastest master, we have fixed a transport mismatch with peer issue, hope it helps
  4. Have you try Freeswith & Linphone as a comparison test?