search

espressif / esp-adf

Espressif Audio Development Framework
Other
1.55k stars 685 forks source link

Cannot Hang up VoIP Call Correctly - using ADF2.5 (AUD-4551) #991

Closed charon22 closed 1 year ago

charon22 commented 1 year ago

Environment

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

Problem Description

It is currently being developed using ESP32-LyraT, and MicroSIP is installed on the development PC to test the call. PC (MicroSIP) <--> Twilio SIP server <--> ESP32-LyraT Problem :

The VoIP call session is not ended correctly when caller is not the ESP device.

That is, if I use MicroSIP to call the device, the device accept the call and then hangup, the session cannot be ended. o PC (MicroSIP) -----> Twilio SIP server --> ESP32-LyraT Call ------------------------------------------> _____Accept call <----------------------------------------------Hang up

Call status is maintained.

The situation is the same even if we change send_option.

ahhfzhang commented 1 year ago

Hi @charon22

Based on your description, we have made some modifications. Please help to test if the issue has been resolved.

esp_media_protocols.zip

Thank you.

EdwardRyu commented 1 year ago

Hi Michael,

I have tested it again with your new library. From the ESP32 perspective, your library is same as ADFv2.5 which is currently I'm using. esp_rtp.h and esp_rtsp.h have a slight changes, but they don't seem to have an effect.

Once again, the problem is that the format of BYE message from device has an unexpected URI format according to the analysis by MicroSIP as described in Issue932.

I also could see the error message like below in case of problematic case.

Here I again attached log snippet as follows. It would be appreciated if you take care of this long runner.

Thanks in advance. Edward

1. Problematic Case : Incoming call --> Answer --> Bye from the device BYE sip:101@epicsafetysiptest.sip.twilio.com:5060 SIP/2.0 Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK73e8.e1fafb3f2df5420dc53f8973c94e5987.0 Via: SIP/2.0/UDP 172.25.33.142:5060;rport=5060;received=3.87.37.222;branch=z9hG4bK34f09984-1915-41ba-97e7-b490dd459420_c3356d0b_514-1954785748264120886 From: sip:100@10.0.28.121:16785;tag=-1457145071 To: "101" sip:101@epicsafetysiptest.sip.twilio.com;tag=68277702_c3356d0b_34f09984-1915-41ba-97e7-b490dd459420 Contact: sip:100@10.0.28.121:16785;transport=UDP Max-Forwards: 70 Call-ID: 4a6f6394b0dedc8b0e4aac0654a942a9@0.0.0.0 CSeq: 8 BYE Expires: 3600 User-Agent: ESP32 SIP/2.0 Content-Length: 0 Authorization: Digest username="100", realm="sip.twilio.com", nonce="YQuvuMC8jlegdjCD_44GNXWScWVPXP-mh1cj_3qle4LMNjXC", uri="sip:epicsafetysiptest.sip.twilio.com:5060", response="604149c61f2f1716251e2ed116eb1041", algorithm=md5, nc=00000003, cnonce="ac15fdd565d0a4d8", qop=auth, opaque="682cf3e77e19d78ab48aa2cdf6a88977" I (1254999) SIP: [1970-01-01/00:22:01]=======================>> I (1255121) SIP: [1970-01-01/00:22:01]<<=====READ 0594 bytes== I (1255122) SIP: SIP/2.0 481 Call/Transaction Does Not Exist Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK73e8.e1fafb3f2df5420dc53f8973c94e5987.0;rport=16785;received=207.6.10.148 Via: SIP/2.0/UDP 172.25.33.142:5060;rport=5060;received=3.87.37.222;branch=z9hG4bK34f09984-1915-41ba-97e7-b490dd459420_c3356d0b_514-1954785748264120886 From: sip:100@10.0.28.121:16785;tag=-1457145071 To: "101" sip:101@epicsafetysiptest.sip.twilio.com;tag=68277702_c3356d0b_34f09984-1915-41ba-97e7-b490dd459420 Call-ID: 4a6f6394b0dedc8b0e4aac0654a942a9@0.0.0.0 CSeq: 8 BYE Server: Twilio Gateway Content-Length: 0

2. Normal Case : Outgoing call --> Accepted by peer --> Bye from the device BYE sip:172.25.55.230:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.28.121:16785;received=207.6.10.148;branch=z9hG4bK-813993005;rport=16785 Route: <sip:54.172.60.3;lr;twnat=sip:207.6.10.148:16785> From: sip:100@epicsafetysiptest.sip.twilio.com:5060;tag=588317154 To: sip:101@epicsafetysiptest.sip.twilio.com:5060;tag=67414753_c3356d0b_f79d4439-0ba8-45f3-8a9a-581dc92418c8 Contact: sip:100@10.0.28.121:16785;transport=UDP Max-Forwards: 70 Call-ID: 132624D12F44733DD2DA1B53EA828F325C975AF97786 CSeq: 7 BYE Expires: 3600 User-Agent: ESP32 SIP/2.0 Content-Length: 0 Authorization: Digest username="100", realm="sip.twilio.com", nonce="YQuvuMC8jlegdjCD_44GNXWScWVPXP-mh1cj_3qle4LMNjXC", uri="sip:epicsafetysiptest.sip.twilio.com:5060", response="23da2e98d65962a2b73a732a965398f1", algorithm=md5, nc=00000002, cnonce="8a5719b0f0850905", qop=auth, opaque="682cf3e77e19d78ab48aa2cdf6a88977"

I (1096896) SIP: [1970-01-01/00:19:12]=======================>> I (1096984) SIP: [1970-01-01/00:19:12]<<=====READ 0472 bytes== I (1096989) SIP:

SIP/2.0 200 OK CSeq: 7 BYE Call-ID: 132624D12F44733DD2DA1B53EA828F325C975AF97786 From: sip:100@epicsafetysiptest.sip.twilio.com:5060;tag=588317154 To: sip:101@epicsafetysiptest.sip.twilio.com:5060;tag=67414753_c3356d0b_f79d4439-0ba8-45f3-8a9a-581dc92418c8 Via: SIP/2.0/UDP 10.0.28.121:16785;received=207.6.10.148;branch=z9hG4bK-813993005;rport=16785 Server: Twilio Supported: replaces X-Twilio-CallSid: CAcdc54567fc2166e8e22e7bc1ee0ef432 Content-Length: 0

ahhfzhang commented 1 year ago

Hi Edward,

Forgot to update the ESP32 library, please help test again, thanks.

esp_media_protocols.zip

EdwardRyu commented 1 year ago

Thank you, Michael for the new library.

URI format @SIP BYE message which MicroSIP pointed out has now correct format, but it still fails. But I have found the clue as follows. I am not sure but you had better look into this. Analysis

I could see the CSeq No. is jumping in case of the problem as attached screen shot.

I attach new logs and snapshot, please have a look at the issue and then get back to us.

'F' in red indicates our BYE problem in the picture.

SIP_BYE_GOOD_MO_CALL_COM8_20230517_100027.log teraterm_COM8_20230517_100812.log SIP_BYE_FAILURE_MT_CALL_COM8_20230517_095907.log

Thanks, Edward

ahhfzhang commented 1 year ago

Hi Edward,

In the failure log, the CSeq No is correct because when MicroSIP -> ESP32, the ESP32 should use its own CSeq No for ‘BYE’ request, ref: https://datatracker.ietf.org/doc/html/rfc3261#section-24.2

image

Similarly, when ESP32 -> MicroSIP, the ESP32 also use its own CSeq No for request, but this time twillo can reply correctly.

You can try testing ESP32 -> MicroSIP and then MicroSIP request 'BYE' ,In this case, MicroSIP will also use its own CSeq No.

Currently, it is not clear why twillo is responding with 481.

Thanks.

EdwardRyu commented 1 year ago

Thanks Michael for the update.

Will contact Twilio (not MicroSIP) and then get back to you soon.

Thanks.

EdwardRyu commented 1 year ago

Hi Michael,

We found a clue that ESP32 doesn't include 'Route' field in case of failure. And I guess I should have provided more details in accurate way.

Test Details :

  1. 100 calls to 101 and then 100 ends the call.
  2. 101 calls to 100 and then 100 ends the call. --> Only this fails 100%.
  3. 100 calls to 101 and then 101 ends the call.
  4. 101 calls to 100 and then 101 ends the call.
  1. MicroSIP(101) doesn't get BYE message from the server for more than 30 seconds.
  2. ESP device (100) receives '481 ERROR' in response to 'BYE' Request instead of '200 OK'.

Findings :

When we compare the logs from ESP device and MicroSIP, we could see a big difference between failure and success. It is that ESP32 doesn't include 'Route' field for the problematic case.

Here I am attaching log snippets from both ESP32 and MicroSIP for the BYE message. As you can see MicroSIP includes/sends 'Route' field all the time whenever call end is triggered. But ESP32 device doesn't.

It would be appreciated if you have a look into this again with a priority, as it is a long runner and it is critical to our company.

MicroSIP_Called_and_ESP_Ended_FAILURE.log MicroSIP_Called_and_MicroSIP_Ended_OK.log MicroSIP_logs.txt ESP_Called_and_ESP_Ended_OK.log ESP_Called_and_MicroSIP_Ended_OK.log

Thanks, Edward

BYE REQUEST @MicroSIP, ESP made a call to MicroSIP and then MicroSIP ended a call.

BYE sip:100@172.25.85.132:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.0.28.192:52331;rport;branch=z9hG4bKPje077205961c74218a45e20556423dc3c Max-Forwards: 70 From: sip:101@10.0.28.192;tag=ec411f296ad84e0a8ff0418e7d96772e To: "100" sip:100@epicsafetysiptest.sip.twilio.com;tag=32740858_c3356d0b_e20dbff0-3c8a-4cf3-b660-2def6517cab5 Call-ID: 3e88333d0dac3a71decbc40be1917216@0.0.0.0 CSeq: 24389 BYE Route: <sip:54.172.60.0;lr;twnat=sip:207.6.10.148:52331> User-Agent: MicroSIP/3.21.3 Content-Length: 0

BYE REQUEST @MicroSIP, MicroSIP made a call to ESP and then MicroSIP ended a call.

BYE sip:172.25.22.72:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.28.192:52331;rport;branch=z9hG4bKPj3d946c7f304b4de6a1445ad807e93790 Max-Forwards: 70 From: "SIP internal 101" sip:101@epicsafetysiptest.sip.twilio.com;tag=fce8c68d5c9842c3b0a72bd09732c774 To: sip:100@epicsafetysiptest.sip.twilio.com;tag=72148993_c3356d0b_5aeda338-17e3-4c3c-b34d-04766eb05189 Call-ID: f75e8573c8f845328acd1b0ccf931d74 CSeq: 30933 BYE Route: <sip:54.172.60.0;lr;twnat=sip:207.6.10.148:52331> User-Agent: MicroSIP/3.21.3 Content-Length: 0

BYE REQUEST @ESP32, ESP made a call to ESP and then ESP ended a call.

[2023-05-19 09:45:42.324] BYE sip:172.25.19.164:5060 SIP/2.0 [2023-05-19 09:45:42.324] Via: SIP/2.0/UDP 10.0.28.112:18095;received=207.6.10.148;branch=z9hG4bK-135300017;rport=18095 [2023-05-19 09:45:42.324] Route: <sip:54.172.60.2;lr;twnat=sip:207.6.10.148:18095> [2023-05-19 09:45:42.324] From: sip:100@epicsafetysiptest.sip.twilio.com:5060;tag=232746858 [2023-05-19 09:45:42.324] To: sip:101@epicsafetysiptest.sip.twilio.com:5060;tag=71224791_c3356d0b_59edce53-661e-4541-a2d5-42911eb01b66 [2023-05-19 09:45:42.324] Contact: sip:100@10.0.28.112:18095;transport=UDP [2023-05-19 09:45:42.324] Max-Forwards: 70 [2023-05-19 09:45:42.324] Call-ID: 5927BAE1824C4E18CC5706F90EB5FF30C16E060EF5E2 [2023-05-19 09:45:42.324] CSeq: 5 BYE [2023-05-19 09:45:42.324] Expires: 3600 [2023-05-19 09:45:42.324] User-Agent: ESP32 SIP/2.0 [2023-05-19 09:45:42.324] Content-Length: 0 [2023-05-19 09:45:42.324] Authorization: Digest username="100", realm="sip.twilio.com", nonce="U65JY72n4CdDIrgW9yRHdhG58_AI0my127BjE9yDtvEDlkzq", uri="sip:epicsafetysiptest.sip.twilio.com:5060", response="70ef043ee97d303738cfa18deeed067a", algorithm=MD5, qop=auth, nc=00000002, cnonce="edb3dd6befc00c86", opaque="f36efc836766b5d4c50379d884b0839a"

BYE REQUEST @ESP32, MicroSIP made a call to ESP and then ESP ended a call. !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! FAILURE !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

[2023-05-19 09:48:04.065] BYE sip:101@172.25.59.67:5060;transport=udp SIP/2.0 [2023-05-19 09:48:04.065] Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK7d5c.20d454da70c35d38d9faab3a79f37e36.0 [2023-05-19 09:48:04.065] Via: SIP/2.0/UDP 172.25.59.67:5060;rport=5060;received=3.88.65.162;branch=z9hG4bKeaee0131-5d2c-4561-af8a-5b3250401a98_c3356d0b_555-8895710993749738194 [2023-05-19 09:48:04.065] From: sip:100@10.0.28.112:11045;tag=-587730812 [2023-05-19 09:48:04.065] To: "101" sip:101@epicsafetysiptest.sip.twilio.com;tag=04848179_c3356d0b_eaee0131-5d2c-4561-af8a-5b3250401a98 [2023-05-19 09:48:04.065] Contact: sip:100@10.0.28.112:11045;transport=UDP [2023-05-19 09:48:04.065] Max-Forwards: 70 [2023-05-19 09:48:04.075] Call-ID: a16e22c211e8e47fe63c67acaa43f2c3@0.0.0.0 [2023-05-19 09:48:04.075] CSeq: 3 BYE [2023-05-19 09:48:04.075] Expires: 3600 [2023-05-19 09:48:04.075] User-Agent: ESP32 SIP/2.0 [2023-05-19 09:48:04.075] Content-Length: 0 [2023-05-19 09:48:04.075] Authorization: Digest username="100", realm="sip.twilio.com", nonce="pla6tFD5Kas5ZxdEKXMRbh9F--es4nLf4ZBDz3f4nt8MB0Ut", uri="sip:epicsafetysiptest.sip.twilio.com:5060", response="5e595b7fa9d54d81e7ecd406d6f4e12a", algorithm=MD5, qop=auth, nc=00000002, cnonce="57c188b120cf15a4", opaque="597395751040cbd1a323c27457d4b324"

ahhfzhang commented 1 year ago

Hi Edward,

Thank you for your detailed analysis. It looks reasonable. I have made a modification to add this "Record" field.

libesp_media_protocols_esp32.zip

Please help to replace to esp-adf-libs\esp_media_protocols\lib\esp32 directory and test again, thanks.

EdwardRyu commented 1 year ago

Thank you, Michael, for your support.

I tested it but it doesn't work. 'Route' field has been included, but we still have 481 error as an response. I will keep communication with Twilio and then get back to you.

Thanks. Edward

BYE sip:101@172.25.90.229:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKaa5f.4cc3d89527cfee61055932ce9988c0ae.0 Via: SIP/2.0/UDP 172.25.90.229:5060;rport=5060;received=54.205.135.121;branch=z9hG4bK4bb137d8-5577-4f00-b025-0ca8b34a106d_c3356d0b_561-3261834192875044748 Route: sip:54.172.60.0;lr;twnat=sip:207.6.10.148:19446 From: sip:100@10.0.28.128:19446;tag=-1226794112 To: "101" sip:101@epicsafetysiptest.sip.twilio.com;tag=58670300_c3356d0b_4bb137d8-5577-4f00-b025-0ca8b34a106d Contact: sip:100@10.0.28.128:19446;transport=UDP Max-Forwards: 70 Call-ID: 4fcfeac91be99541077a4961772ffc0f@0.0.0.0 CSeq: 3 BYE Expires: 3600 User-Agent: ESP32 SIP/2.0 Content-Length: 0 Authorization: Digest username="100", realm="sip.twilio.com", nonce="5xfkwlTOLZVY9OvklsFMdJRrEk6C0n2i0TyL7ct1YUOE6bp7", uri="sip:epicsafetysiptest.sip.twilio.com:5060", response="c56ea3e7f7ec447b28582181346c9b22", algorithm=MD5, qop=auth, nc=00000002, cnonce="f150bc0acf26478d", opaque="78624f3f9f72ab04706f62bf6a9bbab9"

I (107454) SIP: [1970-01-01/00:01:23]=======================>> I (107532) SIP: [1970-01-01/00:01:23]<<=====READ 0597 bytes== I (107533) SIP:

SIP/2.0 481 Call/Transaction Does Not Exist Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKaa5f.4cc3d89527cfee61055932ce9988c0ae.0;rport=19446;received=207.6.10.148 Via: SIP/2.0/UDP 172.25.90.229:5060;rport=5060;received=54.205.135.121;branch=z9hG4bK4bb137d8-5577-4f00-b025-0ca8b34a106d_c3356d0b_561-3261834192875044748 From: sip:100@10.0.28.128:19446;tag=-1226794112 To: "101" sip:101@epicsafetysiptest.sip.twilio.com;tag=58670300_c3356d0b_4bb137d8-5577-4f00-b025-0ca8b34a106d Call-ID: 4fcfeac91be99541077a4961772ffc0f@0.0.0.0 CSeq: 3 BYE Server: Twilio Gateway Content-Length: 0

EdwardRyu commented 1 year ago

Hi Michael,

I got an update from Twilio as follows. Could you check below analysis and then let me have a new library again?

Our baseline SW is ADFv2.5 & IDFv4.4.4 as described in the beginning.

**

Edward,

Could you try sending the Route value within angle brackets <> and retest?

So it will look like this Route: <sip:54.172.60.3;lr;twnat=sip:207.6.10.148:12751>

**

Thanks, Edward

ahhfzhang commented 1 year ago

Hi Edward,

ok. libesp_media_protocols_esp32.zip

EdwardRyu commented 1 year ago

Hi Michael,

Now the problem has gone. Thanks for your great support on this.

Regards, Edward