espressif / esp-adf

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

ESP32 LyraT keeps ringing after hanging up SIP call (AUD-5459) #1212

Open carlosrodridel opened 3 weeks ago

carlosrodridel commented 3 weeks ago

Environment

INVITE sip:X@192.168.2.2:14077;transport=udp SIP/2.0 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: Content-Type: application/sdp CSeq: 1740970801 INVITE From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Max-Forwards: 29 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 To: sip:0184250727@10.7.1.68;user=phone Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-FRRA-c9bed035-2f5362dc Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK User-Agent: Cirpack/v4.76 (gw_sip) Content-Length: 323

v=0 o=anonymous 171802877280 171802877280 IN IP4 91.121.129.159 s=SIP Call c=IN IP4 91.121.129.146 t=0 0 m=audio 31586 RTP/AVP 8 0 18 101 b=AS:82 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=rtpmap:18 G729/8000/1 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv

I (12927) SIP: [1970-01-01/00:00:05]<<====================== I (12935) SIP: Remote ARTP port=31586 I (12938) SIP: Remote RTP addr=91.121.129.146 I (12943) SIP: call from 0XX I (12947) SIP: [1970-01-01/00:00:05]=======WRITE 0543 bytes>> I (12954) SIP:

SIP/2.0 100 Trying Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-FRRA-c9bed035-2f5362dc Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=1804088857 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970801 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (13005) SIP: [1970-01-01/00:00:05]=======================>> I (13014) SIP: [1970-01-01/00:00:05]=======WRITE 0543 bytes>> I (13017) SIP:

SIP/2.0 180 Ringing Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-FRRA-c9bed035-2f5362dc Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=829229828 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970801 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (13069) SIP: [1970-01-01/00:00:06]=======================>> W (13077) SIP: CHANGE STATE FROM 2, TO 16, :func: _sip_uas_process_req_invite:1003 I (14084) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (15084) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (15919) VoIP_EXAMPLE: [ * ] [Play] input key event I (15984) SIP: [1970-01-01/00:00:07]=======WRITE 0726 bytes>> I (15985) SIP:

SIP/2.0 200 OK Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-FRRA-c9bed035-2f5362dc Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970801 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 153 Content-Type: application/sdp

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

I (16048) SIP: [1970-01-01/00:00:07]=======================>> I (16084) SIP: [1970-01-01/00:00:07]<<=====READ 0475 bytes== I (16084) SIP:

ACK sip:X@192.168.2.2:14077;transport=udp SIP/2.0 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: CSeq: 1740970801 ACK From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Max-Forwards: 29 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-IBWY-c9bede9d-53532e4e User-Agent: Cirpack/v4.76 (gw_sip) Content-Length: 0

I (16124) SIP: [1970-01-01/00:00:07]<<====================== I (16132) SIP_SERVICE: ESP_RTC_EVENT_AUDIO_SESSION_BEGIN I (16138) AUDIO_PIPELINE: link el->rb, el:0x3f823a74, tag:algo, rb:0x3f8243d4 I (16145) AUDIO_THREAD: The algo task allocate stack on external memory I (16152) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:4230311 Bytes, Inter:247759 Bytes, Dram:209131 Bytes

I (16164) AFE_VC: afe interface for voice communication

I (16170) AFE_VC: AFE version: VC_V220727

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

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

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

I (16196) AFE_VC: ns_mode: 0

I (16231) AUDIO_PIPELINE: Pipeline started I (16231) AUDIO_THREAD: The _audio_enc task allocate stack on external memory I (16233) AV_STREAM: audio_enc started I (16238) AUDIO_THREAD: The _audio_dec task allocate stack on external memory I (16240) AFE_VC: mode: 1, (Nov 21 2023 19:15:51)

I (16250) AUDIO_THREAD: The algo_fetch task allocate stack on external memory I (16270) AV_STREAM: audio_dec started W (16271) SIP: CHANGE STATE FROM 16, TO 32, :func: sip_uas_process_req:1078 I (16300) SIP: [1970-01-01/00:00:07]<<=====READ 0910 bytes== I (16302) SIP:

INVITE sip:X@192.168.2.2:14077;transport=udp SIP/2.0 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: Content-Type: application/sdp CSeq: 1740970802 INVITE From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Max-Forwards: 29 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK User-Agent: Cirpack/v4.76 (gw_sip) Content-Length: 248

v=0 o=anonymous 171802877280 171802877281 IN IP4 91.121.129.159 s=SIP Call c=IN IP4 91.121.129.146 t=0 0 m=audio 31586 RTP/AVP 8 101 b=AS:82 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv

I (16381) SIP: [1970-01-01/00:00:07]<<====================== I (16398) SIP: [1970-01-01/00:00:07]=======WRITE 0555 bytes>> I (16399) SIP:

SIP/2.0 200 OK Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=-813523281 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (16448) SIP: [1970-01-01/00:00:07]=======================>> I (16734) SIP: [1970-01-01/00:00:07]<<=====READ 0910 bytes== I (16734) SIP:

INVITE sip:X@192.168.2.2:14077;transport=udp SIP/2.0 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: Content-Type: application/sdp CSeq: 1740970802 INVITE From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Max-Forwards: 29 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK User-Agent: Cirpack/v4.76 (gw_sip) Content-Length: 248

v=0 o=anonymous 171802877280 171802877281 IN IP4 91.121.129.159 s=SIP Call c=IN IP4 91.121.129.146 t=0 0 m=audio 31586 RTP/AVP 8 101 b=AS:82 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv

I (16814) SIP: [1970-01-01/00:00:07]<<====================== I (16822) SIP: [1970-01-01/00:00:07]=======WRITE 0556 bytes>> I (16826) SIP:

SIP/2.0 200 OK Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=-1491982113 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (16879) SIP: [1970-01-01/00:00:07]=======================>> I (17740) SIP: [1970-01-01/00:00:08]<<=====READ 0910 bytes== I (17741) SIP:

INVITE sip:X@192.168.2.2:14077;transport=udp SIP/2.0 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: Content-Type: application/sdp CSeq: 1740970802 INVITE From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Max-Forwards: 29 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK User-Agent: Cirpack/v4.76 (gw_sip) Content-Length: 248

v=0 o=anonymous 171802877280 171802877281 IN IP4 91.121.129.159 s=SIP Call c=IN IP4 91.121.129.146 t=0 0 m=audio 31586 RTP/AVP 8 101 b=AS:82 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv

I (17820) SIP: [1970-01-01/00:00:08]<<====================== I (17828) SIP: [1970-01-01/00:00:08]=======WRITE 0554 bytes>> I (17837) SIP:

SIP/2.0 200 OK Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=-31930431 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (17885) SIP: [1970-01-01/00:00:08]=======================>> I (19747) SIP: [1970-01-01/00:00:09]<<=====READ 0910 bytes== I (19748) SIP:

INVITE sip:X@192.168.2.2:14077;transport=udp SIP/2.0 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: Content-Type: application/sdp CSeq: 1740970802 INVITE From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Max-Forwards: 29 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK User-Agent: Cirpack/v4.76 (gw_sip) Content-Length: 248

v=0 o=anonymous 171802877280 171802877281 IN IP4 91.121.129.159 s=SIP Call c=IN IP4 91.121.129.146 t=0 0 m=audio 31586 RTP/AVP 8 101 b=AS:82 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv

I (19828) SIP: [1970-01-01/00:00:09]<<====================== I (19835) SIP: [1970-01-01/00:00:09]=======WRITE 0555 bytes>> I (19840) SIP:

SIP/2.0 200 OK Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=1210986832 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (19893) SIP: [1970-01-01/00:00:09]=======================>> E (22223) VoIP_EXAMPLE: [ * ] [Set/Mode] input key event I (22223) SIP: User call sip BYE I (22321) SIP: [1970-01-01/00:00:10]=======WRITE 0748 bytes>> I (22321) SIP:

BYE sip:91.121.129.159:5060 SIP/2.0 Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-FRRA-c9bed035-2f5362dc Route: <sip:91.121.129.159:5060;lr>;session=75155 From: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 To: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Contact: sip:X@192.168.2.2:14077;transport=UDP Max-Forwards: 70 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 3 BYE Expires: 3600 User-Agent: ESP32 SIP/2.0 Content-Length: 0 Authorization: Digest username="X", realm="sip3.ovh.fr", nonce="b00b9a91425887cb728086d7590d8a3e", uri="sip:sip3.ovh.fr:5060", response="70c29c5a52f9417d13d9e51c4a1a3176", algorithm=MD5, opaque="aff272ce7d430ac"

I (22386) SIP: [1970-01-01/00:00:10]=======================>> I (22419) SIP: [1970-01-01/00:00:10]<<=====READ 0503 bytes== I (22419) SIP:

SIP/2.0 200 OK Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: CSeq: 3 BYE From: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Record-Route: <sip:91.121.129.159:5060;transport=udp;lr>;session=75155 To: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Via: SIP/2.0/UDP 91.121.129.159:5060;received=80.15.57.179;rport=38506;branch=z9hG4bK-FRRA-c9bed035-2f5362dc Server: Cirpack/v4.76 (gw_sip) Content-Length: 0

I (22462) SIP: [1970-01-01/00:00:10]<<====================== W (22469) SIP: CHANGE STATE FROM 32, TO 2, :func: _sip_request_bye:1633 I (22480) SIP_SERVICE: ESP_RTC_EVENT_AUDIO_SESSION_END I (22497) AV_STREAM: _audio_enc task stoped I (22509) ALGORITHM_STREAM: _algo_fetch_task is stopped I (22511) AFE_VC: afe_se_task quit

I (22512) AFE_VC: afe task destroy finished

I (22515) AFE_VC: exit function: afe_destory

W (22519) AUDIO_PIPELINE: There are no listener registered I (22525) AUDIO_PIPELINE: audio_pipeline_unlinked I (22531) AV_STREAM: _audio_dec task stoped I (22536) SIP_SERVICE: ESP_RTC_EVENT_HANGUP I (23901) SIP: [1970-01-01/00:00:11]<<=====READ 0910 bytes== I (23902) SIP:

INVITE sip:X@192.168.2.2:14077;transport=udp SIP/2.0 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: Content-Type: application/sdp CSeq: 1740970802 INVITE From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Max-Forwards: 29 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK User-Agent: Cirpack/v4.76 (gw_sip) Content-Length: 248

v=0 o=anonymous 171802877280 171802877281 IN IP4 91.121.129.159 s=SIP Call c=IN IP4 91.121.129.146 t=0 0 m=audio 31586 RTP/AVP 8 101 b=AS:82 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv

I (23981) SIP: [1970-01-01/00:00:11]<<====================== I (23989) SIP: Remote ARTP port=31586 I (23992) SIP: Remote RTP addr=91.121.129.146 I (23997) SIP: call from 0XX I (24001) SIP: [1970-01-01/00:00:11]=======WRITE 0560 bytes>> I (24007) SIP:

SIP/2.0 100 Trying Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=-2108648640 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (24060) SIP: [1970-01-01/00:00:11]=======================>> I (24069) SIP: [1970-01-01/00:00:11]=======WRITE 0560 bytes>> I (24073) SIP:

SIP/2.0 180 Ringing Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=-158347233 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (24125) SIP: [1970-01-01/00:00:11]=======================>> W (24134) SIP: CHANGE STATE FROM 2, TO 16, :func: _sip_uas_process_req_invite:1003 I (25140) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (26140) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (27240) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... *E (27617) VoIP_EXAMPLE: [ ] [Set/Mode] input key event W (27640) SIP: Deny the call W (27640) SIP: CHANGE STATE FROM 16, TO 2, :func: _sip_uas_process_res_invite:1149 I (27641) SIP_SERVICE: ESP_RTC_EVENT_HANGUP** I (27646) SIP: [1970-01-01/00:00:13]=======WRITE 0562 bytes>> I (27652) SIP:

SIP/2.0 486 Busy Here Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=1645529787 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (27705) SIP: [1970-01-01/00:00:13]=======================>> I (31888) SIP: [1970-01-01/00:00:15]<<=====READ 0910 bytes== I (31889) SIP:

INVITE sip:X@192.168.2.2:14077;transport=udp SIP/2.0 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr Contact: Content-Type: application/sdp CSeq: 1740970802 INVITE From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 Max-Forwards: 29 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702 Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK User-Agent: Cirpack/v4.76 (gw_sip) Content-Length: 248

v=0 o=anonymous 171802877280 171802877281 IN IP4 91.121.129.159 s=SIP Call c=IN IP4 91.121.129.146 t=0 0 m=audio 31586 RTP/AVP 8 101 b=AS:82 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv

I (31968) SIP: [1970-01-01/00:00:15]<<====================== I (31976) SIP: Remote ARTP port=31586 I (31979) SIP: Remote RTP addr=91.121.129.146 I (31984) SIP: call from 0XX I (31988) SIP: [1970-01-01/00:00:15]=======WRITE 0560 bytes>> I (31994) SIP:

SIP/2.0 100 Trying Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=-1682432670 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (32047) SIP: [1970-01-01/00:00:15]=======================>> I (32056) SIP: [1970-01-01/00:00:15]=======WRITE 0560 bytes>> I (32060) SIP:

SIP/2.0 180 Ringing Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=1831558996 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (32113) SIP: [1970-01-01/00:00:15]=======================>> W (32120) SIP: CHANGE STATE FROM 2, TO 16, :func: _sip_uas_process_req_invite:1003 I (33127) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... I (34127) SIP_SERVICE: ESP_RTC_EVENT_INCOMING... E (35111) VoIP_EXAMPLE: [ * ] [Set/Mode] input key event W (35127) SIP: Deny the call W (35127) SIP: CHANGE STATE FROM 16, TO 2, :func: _sip_uas_process_res_invite:1149 I (35127) SIP_SERVICE: ESP_RTC_EVENT_HANGUP I (35133) SIP: [1970-01-01/00:00:17]=======WRITE 0561 bytes>> I (35139) SIP:

SIP/2.0 486 Busy Here Via: SIP/2.0/UDP 91.121.129.159:5060;branch=z9hG4bK-ZMRE-c9bedfb1-5ac6b6d5 Record-Route: <sip:91.121.129.159:5060;lr>;session=75155 Contact: sip:X@192.168.2.2:14077;transport=UDP From: "+33XX" sip:0XX@sip3.ovh.fr;user=phone;tag=19832-SL-db9531d2-2ee7c6865 To: sip:0184250727@10.7.1.68;user=phone;tag=-1065477702;tag=698078662 Call-ID: 19832-RQ-db9531d1-45ee3cf06@sip3.ovh.fr CSeq: 1740970802 INVITE Server: ESP32 SIP/2.0 Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO Content-Length: 0

I (35191) SIP: [1970-01-01/00:00:17]=======================>> I (40797) SIP: [1970-01-01/00:00:19]<<=====READ 0411 bytes== I (40797) SIP:


- Compiler version : xtensa-esp32-elf-gcc (crosstool-NG esp-2021r2-patch5) 8.4.0
- Operating system:     macOS
- Using an IDE?: Visual Studio Code

## Problem Description

I am using the ADF VOIP example to implement SIP functionality on my ESP32 LyraT board. The problem occurs when I make a call using the OVH SIP service. When I hang up the call from my ESP32 board, I still receive the "ESP_RTC_EVENT_INCOMING" event, which causes the board to start ringing as if it is receiving a new call.

### Expected Behavior

After hanging up the call from the ESP32 LyraT board, the board should not receive any further "ESP_RTC_EVENT_INCOMING" events unless a new call is made.

### Actual Behavior

After hanging up the call, the ESP32 LyraT board continues to receive "ESP_RTC_EVENT_INCOMING" events, causing it to ring as if it is receiving a new call.

### Steps to Reproduce

1. Set up the ESP32 LyraT with the ESP-ADF VOIP example.
2. Use the OVH SIP service to make a call to the ESP32 LyraT from any phone.
3. Hang up the call from the ESP32 LyraT board.
4. Observe that the board continues to ring due to receiving "ESP_RTC_EVENT_INCOMING".

### Additional Information:

- OVH SIP Service Behavior: It appears that OVH sends another INVITE SDP package that needs to be replied to with a 200 OK SDP. If not replied to, OVH keeps sending the same package even when the call has ended, which causes the board to ring, thinking it's a new call.

#### Wireshark traces when calling to the LyraT
![call tel-esp-ovh2](https://github.com/espressif/esp-adf/assets/73194683/33384f29-66e2-4182-9907-3474f7ef059a)

- When making the same call using the "Telephone" application on MAC, this problem does not occur. This suggests that the issue is specific to how the ESP-ADF handles the SIP communication with OVH.

#### Wireshark traces when calling to "Telephone" Mac application
![call tel-pc-ovh](https://github.com/espressif/esp-adf/assets/73194683/e657c3fb-6569-40c6-9703-ecf377ec5c02)
TempoTian commented 3 weeks ago

I have checked the log seems the issue is caused by second invite response not contain sdp body, I have build one version with response with sdp also when reply after connection build, you can have a try. I just upload the version for ESP32, you can replace it to folder https://github.com/espressif/esp-adf-libs/tree/master/esp_media_protocols/lib/esp32. libesp_media_protocols.zip

carlosrodridel commented 2 weeks ago

I have checked the log seems the issue is caused by second invite response not contain sdp body, I have build one version with response with sdp also when reply after connection build, you can have a try. I just upload the version for ESP32, you can replace it to folder https://github.com/espressif/esp-adf-libs/tree/master/esp_media_protocols/lib/esp32. libesp_media_protocols.zip

Hi,

Thank you for the quick response and for providing the updated version.

I have tested the solution and observed in Wireshark that the ESP32 is now responding to the INVITE SDP messages with the corresponding 200 OK SDP messages. However, I'm still receiving more INVITE messages from the server. This indicates that there might be something missing or incorrect in the response message from the ESP32.

Screenshot 2024-06-18 at 17 06 56

I will continue to perform tests to identify the exact issue and will post a new comment with my findings as soon as possible.

Thanks again for your assistance.

carlosrodridel commented 1 week ago

Hi @TempoTian ,

I have completed the necessary tests and have some findings to share.

Using a Python VoIP library, I reproduced the OK SDP replies that the ESP32 is sending to the server to debug the SIP packets. Here are my analysis and conclusions:

Analysis of Frames Replicating ESP32 Behavior:

image

INVITE SDP from Server:

INVITE sip:0033XXXXXXXX@192.168.2.101:5060;transport=udp SIP/2.0
Call-ID: 07739-VS-e9e0fd68-34308c521@sip3.ovh.fr
Contact: <sip:XX.XXX.XXX.XXX:5060>
Content-Type: application/sdp
CSeq: 1992890617 INVITE
From: "+33XXXXXXXXX" <sip:0XXXXXXXXX@sip3.ovh.fr;user=phone>;tag=07739-HP-e9e0fd69-5378e1814
Max-Forwards: 29
Record-Route: <sip:XX.XXX.XXX.XXX:5060;lr>;session=467403
To: <sip:0XXXXXXXX@10.7.1.68;user=phone>
Via: SIP/2.0/UDP XX.XXX.XXX.XXX:5060;branch=z9hG4bK-OHOR-13ec59b9-147ba413
Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK
User-Agent: Cirpack/v4.76 (gw_sip)
Content-Length: 323

v=0
o=anonymous 171932821733 171932821733 IN IP4 XX.XXX.XXX.XXX
s=SIP Call
c=IN IP4 91.121.129.155
t=0 0
m=audio 36700 RTP/AVP 8 0 18 101
b=AS:82
a=rtpmap:8 PCMA/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:18 G729/8000/1
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

First 200 OK SDP:

SIP/2.0 200 OK
Via: SIP/2.0/UDP XX.XXX.XXX.XXX:5060;branch=z9hG4bK-OHOR-13ec59b9-147ba413
Record-Route: <sip:XX.XXX.XXX.XXX:5060;lr>;session=467403
From: "+33XXXXXXXXX" <sip:0XXXXXXXXX@sip3.ovh.fr;user=phone>;tag=07739-HP-e9e0fd69-5378e1814
To: <sip:0XXXXXXXX@10.7.1.68;user=phone>;tag=-1239239399
Call-ID: 07739-VS-e9e0fd68-34308c521@sip3.ovh.fr
CSeq: 1992890617 INVITE
Server: ESP32 SIP/2.0
Contact: <sip:0033XXXXXXXX@192.168.2.101:5060;transport=UDP>
Allow: INVITE, ACK, BYE, CANCEL, UPDATE, OPTIONS, INFO
Content-Type: application/sdp
Content-Length: 153

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

Second INVITE SDP from Server:


INVITE sip:0033XXXXXXXX@192.168.2.101:5060;transport=udp SIP/2.0
Call-ID: 07739-VS-e9e0fd68-34308c521@sip3.ovh.fr
Contact: <sip:XX.XXX.XXX.XXX:5060>
Content-Type: application/sdp
CSeq: 1992890618 INVITE
From: "+33XXXXXXXXX" <sip:0XXXXXXXXX@sip3.ovh.fr;user=phone>;tag=07739-HP-e9e0fd69-5378e1814
Max-Forwards: 29
Record-Route: <sip:XX.XXX.XXX.XXX:5060;lr>;session=467403
To: <sip:0XXXXXXXX@10.7.1.68;user=phone>;tag=-1239239399
Via: SIP/2.0/UDP XX.XXX.XXX.XXX:5060;branch=z9hG4bK-JZSQ-13ec5dba-634a921c
Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK
User-Agent: Cirpack/v4.76 (gw_sip)
Content-Length: 248

v=0
o=anonymous 171932821733 171932821734 IN IP4 XX.XXX.XXX.XXX
s=SIP Call
c=IN IP4 91.121.129.155
t=0 0
m=audio 36700 RTP/AVP 8 101
b=AS:82
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

Second 200 OK SDP Reply:

SIP/2.0 200 OK
Via: SIP/2.0/UDP XX.XXX.XXX.XXX:5060;branch=z9hG4bK-JZSQ-13ec5dba-634a921c
Record-Route: <sip:XX.XXX.XXX.XXX:5060;lr>;session=467403
From: "+33XXXXXXXXX" <sip:0XXXXXXXXX@sip3.ovh.fr;user=phone>;tag=07739-HP-e9e0fd69-5378e1814
To: <sip:0XXXXXXXX@10.7.1.68;user=phone>;tag=-1239239399;tag=-2004755355
Call-ID: 07739-VS-e9e0fd68-34308c521@sip3.ovh.fr
CSeq: 1992890617 INVITE
Server: ESP32 SIP/2.0
Contact: <sip:0033XXXXXXXX@192.168.2.101:5060;transport=UDP>
Allow: INVITE, ACK, BYE, CANCEL, UPDATE, OPTIONS, INFO
Content-Type: application/sdp
Content-Length: 153

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

Issue Identified: The ESP32 is sending an extra tag in the "To" Header, which causes the packet to not be recognized and acknowledged by the server. When the second tag is removed from this header, the server responds with an ACK, and the INVITE SDP requests stop As we see next :

Frame Analysis with Corrected "To" Header:

image

INVITE SDP from Server:

INVITE sip:0033XXXXXXXX@192.168.2.101:5060;transport=udp SIP/2.0
Call-ID: 02587-AQ-ea6c106a-4c067c157@sip3.ovh.fr
Contact: <sip:XX.XXX.XXX.XXX:5060>
Content-Type: application/sdp
CSeq: 2003502912 INVITE
From: "+33XXXXXXXXX" <sip:0XXXXXXXXX@sip3.ovh.fr;user=phone>;tag=02587-OF-ea6c106b-3ddada606
Max-Forwards: 29
Record-Route: <sip:XX.XXX.XXX.XXX:5060;lr>;session=225575
To: <sip:0XXXXXXXX@10.7.1.68;user=phone>
Via: SIP/2.0/UDP XX.XXX.XXX.XXX:5060;branch=z9hG4bK-GNBF-175f9337-1fe841e0
Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK
User-Agent: Cirpack/v4.76 (gw_sip)
Content-Length: 323

v=0
o=anonymous 171938964817 171938964817 IN IP4 XX.XXX.XXX.XXX
s=SIP Call
c=IN IP4 91.121.129.146
t=0 0
m=audio 36926 RTP/AVP 8 0 18 101
b=AS:82
a=rtpmap:8 PCMA/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:18 G729/8000/1
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

First 200 OK SDP:

SIP/2.0 200 OK
Via: SIP/2.0/UDP XX.XXX.XXX.XXX:5060;branch=z9hG4bK-GNBF-175f9337-1fe841e0
Record-Route: <sip:XX.XXX.XXX.XXX:5060;lr>;session=225575
From: "+33XXXXXXXXX" <sip:0XXXXXXXXX@sip3.ovh.fr;user=phone>;tag=02587-OF-ea6c106b-3ddada606
To: <sip:0XXXXXXXX@10.7.1.68;user=phone>;tag=-1239239399
Call-ID: 02587-AQ-ea6c106a-4c067c157@sip3.ovh.fr
CSeq: 2003502912 INVITE
Server: ESP32 SIP/2.0
Contact: <sip:0033XXXXXXXX@192.168.2.101:5060;transport=UDP>
Allow: INVITE, ACK, BYE, CANCEL, UPDATE, OPTIONS, INFO
Content-Type: application/sdp
Content-Length: 153

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

Second INVITE SDP from Server:

INVITE sip:0033XXXXXXXX@192.168.2.101:5060;transport=udp SIP/2.0
Call-ID: 02587-AQ-ea6c106a-4c067c157@sip3.ovh.fr
Contact: <sip:XX.XXX.XXX.XXX:5060>
Content-Type: application/sdp
CSeq: 2003502913 INVITE
From: "+33XXXXXXXXX" <sip:0XXXXXXXXX@sip3.ovh.fr;user=phone>;tag=02587-OF-ea6c106b-3ddada606
Max-Forwards: 29
Record-Route: <sip:XX.XXX.XXX.XXX:5060;lr>;session=225575
To: <sip:0XXXXXXXX@10.7.1.68;user=phone>;tag=-1239239399
Via: SIP/2.0/UDP XX.XXX.XXX.XXX:5060;branch=z9hG4bK-RLJA-175f976a-4c0300ec
Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK
User-Agent: Cirpack/v4.76 (gw_sip)
Content-Length: 248

v=0
o=anonymous 171938964817 171938964818 IN IP4 XX.XXX.XXX.XXX
s=SIP Call
c=IN IP4 91.121.129.146
t=0 0
m=audio 36926 RTP/AVP 8 101
b=AS:82
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

Second 200 OK SDP Reply:

SIP/2.0 200 OK
Via: SIP/2.0/UDP XX.XXX.XXX.XXX:5060;branch=z9hG4bK-RLJA-175f976a-4c0300ec
Record-Route: <sip:XX.XXX.XXX.XXX:5060;lr>;session=225575
From: "+33XXXXXXXXX" <sip:0XXXXXXXXX@sip3.ovh.fr;user=phone>;tag=02587-OF-ea6c106b-3ddada606
To: <sip:0XXXXXXXX@10.7.1.68;user=phone>;tag=-1239239399
Call-ID: 02587-AQ-ea6c106a-4c067c157@sip3.ovh.fr
CSeq: 2003502912 INVITE
Server: ESP32 SIP/2.0
Contact: <sip:0033XXXXXXXX@192.168.2.101:5060;transport=UDP>
Allow: INVITE, ACK, BYE, CANCEL, UPDATE, OPTIONS, INFO
Content-Type: application/sdp
Content-Length: 153

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

After making the correction, the server properly acknowledges the OK replies with an ACK and stops the continuous INVITE SDP requests.

Note on CSeq Number: It was also observed that the ESP32 replies to the first INVITE SDP with the same CSeq number as the request, which is correct. However, for subsequent INVITE requests from the server, the CSeq increments while the ESP32 replies with the same CSeq as the first request. Currently, this is not causing any issues with the server's acceptance of the response, but it might be a potential issue with different servers in the future.

Finally, I would like to request this correction specifically for the ESP32-S3, as we are currently using a custom ESP32-S3 board to implement our solution. The Lyra Board was utilized solely for testing purposes.

Please let me know if there are any further steps or additional information required.

TempoTian commented 1 week ago

Thanks for you investigation. I have fixed the issue you mentioned, please help to try if OK we will merge it esp_media_protocol.zip

carlosrodridel commented 1 week ago

Thank you for the quick response and fix. I have tested the updated library on both the ESP32 and ESP32S3, and I can confirm that both are now working as expected. Thanks again for your help!