search

espressif / esp-adf

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

使用4G联网方式，voip接通没有声音 (AUD-4460) #967

Closed zdodo55 closed 1 year ago

zdodo55 commented 1 year ago

使用环境： esp-adf-v2.4.1 esp-idf-v4.4.4 设备：ESP32-S3-WROOM-1 N16R8 + 移远Cat1 4G模组 EC800MCNLA-I05-SNNDA 例程：https://github.com/espressif/esp-adf/tree/v2.4.1/examples/advanced_examples/voip https://github.com/espressif/esp-iot-solution/tree/master/examples/usb/host/usb_cdc_4g_module 服务端：ubuntu_18.04.6/freeswitch-1.10.9 电脑端：MicroSIP-3.21.3 手机端：Linphone-5.0.1

问题描述：

设备采用4G或者WiFi联网，均能正常连接freeswitch服务器和物联网服务器，如腾讯云，并可正常收发数据。

MicroSIP/Linphone呼叫设备，或者设备呼叫MicroSIP/Linphone，接通后没有任何声音。 而如果设备采用WiFi方式联网，没有以上问题。 Linphone与MicroSIP互通也没有问题， 手机端Linphone采用4G联网，

其中MicroSIP，Linphone和设备与freeswitch连接均采用公网IP连接，UDP方式，

由于自己对Wireshark包分析不熟悉，也没看出两种数据有哪些差异。 不知道哪个环节出问题了。

Wireshark抓包： voip_4g.zip voip_wifi.zip

log

I (43303) SIP: [2023-03-15/16:58:16]<<=====READ 1297 bytes==
I (43304) SIP:

INVITE sip:1002@112.60.207.63:15910;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK3U7HZB499XQNB
Route: <sip:1002@111.55.138.125:20070>;transport=UDP
Max-Forwards: 69
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=gSvj48SrK598K
To: <sip:1002@112.60.207.63:15910;transport=UDP>
Call-ID: 6733786e-3db2-123c-c4a0-000c29a346c1
CSeq: 64881564 INVITE
Contact: <sip:mod_sofia@183.17.231.186:5760>
User-Agent: FreeSWITCH-mod_sofia/1.10.9-release+git~20230203T200730Z~a615e85afc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 247
X-FS-Support: update_display,send_info
Remote-Party-ID: "Extension 1000" <sip:1000@192.168.2.57>;party=calling;screen=yes;privacy=off

v=0
o=FreeSWITCH 1678864976 1678864977 IN IP4 183.17.231.186
s=FreeSWITCH
c=IN IP4 183.17.231.186
t=0 0
m=audio 5736 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

I (43417) SIP: [2023-03-15/16:58:16]<<======================
I (43424) SIP: Remote RTP port=5736
I (43428) SIP: Remote RTP addr=183.17.231.186
I (43433) SIP: call from 1000
I (43437) SIP: [2023-03-15/16:58:16]=======WRITE 0434 bytes>>
I (43443) SIP:

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK3U7HZB499XQNB
Contact: <sip:1002@112.60.207.63:15910>
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=gSvj48SrK598K
To: <sip:1002@112.60.207.63:15910;transport=UDP>;tag=1223670573
Call-ID: 6733786e-3db2-123c-c4a0-000c29a346c1
CSeq: 64881564 INVITE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 0

I (43484) SIP: [2023-03-15/16:58:16]=======================>>
I (43492) SIP: [2023-03-15/16:58:16]=======WRITE 0435 bytes>>
I (43497) SIP:

SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK3U7HZB499XQNB
Contact: <sip:1002@112.60.207.63:15910>
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=gSvj48SrK598K
To: <sip:1002@112.60.207.63:15910;transport=UDP>;tag=-580635144
Call-ID: 6733786e-3db2-123c-c4a0-000c29a346c1
CSeq: 64881564 INVITE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 0

I (43539) SIP: [2023-03-15/16:58:16]=======================>>
W (43546) SIP: CHANGE STATE FROM 2, TO 16, :func: _sip_uas_process_req_invite:873
I (44554) voip: ringing... RemotePhoneNum 1000
I (44554) SIP: [2023-03-15/16:58:16]=======WRITE 0620 bytes>>
I (44555) SIP:

SIP/2.0 200 OK
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK3U7HZB499XQNB
Contact: <sip:1002@112.60.207.63:15910>
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=gSvj48SrK598K
To: <sip:1002@112.60.207.63:15910;transport=UDP>;tag=1366411781
Call-ID: 6733786e-3db2-123c-c4a0-000c29a346c1
CSeq: 64881564 INVITE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 157
Content-Type: application/sdp

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

I (44613) SIP: [2023-03-15/16:58:16]=======================>>
I (44738) SIP: [2023-03-15/16:58:16]<<=====READ 0397 bytes==
I (44739) SIP:

ACK sip:1002@112.60.207.63:15910 SIP/2.0
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK440a16mD76D8p
Max-Forwards: 70
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=gSvj48SrK598K
To: <sip:1002@112.60.207.63:15910;transport=UDP>;tag=1366411781
Call-ID: 6733786e-3db2-123c-c4a0-000c29a346c1
CSeq: 64881564 ACK
Contact: <sip:mod_sofia@183.17.231.186:5760>
Content-Length: 0

I (44772) SIP: [2023-03-15/16:58:16]<<======================
W (44780) SIP: CHANGE STATE FROM 16, TO 32, :func: sip_uas_process_req:942
I (44786) voip: SIP_EVENT_AUDIO_SESSION_BEGIN
I (44791) AUDIO_PIPELINE: link el->rb, el:0x3d817404, tag:algo, rb:0x3d8186d4
I (44799) AUDIO_PIPELINE: link el->rb, el:0x3d818564, tag:audio_encoder, rb:0x3d818814
I (44808) AUDIO_PIPELINE: link el->rb, el:0x3d8188c0, tag:raw_write, rb:0x3d818b84
I (44816) AUDIO_ELEMENT: [raw_write-0x3d8188c0] Element task created
I (44823) AUDIO_THREAD: The audio_decoder task allocate stack on external memory
I (44831) AUDIO_ELEMENT: [audio_decoder-0x3d818a14] Element task created
I (44838) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:8424983 Bytes, Inter:142819 Bytes, Dram:142819 Bytes

I (44850) AUDIO_ELEMENT: [audio_decoder] AEL_MSG_CMD_RESUME,state:1
I (44857) CODEC_ELEMENT_HELPER: The element is 0x3d818a14. The reserve data 2 is 0x0.
I (44858) AUDIO_PIPELINE: Pipeline started
I (44870) AUDIO_THREAD: The algo task allocate stack on external memory
I (44878) AUDIO_ELEMENT: [algo-0x3d817404] Element task created
I (44884) AUDIO_THREAD: The audio_encoder task allocate stack on external memory
I (44892) AUDIO_ELEMENT: [audio_encoder-0x3d818564] Element task created
I (44900) AUDIO_ELEMENT: [raw_read-0x3d817288] Element task created
I (44907) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:8411987 Bytes, Inter:142123 Bytes, Dram:142123 Bytes

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

I (44931) AFE_VC: AFE version: VC_V220727

E (44936) SR_SYS: Data cache should be 64KB
E (44941) SR_SYS: Data cache line should be 64B
I (44946) AFE_VC: Initial auido front-end, total channel: 2, mic num: 1, ref num: 1

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

I (44960) AFE_VC: wakenet_init: 0

I (44978) AUDIO_ELEMENT: [audio_encoder] AEL_MSG_CMD_RESUME,state:1
I (44979) AUDIO_PIPELINE: Pipeline started
I (44979) SIP_RTP: receive task, local addr=255.255.63.179:38224
:5736980) SIP_RTP: send task, remote addr=183.17.231.186
I (44988) AFE_VC: mode: 0, (Aug 23 2022 18:31:47)

I (44998) AUDIO_THREAD: The algo_fetch task allocate stack on external memory
I (49228) SIP: [2023-03-15/16:58:19]<<=====READ 0622 bytes==
I (49229) SIP:

BYE sip:1002@112.60.207.63:15910 SIP/2.0
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK5Dt3215g4F4tj
Max-Forwards: 70
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=gSvj48SrK598K
To: <sip:1002@112.60.207.63:15910;transport=UDP>;tag=1366411781
Call-ID: 6733786e-3db2-123c-c4a0-000c29a346c1
CSeq: 64881565 BYE
User-Agent: FreeSWITCH-mod_sofia/1.10.9-release+git~20230203T200730Z~a615e85afc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0

I (49282) SIP: [2023-03-15/16:58:19]<<======================
I (49304) SIP_RTP: send task stopped
I (49329) voip: SIP_EVENT_AUDIO_SESSION_END
W (49329) AUDIO_ELEMENT: IN-[audio_decoder] AEL_IO_ABORT
W (49329) AUDIO_PIPELINE: There are no listener registered
I (49335) AUDIO_PIPELINE: audio_pipeline_unlinked
W (49340) AUDIO_ELEMENT: [raw_write] Element has not create when AUDIO_ELEMENT_TERMINATE
W (49349) AUDIO_ELEMENT: [audio_decoder] Element has not create when AUDIO_ELEMENT_TERMINATE
E (49358) AUDIO_ELEMENT: [audio_encoder] ERROR_PROCESS, AEL_IO_FAIL
W (49365) AUDIO_ELEMENT: [audio_encoder] audio_element_on_cmd_error,3
W (49382) AUDIO_ELEMENT: OUT-[algo] AEL_IO_ABORT
I (49382) ALGORITHM_STREAM: _algo_fetch_task is stopped
I (49384) AFE_VC: afe_se_task quit

I (49387) AFE_VC: afe task destroy finished

I (49395) AFE_VC: exit function: afe_destory

W (49398) AUDIO_PIPELINE: There are no listener registered
I (49404) AUDIO_PIPELINE: audio_pipeline_unlinked
W (49409) AUDIO_ELEMENT: [algo] Element has not create when AUDIO_ELEMENT_TERMINATE
W (49417) AUDIO_ELEMENT: [audio_encoder] Element has not create when AUDIO_ELEMENT_TERMINATE
W (49427) AUDIO_ELEMENT: [raw_read] Element has not create when AUDIO_ELEMENT_TERMINATE
I (49435) SIP_RTP: receive task stopped
I (49440) SIP_RTP: RTP stopped
I (49443) voip: SIP_EVENT_HANGUP
W (49447) SIP: CHANGE STATE FROM 32, TO 2, :func: sip_uas_process_req:912
I (49455) SIP: [2023-03-15/16:58:19]=======WRITE 0441 bytes>>
I (49461) SIP:

SIP/2.0 200 OK
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK5Dt3215g4F4tj
Contact: <sip:1002@112.60.207.63:15910>
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=gSvj48SrK598K
To: <sip:1002@112.60.207.63:15910;transport=UDP>;tag=1366411781;tag=834947472
Call-ID: 6733786e-3db2-123c-c4a0-000c29a346c1
CSeq: 64881565 BYE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 0

I (49503) SIP: [2023-03-15/16:58:19]=======================>>
ahhfzhang commented 1 year ago

Hi @zdodo55

分析:

通过你发的抓包信息看，这里服务器将所有的音频数据发送给了一个IP地址 '176.129.19.60' ，看起来4G给的虚拟内网地址不属于私有网段，而WiFi给的内网地址属于私有网段，导致服务器认为'176.129.19.60'是个公网地址，直接往这个地址发送数据，从而导致没有数据。

我们在ADF v2.5 中已经fix此问题，只需要将配置项use_public_addr打开，使用公网地址与服务器交互。

zdodo55 commented 1 year ago

嗨@zdodo55

分析:

通过你发的抓包信息看，这里服务器将所有的音频数据发送给了一个IP地址 '176.129.19.60' ，看起来4G给的虚拟内网地址不属于私有网段，而WiFi给的内网地址属于私有网段，导致服务器认为'176.129.19.60'是个公网地址，直接往这个地址发送数据，从而导致没有数据。

我们在ADF v2.5 中已经修复此问题，只需要将配置项use_public_addr打开，使用公网地址与服务器交互。

ADF v2.5中voip的例程变化有点大呀，而且要一堆的依赖，什么av_stream，usb_stream，esp32-camera，lcd 只是要用个音频，非得整一堆，头大！ ADF v2.5中voip能有简单点的例程不？

ahhfzhang commented 1 year ago

这个不仅仅是给VoIP用的，是我们把音视频放在一起的，媒体部分也很简单吧，都是可以自己去裁剪的。

另外如果有看懂我们接口的话，你可以自己去实现媒体的部分，或者参考版本之前的方式。

zdodo55 commented 1 year ago

我已经移植好了，voip其实只用到音频流，av_stream，usb_stream，esp32-camera，lcd这些都有点唬人。

使用ADF v2.5后的确解决了接通没有声音的问题了，但是又产生了另外的问题：

采用4G联网方式接通后，如果MicroSIP端主动挂断，设备端不知道有没有挂断，反正没有产生“ESP_RTC_EVENT_AUDIO_SESSION_END”或者“ESP_RTC_EVENT_HANGUP”事件。 不管use_public_addr是0或1都是一样结果。 但是如果设备端主动挂断就没有问题。

Wireshark抓包： voip_4g_0317.zip voip_wifi_0317.zip

log：

I (31692) SIP: [1970-01-01/08:00:15]<<=====READ 1241 bytes==
I (31693) SIP: 

INVITE sip:1001@39.144.10.14:63894;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK474FHFt2KvFjD
Max-Forwards: 69
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=H5my8UKr04ySB
To: <sip:1001@39.144.10.14:63894;transport=UDP>
Call-ID: 8debe389-3f39-123c-22ad-000c29a346c1
CSeq: 64965563 INVITE
Contact: <sip:mod_sofia@183.17.231.186:5760>
User-Agent: FreeSWITCH-mod_sofia/1.10.9-release+git~20230203T200730Z~a615e85afc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 247
X-FS-Support: update_display,send_info
Remote-Party-ID: "Extension 1000" <sip:1000@192.168.2.57>;party=calling;screen=yes;privacy=off

v=0
o=FreeSWITCH 1679028524 1679028525 IN IP4 183.17.231.186
s=FreeSWITCH
c=IN IP4 183.17.231.186
t=0 0
m=audio 5762 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

I (31801) SIP: [1970-01-01/08:00:15]<<======================
I (31808) SIP: Remote ARTP port=5762
I (31812) SIP: Remote RTP addr=183.17.231.186
I (31817) SIP: call from 1000
I (31821) SIP: [1970-01-01/08:00:15]=======WRITE 0432 bytes>>
I (31827) SIP: 

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK474FHFt2KvFjD
Contact: <sip:1001@39.144.10.14:63894>
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=H5my8UKr04ySB
To: <sip:1001@39.144.10.14:63894;transport=UDP>;tag=-881623574
Call-ID: 8debe389-3f39-123c-22ad-000c29a346c1
CSeq: 64965563 INVITE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 0

I (31868) SIP: [1970-01-01/08:00:15]=======================>>
I (31875) SIP: [1970-01-01/08:00:15]=======WRITE 0432 bytes>>
I (31881) SIP: 

SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK474FHFt2KvFjD
Contact: <sip:1001@39.144.10.14:63894>
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=H5my8UKr04ySB
To: <sip:1001@39.144.10.14:63894;transport=UDP>;tag=443353345
Call-ID: 8debe389-3f39-123c-22ad-000c29a346c1
CSeq: 64965563 INVITE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 0

I (31923) SIP: [1970-01-01/08:00:15]=======================>>
W (31929) SIP: CHANGE STATE FROM 2, TO 16, :func: _sip_uas_process_req_invite:949
W (33037) voip: ESP_RTC_EVENT_INCOMING...
I (33037) SIP: [1970-01-01/08:00:15]=======WRITE 0605 bytes>>
I (33038) SIP: 

SIP/2.0 200 OK
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK474FHFt2KvFjD
Contact: <sip:1001@39.144.10.14:63894>
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=H5my8UKr04ySB
To: <sip:1001@39.144.10.14:63894;transport=UDP>;tag=280830238
Call-ID: 8debe389-3f39-123c-22ad-000c29a346c1
CSeq: 64965563 INVITE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 145
Content-Type: application/sdp

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

I (33094) SIP: [1970-01-01/08:00:16]=======================>>
I (33270) SIP: [1970-01-01/08:00:16]<<=====READ 0394 bytes==
I (33271) SIP: 

ACK sip:1001@39.144.10.14:63894 SIP/2.0
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK5gy8jaB6g554r
Max-Forwards: 70
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=H5my8UKr04ySB
To: <sip:1001@39.144.10.14:63894;transport=UDP>;tag=280830238
Call-ID: 8debe389-3f39-123c-22ad-000c29a346c1
CSeq: 64965563 ACK
Contact: <sip:mod_sofia@183.17.231.186:5760>
Content-Length: 0

I (33304) SIP: [1970-01-01/08:00:16]<<======================
W (33311) voip: ESP_RTC_EVENT_AUDIO_SESSION_BEGIN
I (33316) AUDIO_PIPELINE: link el->rb, el:0x3d81602c, tag:algo, rb:0x3d8172fc
I (33323) AUDIO_PIPELINE: link el->rb, el:0x3d81718c, tag:audio_encoder, rb:0x3d81743c
I (33332) AUDIO_PIPELINE: link el->rb, el:0x3d8174e8, tag:raw_write, rb:0x3d8177ac
I (33340) AUDIO_ELEMENT: [raw_write-0x3d8174e8] Element task created
I (33347) AUDIO_THREAD: The audio_decoder task allocate stack on external memory
I (33355) AUDIO_ELEMENT: [audio_decoder-0x3d81763c] Element task created
I (33363) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:8419819 Bytes, Inter:132491 Bytes, Dram:132491 Bytes

I (33375) AUDIO_ELEMENT: [audio_decoder] AEL_MSG_CMD_RESUME,state:1
I (33382) CODEC_ELEMENT_HELPER: The element is 0x3d81763c. The reserve data 2 is 0x0.
I (33383) AUDIO_PIPELINE: Pipeline started
I (33395) AUDIO_THREAD: The algo task allocate stack on external memory
I (33402) AUDIO_ELEMENT: [algo-0x3d81602c] Element task created
I (33409) AUDIO_THREAD: The audio_encoder task allocate stack on external memory
I (33417) AUDIO_ELEMENT: [audio_encoder-0x3d81718c] Element task created
I (33424) AUDIO_ELEMENT: [raw_read-0x3d815eb0] Element task created
I (33431) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:8406335 Bytes, Inter:131795 Bytes, Dram:131795 Bytes

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

I (33455) AFE_VC: AFE version: VC_V220727

E (33460) SR_SYS: Data cache should be 64KB
E (33465) SR_SYS: Data cache line should be 64B

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

I (33485) AFE_VC: wakenet_init: 0, voice_communication_agc_init: 1

I (33502) AUDIO_ELEMENT: [audio_encoder] AEL_MSG_CMD_RESUME,state:1
I (33502) AUDIO_PIPELINE: Pipeline started
W (33504) SIP: CHANGE STATE FROM 16, TO 32, :func: sip_uas_process_req:1024
I (33512) AFE_VC: mode: 0, (Nov  3 2022 11:49:25)

I (33517) AUDIO_THREAD: The algo_fetch task allocate stack on external memory
I (35079) SIP: [1970-01-01/08:00:17]<<=====READ 0619 bytes==
I (35080) SIP: 

BYE sip:1001@39.144.10.14:63894 SIP/2.0
Via: SIP/2.0/UDP 183.17.231.186:5760;rport;branch=z9hG4bK6SQ1m5U9DevQm
Max-Forwards: 70
From: "Extension 1000" <sip:1000@192.168.2.57>;tag=H5my8UKr04ySB
To: <sip:1001@39.144.10.14:63894;transport=UDP>;tag=280830238
Call-ID: 8debe389-3f39-123c-22ad-000c29a346c1
CSeq: 64965564 BYE
User-Agent: FreeSWITCH-mod_sofia/1.10.9-release+git~20230203T200730Z~a615e85afc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0

I (35133) SIP: [1970-01-01/08:00:17]<<======================
zdodo55 commented 1 year ago

我发现，adf-v2.5参照v2.4.1移植voip，设备经常不应答服务器的BYE挂断请求，不知为何。 以下是我移植的voip，adf-v2.5 voip_app.zip

zdodo55 commented 1 year ago

我发现，adf-v2.5参照v2.4.1移植voip，设备经常不应答服务器的BYE挂断请求，不知为何。 以下是我移植的voip，adf-v2.5 voip_app.zip

从设备的log来看，设备已经收到服务器发来的挂机BYE指令了，然而设备却没有应答服务器， 此时设备似乎sip服务已经挂了，没有任何的调试信息输出了，正常的话应该会有SIP: Sending keep-alive to server的心跳调试信息，无论通话中或者空闲都有。 但是按键又是可以响应，只是挂机或者拨号都没有响应了。

ahhfzhang commented 1 year ago

Hi @zdodo55

这个问题只在4G场景下出现吗？

看起来是收到了bye的包，可以帮忙将log等级调到ESP_LOG_DEBUG吗，这样可以打印出更多信息来。

zdodo55 commented 1 year ago

Hi @zdodo55

这个问题只在4G场景下出现吗？

看起来是收到了bye的包，可以帮忙将log等级调到ESP_LOG_DEBUG吗，这样可以打印出更多信息来。

4G场景和WiFi场景都会出现。 我把log等级调到ESP_LOG_DEBUG后再贴上相关log

zdodo55 commented 1 year ago

Hi @zdodo55 这个问题只在4G场景下出现吗？ 看起来是收到了bye的包，可以帮忙将log等级调到ESP_LOG_DEBUG吗，这样可以打印出更多信息来。

4G场景和WiFi场景都会出现。 我把log等级调到ESP_LOG_DEBUG后再贴上相关log

WiFi场景下，如果是被动呼入接通，基本不会重现问题，但是如果是主动呼出接通就基本会出现此问题， 出现问题后一直无限重复输出以下log：

D (114132) ALGORITHM_STREAM: VAD state : SILENCE
D (114132) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114140) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206

完整log如下

BYE sip:1001@16.237.202.63:18251;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 183.17.229.180:5760;rport;branch=z9hG4bK4B2ev5X0eSyce
Max-Forwards: 70
From: <sip:1000@183.17.229.180:5760>;tag=rva0jNrgK5DXF
To: <sip:1001@183.17.229.180:5760>;tag=-1449441021
Call-ID: 8DE97E52BBAB45D24EE35479EA7D6A4EEF78366A5CAC
CSeq: 65179505 BYE
User-Agent: FreeSWITCH-mod_sofia/1.10.9-release+git~20230203T200730Z~a615e85afc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0

I (114122) SIP: [1970-01-01/00:01:26]<<======================
D (114132) ALGORITHM_STREAM: VAD state : SILENCE
D (114132) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114140) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114206) ALGORITHM_STREAM: VAD state : SILENCE
D (114207) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114281) ALGORITHM_STREAM: VAD state : SILENCE
D (114281) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=207
D (114282) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=207
D (114354) ALGORITHM_STREAM: VAD state : SILENCE
D (114355) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=207
D (114392) ALGORITHM_STREAM: VAD state : SILENCE
D (114392) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=207
D (114393) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206

4G场景下，无论是被动呼入接通，还是主动呼出接通都会出现此问题， 出现问题后一直无限重复输出以下log：

D (114132) ALGORITHM_STREAM: VAD state : SILENCE
D (114132) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114140) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206

完整log：

D (113958) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (113960) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (113970) I2S: aim_bytes 2 src_bytes 2 size 320
D (113990) I2S: aim_bytes 2 src_bytes 2 size 320
D (113998) ALGORITHM_STREAM: VAD state : SILENCE
D (113998) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114010) I2S: aim_bytes 2 src_bytes 2 size 320
D (114025) ALGORITHM_STREAM: VAD state : SILENCE
D (114025) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114026) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114030) I2S: aim_bytes 2 src_bytes 2 size 320
D (114050) I2S: aim_bytes 2 src_bytes 2 size 320
D (114057) ALGORITHM_STREAM: VAD state : SILENCE
D (114058) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
I (114068) SIP: [1970-01-01/00:01:26]<<=====READ 0621 bytes==
I (114069) SIP: 

BYE sip:1001@16.237.202.63:18251;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 183.17.229.180:5760;rport;branch=z9hG4bK4B2ev5X0eSyce
Max-Forwards: 70
From: <sip:1000@183.17.229.180:5760>;tag=rva0jNrgK5DXF
To: <sip:1001@183.17.229.180:5760>;tag=-1449441021
Call-ID: 8DE97E52BBAB45D24EE35479EA7D6A4EEF78366A5CAC
CSeq: 65179505 BYE
User-Agent: FreeSWITCH-mod_sofia/1.10.9-release+git~20230203T200730Z~a615e85afc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0

I (114122) SIP: [1970-01-01/00:01:26]<<======================
D (114132) ALGORITHM_STREAM: VAD state : SILENCE
D (114132) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114140) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114206) ALGORITHM_STREAM: VAD state : SILENCE
D (114207) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114281) ALGORITHM_STREAM: VAD state : SILENCE
D (114281) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=207
D (114282) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=207
D (114354) ALGORITHM_STREAM: VAD state : SILENCE
D (114355) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=207
D (114392) ALGORITHM_STREAM: VAD state : SILENCE
D (114392) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=207
D (114393) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
D (114466) ALGORITHM_STREAM: VAD state : SILENCE
D (114466) USB_HCDC: cdc write itf: 0, p = 0x3fcd087c, len=206
ahhfzhang commented 1 year ago

Hi @zdodo55

我使用wifi环境没能复制到你说的这个问题，方便给一个跟完整的log，我想看一下这之前的交互发生了什么。

zdodo55 commented 1 year ago

Hi @zdodo55

我使用wifi环境没能复制到你说的这个问题，方便给一个跟完整的log，我想看一下这之前的交互发生了什么。

WiFi环境完整log.zip

ahhfzhang commented 1 year ago

Hi @zdodo55

esp_media_protocols_debug.zip 替换这个debug lib，然后抓取一份log给我，同样是开了DEBUG等级的。

zdodo55 commented 1 year ago

Hi @zdodo55

esp_media_protocols_debug.zip 替换这个debug lib，然后抓取一份log给我，同样是开了DEBUG等级的。

WiFi网络完整log_debug.zip

ahhfzhang commented 1 year ago

task 任务栈状态打印出来看一下

zdodo55 commented 1 year ago

你好，如何能申请两个贵公司的SIP服务器测试账号？ 现在公司的外网IP出现问题了，自己建的Freeswitch服务器没法用了。

zdodo55 commented 1 year ago

task 任务栈状态打印出来看一下

WiFi网络完整log+任务栈状态_debug.zip

MrYanLK commented 1 year ago

@ahhfzhang 麻烦再看一下这个问题，感谢

ahhfzhang commented 1 year ago

这个似乎卡在了一个很奇怪的地方，我在本地调试看看。

zdodo55 commented 1 year ago

这个似乎卡在了一个很奇怪的地方，我在本地调试看看。

@ahhfzhang 不知道会不会跟服务器有关系，之前使用的本地电脑来安装freeswitch，现在使用云服务器来安装freeswitch，centos7.6和Windows Server 2022都试过，效果一样。 可否申请两个你们服务器的SIP账号测试一下？

qiuwei79 commented 1 year ago

@zdodo55 我们这几天也碰到你这几乎类似的问题，2.5用起来没有2.4稳定，加我微信语音讨论一下：d3d3cXcyMDAw【base64】

ahhfzhang commented 1 year ago

@zdodo55 https://github.com/espressif/esp-adf-libs/commit/96a0636c5722653379fa1cf2d340f14a74e759e4 是这里改动导致的，我们后面会添加新的接口，麻烦帮忙先 Revert，看是否还存在问题。

zdodo55 commented 1 year ago

@zdodo55 espressif/esp-adf-libs@96a0636 是这里改动导致的，我们后面会添加新的接口，麻烦帮忙先 Revert，看是否还存在问题。

我发现，adf-v2.5参照v2.4.1移植voip，设备经常不应答服务器的BYE挂断请求，不知为何。 以下是我移植的voip，adf-v2.5 voip_app.zip

@ahhfzhang Revert后使用我自己移植的voip_app.zip问题依旧。o(╯□╰)o

ahhfzhang commented 1 year ago

@zdodo55

  1. 看一下你的 FREERTOS_HZ 是不是1000
  2. 基于原来的example代码。把媒体部分全部拿掉，只跑协议栈，看是否正常。
zdodo55 commented 1 year ago

@zdodo55

  1. 看一下你的 FREERTOS_HZ 是不是1000
  2. 基于原来的example代码。把媒体部分全部拿掉，只跑协议栈，看是否正常。

我发现，adf-v2.5参照v2.4.1移植voip，设备经常不应答服务器的BYE挂断请求，不知为何。 以下是我移植的voip，adf-v2.5 voip_app.zip

@ahhfzhang FREERTOS_HZ 是1000的 我移植的voip_app.zip，就是基于v2.4.1例程，然后移植v2.5的esp_rtc替换原来的esp_sip协议栈的。

ahhfzhang commented 1 year ago

我需要确认的是原生adf v2.5的版本不应该存在这个问题（没有修改的情况下我没有测试到），因为要单独测试协议栈，所以可以把媒体部分都拿掉，我们好对比一下看看。

zdodo55 commented 1 year ago

我需要确认的是原生adf v2.5的版本不应该存在这个问题（没有修改的情况下我没有测试到），因为要单独测试协议栈，所以可以把媒体部分都拿掉，我们好对比一下看看。

你说的把媒体部分拿掉，单独测试协议栈，没能理解。

ahhfzhang commented 1 year ago

Hi @zdodo55

我不确定你的问题到底出在哪里，但基于你发的log，我修改了这部分逻辑，请尝试最新的lib。

libesp_media_protocols.zip

有问题再反馈给我。

zdodo55 commented 1 year ago

Hi @zdodo55

我不确定你的问题到底出在哪里，但基于你发的log，我修改了这部分逻辑，请尝试最新的lib。

libesp_media_protocols.zip

有问题再反馈给我。

@ahhfzhang 替换使用此lib初试真的可以解决无法挂断的问题耶！ 后续深入测试有问题再继续反馈。 感谢！！！

zdodo55 commented 1 year ago

Hi @ahhfzhang 我又发现了一个问题，即.use_public_addr = 1,时，设备上线大概30分钟后就会出现无法呼入的情况，但可以呼出，不过呼出接通后又是出现了之前无法挂断的问题。 使用的adf-v2.5，使用voip例程，或者我自己的工程现象都一样，使用WiFi网络和4G网络现象一样。

而.use_public_addr = 0,时，就没有以上问题， 但是.use_public_addr = 0,又回归了之前使用4G网络的问题。

ε=(´ο｀*)))唉！！！！！！！

zdodo55 commented 1 year ago

Hi @ahhfzhang 我又发现了一个问题，即.use_public_addr = 1,时，设备上线大概30分钟后就会出现无法呼入的情况，但可以呼出，不过呼出接通后又是出现了之前无法挂断的问题。 使用的adf-v2.5，使用voip例程，或者我自己的工程现象都一样，使用WiFi网络和4G网络现象一样。

而.use_public_addr = 0,时，就没有以上问题， 但是.use_public_addr = 0,又回归了之前使用4G网络的问题。

ε=(´ο｀*)))唉！！！！！！！

其中替换和不替换libesp_media_protocols.zip都是一样问题。

zdodo55 commented 1 year ago

Hi @ahhfzhang 我又发现了一个问题，即.use_public_addr = 1,时，设备上线大概30分钟后就会出现无法呼入的情况，但可以呼出，不过呼出接通后又是出现了之前无法挂断的问题。 使用的adf-v2.5，使用voip例程，或者我自己的工程现象都一样，使用WiFi网络和4G网络现象一样。

而.use_public_addr = 0,时，就没有以上问题， 但是.use_public_addr = 0,又回归了之前使用4G网络的问题。

ε=(´ο｀*)))唉！！！！！！！

Hi @ahhfzhang 经测试发现，设备上线后会每隔30分钟进行一次REGISTER注册， 而设备上线后30分钟后进行的第一次REGISTER注册后，此时就出现无法呼入的问题。

ahhfzhang commented 1 year ago

@zdodo55 esp_media_protocols.zip

  1. 使用这个库.use_public_addr = 0 应该也可以解决4G那个问题，帮忙再测试一下，谢谢
  2. config里面也加上了注册间隔的设置

use_public_addr = 1 这里30分钟之后重新注册应该是拿到了新的公网IP，但是为什么服务器找不到，我后面再抓包看一下吧。

zdodo55 commented 1 year ago

@zdodo55 esp_media_protocols.zip

  1. 使用这个库.use_public_addr = 0 应该也可以解决4G那个问题，帮忙再测试一下，谢谢
  2. config里面也加上了注册间隔的设置

use_public_addr = 1 这里30分钟之后重新注册应该是拿到了新的公网IP，但是为什么服务器找不到，我后面再抓包看一下吧。

收到，我测试完继续反馈。

zdodo55 commented 1 year ago

@zdodo55 esp_media_protocols.zip

  1. 使用这个库.use_public_addr = 0 应该也可以解决4G那个问题，帮忙再测试一下，谢谢
  2. config里面也加上了注册间隔的设置

use_public_addr = 1 这里30分钟之后重新注册应该是拿到了新的公网IP，但是为什么服务器找不到，我后面再抓包看一下吧。

收到，我测试完继续反馈。

zdodo55 commented 1 year ago

@zdodo55 esp_media_protocols.zip

  1. 使用这个库.use_public_addr = 0 应该也可以解决4G那个问题，帮忙再测试一下，谢谢
  2. config里面也加上了注册间隔的设置

use_public_addr = 1 这里30分钟之后重新注册应该是拿到了新的公网IP，但是为什么服务器找不到，我后面再抓包看一下吧。

@ahhfzhang 经测试 .use_public_addr = 0还是无法解决4G问题 还有，注册间隔.register_interval到时重新注册后里面就无法在呼入了，设置10分钟，10分钟后就无法呼入，设置超过30分钟，30分钟后就无法呼入。

zdodo55 commented 1 year ago

@ahhfzhang 通过wireshark抓包分析发现，freeswitch上通过sofia status profile internal reg查询到的设备注册IP信息和wireshark抓包的IP信息中端口不对应，是不是这个因为导致无法呼入的问题？

zdodo55 commented 1 year ago

@ahhfzhang 再从设备log分析来看，似乎设备在重新注册的时，设备并没有使用sip服务器返回的外网端口来进行注册，导致freeswitch中设备的注册信息IP端口不正确。

设备重新注册的log

I (178690) SIP: Sending keep-alive to server
W (179710) SIP: CHANGE STATE FROM 2, TO 0, :func: sip_reconnect:378
I (180910) SIP: Conecting...
I (181028) SIP: client local port = 53256
W (181029) SIP: CHANGE STATE FROM 0, TO 1, :func: sip_connect:1803
I (181030) SIP: [2023-05-09/10:56:04]=======WRITE 0602 bytes>>
I (181035) SIP: 

REGISTER sip:175.178.160.122:5060 SIP/2.0
Via: SIP/2.0/TCP 111.55.139.36:53256;branch=z9hG4bK--1256453978;rport
From: <sip:1002@175.178.160.122:5060>;tag=1310330754
To: <sip:1002@175.178.160.122:5060>
Contact: <sip:1002@111.55.139.36:53256;transport=TCP>
Max-Forwards: 70
Call-ID: A4359FDA5F99FBCCCC89385F6C29E7016C35308A23C9
CSeq: 3 REGISTER
Expires: 300
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 (181092) SIP: [2023-05-09/10:56:04]=======================>>
I (181210) SIP: [2023-05-09/10:56:04]<<=====READ 0632 bytes==
I (181211) SIP: 

SIP/2.0 401 Unauthorized
Via: SIP/2.0/TCP 111.55.139.36:53256;branch=z9hG4bK--1256453978;rport=21172
From: <sip:1002@175.178.160.122:5060>;tag=1310330754
To: <sip:1002@175.178.160.122:5060>;tag=390m34ZB0U3QH
Call-ID: A4359FDA5F99FBCCCC89385F6C29E7016C35308A23C9
CSeq: 3 REGISTER
User-Agent: FreeSWITCH-mod_sofia/1.10.9-release~a615e85afc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
WWW-Authenticate: Digest realm="175.178.160.122", nonce="11bd2e4b-2223-4569-91ed-5887baa2bfcb", algorithm=MD5, qop="auth"
Content-Length: 0

I (181265) SIP: [2023-05-09/10:56:04]<<======================
I (181272) SIP: Required authentication
I (181277) SIP: [2023-05-09/10:56:04]=======WRITE 0852 bytes>>
I (181283) SIP: 

REGISTER sip:175.178.160.122:5060 SIP/2.0
Via: SIP/2.0/TCP 111.55.139.36:53256;branch=z9hG4bK--333879791;rport
From: <sip:1002@175.178.160.122:5060>;tag=241671577
To: <sip:1002@175.178.160.122:5060>
Contact: <sip:1002@111.55.139.36:53256;transport=TCP>
Max-Forwards: 70
Call-ID: A4359FDA5F99FBCCCC89385F6C29E7016C35308A23C9
CSeq: 4 REGISTER
Expires: 300
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="1002", realm="175.178.160.122", nonce="11bd2e4b-2223-4569-91ed-5887baa2bfcb", uri="sip:175.178.160.122:5060", response="940a4c84eeda93836403c9d515b803c5", algorithm=MD5, qop=auth, nc=00000001, cnonce="367e41ca9ab641e0"

I (181361) SIP: [2023-05-09/10:56:05]=======================>>
I (181494) SIP: [2023-05-09/10:56:05]<<=====READ 0601 bytes==
I (181495) SIP: 

SIP/2.0 200 OK
Via: SIP/2.0/TCP 111.55.139.36:53256;branch=z9hG4bK--333879791;rport=21172
From: <sip:1002@175.178.160.122:5060>;tag=241671577
To: <sip:1002@175.178.160.122:5060>;tag=4jtD5ZgFX4SaD
Call-ID: A4359FDA5F99FBCCCC89385F6C29E7016C35308A23C9
CSeq: 4 REGISTER
Contact: <sip:1002@111.55.139.36:53256;transport=TCP>;expires=300
Date: Tue, 09 May 2023 02:56:10 GMT
User-Agent: FreeSWITCH-mod_sofia/1.10.9-release~a615e85afc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Length: 0

I (181546) SIP: [2023-05-09/10:56:05]<<======================
I (181554) SIP_SERVICE: ESP_RTC_EVENT_REGISTERED
W (181558) SIP: CHANGE STATE FROM 1, TO 2, :func: sip_register:1831
I (213565) SIP: Sending keep-alive to server

freeswitch的设备注册信息： image

ahhfzhang commented 1 year ago

Hi @zdodo55

是的，后面注册产生新的外网端口，没有及时更新给服务器，导致无法呼入

fix : esp_media_protocols.zip

zdodo55 commented 1 year ago

Hi @zdodo55

是的，后面注册产生新的外网端口，没有及时更新给服务器，导致无法呼入

fix : esp_media_protocols.zip

经测试，完美解决没有声音，无法挂断，无法呼入问题。 1B40AE46