LyraT Mini v1.2 在VOIP例程下不能正常运行，必须手动复位一次才能。

[WangXiaohai]

哈喽，各位，最近调试ESP32-LyraT Mini 1.2的板子在voip例程下不能正常工作的问题。
实验详情：
1.用一块ESP32-LyraT Mini 1.2，使用ESP-ADF自带的ESP-IDF编译，并且下载了“铃声.bin”， Sip服务器搭建好并且2台电脑之间测试完成。
2.在ESP32下载软件之后，可以正常连接WiFi，连接服务器，并且提示连接成功。
3.ESP32在服务器上可以看到已经登陆，注册成功。
4.在电脑端使用Sip客户端呼叫ESP32，能够正常振铃(有振铃提示音)。

5.按键Play按下，能够正常进入语音通信，但是只有喇叭有声音，电脑客户端没有声音。

6.按下RST按键，重新连接服务器之后，能够链接服务器，这时在进行呼叫，双方都正常，有声音。

经过，排查，通过文件存储的形式，最后定位到，在algorithm_stream.c中的 AEC 初始化虽然成功，但是在执行 aec_process(algo->aec_handle, record->aec_buff, reference->aec_buff, algo->aec_buff);无输出到algo->aec_buff。但是通过文件将record->aec_buff，reference->aec_buff, algo->aec_buff 存储，record->aec_buff，reference->aec_buff 均有输出音频。

最后通过手动复位之后，以上错误没有，尝试使用esp_restart(); 软件复位，也不可以。因此必须手动复位一次。

还麻烦看看是什么问题。

[WangXiaohai]

注意：在algorithm_stream.c中的 AEC 初始化虽然成功，但是在执行 aec_process(algo->aec_handle, record->aec_buff, reference->aec_buff, algo->aec_buff);无输出到algo->aec_buff。

通过文件将record->aec_buff，reference->aec_buff, algo->aec_buff 存储。

只有 record->aec_buff，reference->aec_buff 均有输出音频。
algo->aec_buf 是静音的。

[WangXiaohai]

idf branch
* (HEAD detached at 722043f734)
master
remotes/origin/HEAD -> origin/master
remotes/origin/audio/stack_on_psram_v3.3
remotes/origin/ble_mesh_release/esp-ble-mesh-v0.6.1
remotes/origin/customer/maintain_v4.0_xiaomi_tsf_issue
remotes/origin/master
remotes/origin/release/v2.0
remotes/origin/release/v2.1
remotes/origin/release/v3.0
remotes/origin/release/v3.1
remotes/origin/release/v3.2
remotes/origin/release/v3.3
remotes/origin/release/v4.0
remotes/origin/release/v4.1
remotes/origin/release/v4.2
remotes/origin/release/v4.3

esp-adf>git branch -a
* master
remotes/origin/HEAD -> origin/master
remotes/origin/master

[WangXiaohai]

完整的voip log为下
ets Jun 8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x1b (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x1b (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:6928
ho 0 tail 12 room 4
load:0x40078000,len:13020
load:0x40080400,len:7056
entry 0x40080720
I (71) boot: Chip Revision: 1
I (71) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (41) boot: ESP-IDF v3.3.2-107-g722043f734 2nd stage bootloader
I (42) boot: compile time 09:13:04
I (42) boot: Enabling RNG early entropy source...
I (48) qio_mode: Enabling default flash chip QIO
I (53) boot: SPI Speed : 80MHz
I (57) boot: SPI Mode : QIO
I (61) boot: SPI Flash Size : 4MB
I (65) boot: Partition Table:
I (69) boot: ## Label Usage Type ST Offset Length
I (76) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (83) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (91) boot: 2 factory factory app 00 00 00010000 00200000
I (98) boot: 3 flash_tone Unknown data 01 ff 00210000 0007d000
I (106) boot: End of partition table
I (110) boot_comm: chip revision: 1, min. application chip revision: 0
I (117) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x3148c (201868) map
I (178) esp_image: segment 1: paddr=0x000414b4 vaddr=0x3ffb0000 size=0x0387c ( 14460) load
I (183) esp_image: segment 2: paddr=0x00044d38 vaddr=0x40080000 size=0x00400 ( 1024) load
0x40080000: _WindowOverflow4 at D:/wangs/esp-adf/esp-idf/components/freertos/xtensa_vectors.S:1779

I (186) esp_image: segment 3: paddr=0x00045140 vaddr=0x40080400 size=0x0aed0 ( 44752) load
I (209) esp_image: segment 4: paddr=0x00050018 vaddr=0x400d0018 size=0xc0a54 (789076) map
0x400d0018: _flash_cache_start at ??:?

I (413) esp_image: segment 5: paddr=0x00110a74 vaddr=0x4008b2d0 size=0x070d4 ( 28884) load
0x4008b2d0: pxPortInitialiseStack at D:/wangs/esp-adf/esp-idf/components/freertos/port.c:435

I (434) boot: Loaded app from partition at offset 0x10000
I (434) boot: Disabling RNG early entropy source...
I (434) psram: This chip is ESP32-D0WD
I (439) spiram: Found 64MBit SPI RAM device
I (443) spiram: SPI RAM mode: flash 80m sram 80m
I (449) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (456) cpu_start: Pro cpu up.
I (460) cpu_start: Application information:
I (465) cpu_start: Project name: esp-idf
I (469) cpu_start: App version: 6fa0292
I (474) cpu_start: Compile time: Oct 10 2021 09:13:21
I (480) cpu_start: ELF file SHA256: 2adc190804895b01...
I (486) cpu_start: ESP-IDF: v3.3.2-107-g722043f734
I (493) cpu_start: Starting app cpu, entry point is 0x40081468
0x40081468: call_start_cpu1 at D:/wangs/esp-adf/esp-idf/components/esp32/cpu_start.c:268

I (0) cpu_start: App cpu up.
I (978) spiram: SPI SRAM memory test OK
I (979) heap_init: Initializing. RAM available for dynamic allocation:
I (979) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (984) heap_init: At 3FFB4B68 len 0002B498 (173 KiB): DRAM
I (990) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (997) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1003) heap_init: At 400923A4 len 0000DC5C (55 KiB): IRAM
I (1009) cpu_start: Pro cpu start user code
I (1014) spiram: Adding pool of 4077K of external SPI memory to heap allocator
I (140) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (140) spiram: Reserving pool of 18K of internal memory for DMA/internal allocations
I (170) VOIP_EXAMPLE: [1.0] Initialize peripherals management
I (170) VOIP_EXAMPLE: [1.1] Initialize and start peripherals
I (170) VOIP_EXAMPLE: [1.2] Create and start input key service
I (180) VOIP_EXAMPLE: [ 1.3 ] Create display service instance
I (180) VOIP_EXAMPLE: [ 2 ] Start codec chip
I (190) DRV8311: ES8311 in Slave mode
I (200) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
W (210) I2C_BUS: i2c_bus_create:57: I2C bus has been already created, [port:0]
E (210) DRV7243: Es7243 set vol 70
I (220) AUDIO_HAL: Codec mode is 3, Ctrl:1
I (230) VOIP_EXAMPLE: [ 3 ] Initialize tone player
W (230) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (230) ESP_AUDIO_TASK: media_ctrl_task running...,0x3f804ed4

----------------------------- ESP Audio Platform -----------------------------
| |
| ESP_AUDIO-v1.7.0-9-g84df87e-037bef3-09be8fe |
| Compile date: Jul 20 2021-13:51:36 |
------------------------------------------------------------------------------
I (280) ESP_AUDIO_CTRL: Func:media_ctrl_create, Line:350, MEM Total:4422376 Bytes, Inter:323552 Bytes, Dram:267176 Bytes

I (290) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (290) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (300) MP3_DECODER: MP3 init
I (300) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (310) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (310) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (320) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (330) I2S: APLL: Req RATE: 16000, real rate: 15999.986, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 4095996.500, SCLK: 511999.562500, diva: 1, divb: 0
I (340) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (350) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (350) LYRAT_MINI_V1_1: I2S0, MCLK output by GPIO0
I (360) VOIP_EXAMPLE: [ 4 ] Create Wi-Fi service instance
E (360) DISPATCHER: exe first list: 0x0
I (370) DISPATCHER: dispatcher_event_task is running...
W (380) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (390) wifi:wifi driver task: 3ffc82f4, prio:23, stack:3584, core=0
I (390) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (400) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (410) wifi:wifi firmware version: 5f8804c
I (410) wifi:config NVS flash: disabled
I (410) wifi:config nano formating: disabled
I (420) wifi:Init dynamic tx buffer num: 32
I (420) wifi:Init data frame dynamic rx buffer num: 128
I (430) wifi:Init management frame dynamic rx buffer num: 128
I (430) wifi:Init management short buffer num: 32
I (440) wifi:Init static tx buffer num: 9
I (440) wifi:Init static rx buffer size: 1600
I (440) wifi:Init static rx buffer num: 9
I (450) wifi:Init dynamic rx buffer num: 128
I (550) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (550) wifi:mode : sta (ac:67:b2:cc:a7:60)
I (550) WIFI_SERV: Connect to wifi ssid: ChinaNet-903, pwd: wang18924591212
I (1640) wifi<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:1
I (2330) wifi:state: init -> auth (b0)
I (2330) wifi:state: auth -> assoc (0)
I (2340) wifi:state: assoc -> run (10)
I (2350) wifi:connected with ChinaNet-903, aid = 4, channel 9, BW20, bssid = 40:f4:20:c2:75:0a
I (2350) wifi:security type: 4, phy: bgn, rssi: -30
I (2350) wifi:pm start, type: 1

I (2380) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (3170) event: sta ip: 192.168.1.8, mask: 255.255.255.0, gw: 192.168.1.1
I (3170) WIFI_SERV: Got ip:192.168.1.8
W (3170) WIFI_SERV: STATE type:2, pdata:0x0, len:0
I (3190) VOIP_EXAMPLE: PERIPH_WIFI_CONNECTED [323]
I (3190) VOIP_EXAMPLE: [ 5 ] Create SIP Service
I (3190) SIP: esp_sip ver : '1.0.1' Compile date: Apr 23 2021-15:40:57
W (3200) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (3210) SIP: Conecting...
W (3210) SIP: CHANGE STATE FROM 0, TO 1, :func: sip_connect:1667
I (3220) SIP: [1970-01-01/00:00:01]=======WRITE 0577 bytes>>
I (3220) SIP:

REGISTER sip:8002@192.168.1.5:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.8:10845;branch=z9hG4bK-1631001263;rport
From: <sip:8002@192.168.1.5:5060>;tag=-765542593
To: <sip:8002@192.168.1.5:5060>
Contact: <sip:8002@192.168.1.8:10845>
Max-Forwards: 70
Call-ID: F623AAED9EE7334E6C4E8DEB182B553091870A5E65F3
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 (3280) SIP: [1970-01-01/00:00:01]=======================>>
I (3310) SIP: [1970-01-01/00:00:01]<<=====READ 0525 bytes==
I (3310) SIP:

SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.8:10845;branch=z9hG4bK-1631001263;received=192.168.1.8;rport=10845
From: <sip:8002@192.168.1.5:5060>;tag=-765542593
To: <sip:8002@192.168.1.5:5060>;tag=7981093bef95c3e4
CSeq: 1 REGISTER
Call-ID: F623AAED9EE7334E6C4E8DEB182B553091870A5E65F3
Allow: ACK,BYE,CANCEL,INFO,INVITE,MESSAGE,NOTIFY,OPTIONS,PRACK,REFER,REGISTER,SUBSCRIBE
WWW-Authenticate: Digest realm="myvoipapp.com", nonce="62381249AAF1CC19B4F68B599C026635", algorithm=MD5, stale=true
Content-Length: 0


I (3360) SIP: [1970-01-01/00:00:01]<<======================
I (3360) SIP: Required authentication
I (3370) SIP: [1970-01-01/00:00:01]=======WRITE 0808 bytes>>
I (3370) SIP:

REGISTER sip:8002@192.168.1.5:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.8:10845;branch=z9hG4bK-26377405;rport
From: <sip:8002@192.168.1.5:5060>;tag=-1274745670
To: <sip:8002@192.168.1.5:5060>
Contact: <sip:8002@192.168.1.8:10845>
Max-Forwards: 70
Call-ID: F623AAED9EE7334E6C4E8DEB182B553091870A5E65F3
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="8002", realm="myvoipapp.com", nonce="62381249AAF1CC19B4F68B599C026635", uri="sip:192.168.1.5:5060", response="7e8111143508a53ad124e31c0bf535fe", algorithm=MD5, nc=00000001, cnonce="ffdf5de64f894d63"


I (3450) SIP: [1970-01-01/00:00:01]=======================>>
I (3460) SIP: [1970-01-01/00:00:01]<<=====READ 0524 bytes==
I (3460) SIP:

SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.8:10845;branch=z9hG4bK-26377405;received=192.168.1.8;rport=10845
From: <sip:8002@192.168.1.5:5060>;tag=-1274745670
To: <sip:8002@192.168.1.5:5060>;tag=6f2800526a8c5542
CSeq: 2 REGISTER
Call-ID: F623AAED9EE7334E6C4E8DEB182B553091870A5E65F3
Allow: ACK,BYE,CANCEL,INFO,INVITE,MESSAGE,NOTIFY,OPTIONS,PRACK,REFER,REGISTER,SUBSCRIBE
WWW-Authenticate: Digest realm="myvoipapp.com", nonce="B4802BDF7751AF9AD5EE51676D233B19", algorithm=MD5, stale=true
Content-Length: 0


I (3510) SIP: [1970-01-01/00:00:01]<<======================
I (3520) SIP: Required authentication
I (3520) SIP: [1970-01-01/00:00:01]=======WRITE 0807 bytes>>
I (3530) SIP:

REGISTER sip:8002@192.168.1.5:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.8:10845;branch=z9hG4bK-852528818;rport
From: <sip:8002@192.168.1.5:5060>;tag=392781939
To: <sip:8002@192.168.1.5:5060>
Contact: <sip:8002@192.168.1.8:10845>
Max-Forwards: 70
Call-ID: F623AAED9EE7334E6C4E8DEB182B553091870A5E65F3
CSeq: 3 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="8002", realm="myvoipapp.com", nonce="B4802BDF7751AF9AD5EE51676D233B19", uri="sip:192.168.1.5:5060", response="824bc681070d17cb426b8f6a638ab6ba", algorithm=MD5, nc=00000001, cnonce="e31b3860b30b7f18"


I (3600) SIP: [1970-01-01/00:00:01]=======================>>
I (3620) SIP: [1970-01-01/00:00:01]<<=====READ 0509 bytes==
I (3620) SIP:

SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.8:10845;branch=z9hG4bK-852528818;received=192.168.1.8;rport=10845
From: <sip:8002@192.168.1.5:5060>;tag=392781939
To: <sip:8002@192.168.1.5:5060>;tag=2ba355e8fbb069c3
CSeq: 3 REGISTER
Call-ID: F623AAED9EE7334E6C4E8DEB182B553091870A5E65F3
Allow: ACK,BYE,CANCEL,INFO,INVITE,MESSAGE,NOTIFY,OPTIONS,PRACK,REFER,REGISTER,SUBSCRIBE
Contact: "8002"<sip:8002@192.168.1.8:10845>
Server: miniSIPServer V38 (5 clients) build 20210923
Expires: 120
Content-Length: 0


I (3660) SIP: [1970-01-01/00:00:01]<<======================
I (3670) SIP: Expires = 120
I (3670) VOIP_EXAMPLE: SIP_EVENT_REGISTERED
I (3680) ESP_AUDIO_CTRL: Enter play procedure, src:0
I (3680) ESP_AUDIO_CTRL: Play procedure, URL is ok, src:0
I (3690) ESP_AUDIO_CTRL: Request_CMD_Queue CMD:0, Available:5, que:0x3ffb5654
I (3690) ESP_AUDIO_CTRL: Func:_ctrl_play, Line:771, MEM Total:4351824 Bytes, Inter:260912 Bytes, Dram:204536 Bytes

I (3710) ESP_AUDIO_TASK: It's a decoder
I (3710) ESP_AUDIO_TASK: 1.CUR IN:[IN_flash],CODEC:[DEC_mp3],RESAMPLE:[16000],OUT:[OUT_iis],rate:0,ch:0,pos:0
I (3720) AUDIO_ELEMENT: EL->multi_in.max_rb_num 1
I (3730) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (3730) ESP_AUDIO_TASK: 2.Handles,IN:0x3f805130,CODEC:0x3f8052c8,FILTER:0x3f806810,OUT:0x3f805458
I (3740) ESP_AUDIO_TASK: 2.2 Update all pipeline
I (3750) ESP_AUDIO_TASK: 2.3 Linked new pipeline
I (3750) AUDIO_PIPELINE: link el->rb, el:0x3f805130, tag:IN_flash, rb:0x3f808fac
I (3760) AUDIO_PIPELINE: link el->rb, el:0x3f8052c8, tag:DEC_mp3, rb:0x3f80b7ec
I (3770) AUDIO_PIPELINE: link el->rb, el:0x3f806810, tag:Audio_forge, rb:0x3f80d82c
I (3780) ESP_AUDIO_TASK: 3. Previous starting...
I (3780) AUDIO_ELEMENT: [IN_flash-0x3f805130] Element task created
I (3790) AUDIO_ELEMENT: [IN_flash] AEL_MSG_CMD_RESUME,state:1
I (3800) TONE_PARTITION: tone partition format 0, total 21
W (3800) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (3800) TONE_STREAM: Tone offset:00038c2c, Tone length:16344, pos:12

I (3810) AUDIO_ELEMENT: [DEC_mp3-0x3f8052c8] Element task created
I (3820) AUDIO_ELEMENT: [DEC_mp3] AEL_MSG_CMD_RESUME,state:1
I (3830) MP3_DECODER: MP3 opened
I (3830) ESP_AUDIO_TASK: Blocking play until received AEL_MSG_CMD_REPORT_MUSIC_INFO
I (3830) CODEC_ELEMENT_HELPER: The element is 0x3f8052c8. The reserve data 2 is 0x0.
I (3840) ESP_AUDIO_TASK: Recv Element[IN_flash-0x3f805130] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (3860) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f8052c8] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (3880) ESP_AUDIO_TASK: Received muisc info then on play
I (3880) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0
W (3890) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (3890) AUDIO_ELEMENT: [Audio_forge-0x3f806810] Element task created
I (3900) AUDIO_ELEMENT: [Audio_forge] AEL_MSG_CMD_RESUME,state:1
I (3910) AUDIO_FORGE: audio_forge opened
W (3910) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (3910) AUDIO_FORGE: audio_forge reopen
I (3920) AUDIO_ELEMENT: [OUT_iis-0x3f805458] Element task created
I (3930) AUDIO_ELEMENT: [OUT_iis] AEL_MSG_CMD_RESUME,state:1
I (3940) I2S_STREAM: AUDIO_STREAM_WRITER
I (3940) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f806810] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (3950) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f805458] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (3970) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_RUNNING, 0, src:0, is_stopping:0
I (3970) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:938, MEM Total:4253320 Bytes, Inter:242076 Bytes, Dram:185700 Bytes

I (3990) ESP_AUDIO_CTRL: Exit play procedure, ret:0
W (3990) SIP: CHANGE STATE FROM 1, TO 2, :func: sip_register:1695
W (4000) TONE_STREAM: No more data,ret:0 ,info.byte_pos:16344
I (4000) AUDIO_ELEMENT: IN-[IN_flash] AEL_IO_DONE,0
I (4010) ESP_AUDIO_TASK: Recv Element[IN_flash-0x3f805130] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (4920) AUDIO_ELEMENT: IN-[DEC_mp3] AEL_IO_DONE,-2
I (5180) MP3_DECODER: Closed
I (5180) ESP_AUDIO_TASK: Received last pos: 16344 bytes
I (5180) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f8052c8] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (5270) AUDIO_ELEMENT: IN-[Audio_forge] AEL_IO_DONE,-2
I (5270) AUDIO_FORGE: audio forge closed
I (5270) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f806810] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (5440) AUDIO_ELEMENT: IN-[OUT_iis] AEL_IO_DONE,-2
I (5550) ESP_AUDIO_TASK: Received last time: 1520 ms
I (5550) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f805458] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (5560) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_FINISHED, 0, src:0, is_stopping:0
I (5570) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:938, MEM Total:4300016 Bytes, Inter:242104 Bytes, Dram:185728 Bytes

W (5580) ESP_AUDIO_TASK: Destroy the old pipeline, FINISHED
W (5580) ESP_AUDIO_TASK: The old pipeline destroyed, FINISHED
I (8020) SIP: [1970-01-01/00:00:03]<<=====READ 0766 bytes==
I (8020) SIP:

INVITE sip:8002@192.168.1.8:10845 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.5;branch=z9hG4bKYXHe066e6c78a7d12e0;rport
Contact: <sip:8001@192.168.1.5>
Call-ID: f37dcb1bda048147bdd4229b99080dc2D20211013
To: <sip:8002@192.168.1.5>
From: <sip:8001@192.168.1.5>;tag=bdffa4abc99e187b
Max-Forwards: 70
Allow: ACK,BYE,CANCEL,INFO,INVITE,MESSAGE,NOTIFY,OPTIONS,PRACK,REFER,REGISTER,SUBSCRIBE
Supported: 100rel
User-Agent: miniSIPServer V38 (5 clients) build 20210923
CSeq: 1634106261 INVITE
Content-Type: application/sdp
Content-Length: 226

v=0
o=- 1634106261 1634106261 IN IP4 192.168.1.5
s=mss
c=IN IP4 192.168.1.5
t=0 0
m=audio 11002 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=fmtp:101 0-15
a=rtpmap:101 telephone-event/8000
a=sendrecv

I (8080) SIP: [1970-01-01/00:00:03]<<======================
I (8090) SIP: Remote RTP port=11002
I (8100) SIP: Remote RTP addr=192.168.1.5
I (8100) SIP: call from 8001
I (8100) SIP: [1970-01-01/00:00:03]=======WRITE 0400 bytes>>
I (8110) SIP:

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.5;branch=z9hG4bKYXHe066e6c78a7d12e0;rport
Contact: <sip:8002@192.168.1.8:10845>
From: <sip:8001@192.168.1.5>;tag=bdffa4abc99e187b
To: <sip:8002@192.168.1.5>;tag=-675042973
Call-ID: f37dcb1bda048147bdd4229b99080dc2D20211013
CSeq: 1634106261 INVITE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 0


I (8150) SIP: [1970-01-01/00:00:04]=======================>>
I (8160) SIP: [1970-01-01/00:00:04]=======WRITE 0400 bytes>>
I (8160) SIP:

SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.1.5;branch=z9hG4bKYXHe066e6c78a7d12e0;rport
Contact: <sip:8002@192.168.1.8:10845>
From: <sip:8001@192.168.1.5>;tag=bdffa4abc99e187b
To: <sip:8002@192.168.1.5>;tag=547509232
Call-ID: f37dcb1bda048147bdd4229b99080dc2D20211013
CSeq: 1634106261 INVITE
Server: ESP32 SIP/2.0
Allow: ACK, INVITE, BYE, UPDATE, CANCEL, OPTIONS, INFO
Content-Length: 0


I (8200) SIP: [1970-01-01/00:00:04]=======================>>
W (8210) SIP: CHANGE STATE FROM 2, TO 16, :func: _sip_uas_process_req_invite:817
I (9310) VOIP_EXAMPLE: ringing... RemotePhoneNum 8001
I (9310) ESP_AUDIO_CTRL: Enter play procedure, src:0
I (9310) ESP_AUDIO_CTRL: Play procedure, URL is ok, src:0
I (9310) ESP_AUDIO_CTRL: Request_CMD_Queue CMD:0, Available:5, que:0x3ffb5654
I (9320) ESP_AUDIO_CTRL: Func:_ctrl_play, Line:771, MEM Total:4321580 Bytes, Inter:258660 Bytes, Dram:202284 Bytes

I (9330) ESP_AUDIO_TASK: It's a decoder
I (9340) ESP_AUDIO_TASK: 1.CUR IN:[IN_flash],CODEC:[DEC_mp3],RESAMPLE:[16000],OUT:[OUT_iis],rate:0,ch:0,pos:0
I (9350) ESP_AUDIO_TASK: 2.Handles,IN:0x3f805130,CODEC:0x3f8052c8,FILTER:0x3f806810,OUT:0x3f805458
I (9360) AUDIO_PIPELINE: audio_pipeline_unlinked
W (9360) AUDIO_PIPELINE: There are no listener registered
I (9370) ESP_AUDIO_TASK: 2.2 Update all pipeline
I (9370) ESP_AUDIO_TASK: 2.3 Linked new pipeline
I (9380) AUDIO_PIPELINE: link el->rb, el:0x3f805130, tag:IN_flash, rb:0x3f80f954
I (9390) AUDIO_PIPELINE: link el->rb, el:0x3f8052c8, tag:DEC_mp3, rb:0x3f80f990
I (9390) AUDIO_PIPELINE: link el->rb, el:0x3f806810, tag:Audio_forge, rb:0x3f80f9cc
I (9400) ESP_AUDIO_TASK: 3. Previous starting...
I (9410) AUDIO_ELEMENT: [IN_flash-0x3f805130] Element task created
I (9410) AUDIO_ELEMENT: [IN_flash] AEL_MSG_CMD_RESUME,state:1
I (9420) TONE_PARTITION: tone partition format 0, total 21
W (9420) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (9430) TONE_STREAM: Tone offset:00020c78, Tone length:36018, pos:8

I (9430) AUDIO_ELEMENT: [DEC_mp3-0x3f8052c8] Element task created
I (9450) AUDIO_ELEMENT: [DEC_mp3] AEL_MSG_CMD_RESUME,state:1
I (9460) MP3_DECODER: MP3 opened
I (9460) ESP_AUDIO_TASK: Blocking play until received AEL_MSG_CMD_REPORT_MUSIC_INFO
I (9460) CODEC_ELEMENT_HELPER: The element is 0x3f8052c8. The reserve data 2 is 0x0.
I (9470) ESP_AUDIO_TASK: Recv Element[IN_flash-0x3f805130] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (9490) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f8052c8] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (9500) ESP_AUDIO_TASK: Received muisc info then on play
I (9500) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0
W (9510) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (9520) AUDIO_ELEMENT: [Audio_forge-0x3f806810] Element task created
I (9530) AUDIO_ELEMENT: [Audio_forge] AEL_MSG_CMD_RESUME,state:1
I (9530) AUDIO_FORGE: audio_forge opened
W (9530) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (9540) AUDIO_FORGE: audio_forge reopen
I (9550) AUDIO_ELEMENT: [OUT_iis-0x3f805458] Element task created
I (9560) AUDIO_ELEMENT: [OUT_iis] AEL_MSG_CMD_RESUME,state:1
I (9560) I2S_STREAM: AUDIO_STREAM_WRITER
I (9560) ESP_AUDIO_CTRL: Exit play procedure, ret:0
I (9560) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f806810] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (9580) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f805458] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (9600) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_RUNNING, 0, src:0, is_stopping:0
I (9600) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:938, MEM Total:4249200 Bytes, Inter:241184 Bytes, Dram:184808 Bytes

W (10290) ADC_BTN: Old ID:5, New ID:3
I (10370) VOIP_EXAMPLE: ringing... RemotePhoneNum 8001
I (10370) ESP_AUDIO_CTRL: Enter play procedure, src:0
W (10370) ESP_AUDIO_CTRL: Pipeline is already running. Please stop it first.
I (10540) VOIP_EXAMPLE: [ * ] [Play] input key event
I (10540) ESP_AUDIO_CTRL: Enter media_ctrl_stop procedure, src:0, type:0, st:RUNNING, phase:4
I (10540) ESP_AUDIO_CTRL: media_ctrl_stop, type:0, st:RUNNING, block_playing:1, MEDIA_CTRL_PHASE_WAIT_RUNNING
I (10550) ESP_AUDIO_CTRL: media_ctrl_stop, src:0, type:0, st:RUNNING, phase:4
I (10560) ESP_AUDIO_CTRL: Request_CMD_Queue CMD:2, Available:5, que:0x3ffb5654
I (10570) ESP_AUDIO_TASK: MEDIA_CTRL_EVT_STOP, status:RUNNING
W (10570) AUDIO_ELEMENT: OUT-[IN_flash] AEL_IO_ABORT
W (10570) AUDIO_ELEMENT: OUT-[DEC_mp3] AEL_IO_ABORT
W (10580) MP3_DECODER: output aborted -3
I (10590) MP3_DECODER: Closed
W (10590) AUDIO_ELEMENT: OUT-[Audio_forge] AEL_IO_ABORT
W (10600) AUDIO_ELEMENT: OUT-[Audio_forge] AEL_IO_ABORT
I (10600) AUDIO_FORGE: audio forge closed
I (10630) ESP_AUDIO_TASK: MEDIA_CTRL_EVT_STOP Done, dat:0
I (10630) ESP_AUDIO_TASK: Received last pos: 15877 bytes
I (10630) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f8052c8] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_STOPPED
I (10640) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f806810] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_STOPPED
I (10660) ESP_AUDIO_TASK: Recv Element[IN_flash-0x3f805130] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_STOPPED
I (10670) ESP_AUDIO_TASK: Received last time: 1056 ms
I (10670) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f805458] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_STOPPED
I (10680) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_STOPPED, 0, src:0, is_stopping:1
I (10690) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:938, MEM Total:4299076 Bytes, Inter:241272 Bytes, Dram:184896 Bytes

W (10710) ESP_AUDIO_TASK: Destroy the old pipeline, STOPPED
W (10710) ESP_AUDIO_TASK: The old pipeline destroyed, STOPPED
I (10720) ESP_AUDIO_CTRL: Exit media_ctrl_stop procedure, ret:0
I (10720) ESP_AUDIO_TASK: Recv Element[IN_flash-0x3f805130] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_STOPPED
I (10780) SIP: [1970-01-01/00:00:05]=======WRITE 0585 bytes>>
I (10780) SIP:

SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.5;branch=z9hG4bKYXHe066e6c78a7d12e0;rport
Contact: <sip:8002@192.168.1.8:10845>
From: <sip:8001@192.168.1.5>;tag=bdffa4abc99e187b
To: <sip:8002@192.168.1.5>;tag=-1798470490
Call-ID: f37dcb1bda048147bdd4229b99080dc2D20211013
CSeq: 1634106261 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.1.8
s=Z
c=IN IP4 192.168.1.8
t=0 0
m=audio 31413 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000


I (10830) SIP: [1970-01-01/00:00:05]=======================>>
I (10840) SIP: [1970-01-01/00:00:05]<<=====READ 0318 bytes==
I (10840) SIP:

ACK sip:8002@192.168.1.8:10845 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.5;branch=z9hG4bKYXH61892ea15eb4a14f;rport
To: <sip:8002@192.168.1.5>;tag=-1798470490
From: <sip:8001@192.168.1.5>;tag=bdffa4abc99e187b
Call-ID: f37dcb1bda048147bdd4229b99080dc2D20211013
CSeq: 1634106261 ACK
Max-Forwards: 70
Content-Length: 0


I (10870) SIP: [1970-01-01/00:00:05]<<======================
W (10880) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
W (10890) SIP: CHANGE STATE FROM 16, TO 32, :func: sip_uas_process_req:886
I (10890) VOIP_EXAMPLE: SIP_EVENT_AUDIO_SESSION_BEGIN
I (10900) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (10900) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (10910) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (10920) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (10920) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (10930) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
W (10930) I2S: I2S driver already installed
I (10940) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (10940) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (10950) LYRAT_MINI_V1_1: I2S0, MCLK output by GPIO0
I (10950) AUDIO_PIPELINE: link el->rb, el:0x3f80fd40, tag:raw, rb:0x3f81032c
I (10960) AUDIO_PIPELINE: link el->rb, el:0x3f80fe68, tag:sip_dec, rb:0x3f81236c
I (10970) AUDIO_PIPELINE: link el->rb, el:0x3f8100f0, tag:filter, rb:0x3f812fac
I (10980) AUDIO_ELEMENT: [raw-0x3f80fd40] Element task created
W (10980) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (10990) AUDIO_ELEMENT: [sip_dec-0x3f80fe68] Element task created
W (11000) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (11010) AUDIO_ELEMENT: [filter-0x3f8100f0] Element task created
I (11010) AUDIO_ELEMENT: [i2s-0x3f8101cc] Element task created
I (11020) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:4282128 Bytes, Inter:237236 Bytes, Dram:180860 Bytes

I (11030) AUDIO_ELEMENT: [sip_dec] AEL_MSG_CMD_RESUME,state:1
I (11040) AUDIO_ELEMENT: [filter] AEL_MSG_CMD_RESUME,state:1
I (11050) CODEC_ELEMENT_HELPER: The element is 0x3f80fe68. The reserve data 2 is 0x0.
I (11050) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:1
I (11060) I2S_STREAM: AUDIO_STREAM_WRITER
I (11060) AUDIO_PIPELINE: Pipeline started
I (11070) VOIP_EXAMPLE: SIP player has been created
I (11080) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (11080) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (11090) I2S: APLL: Req RATE: 16000, real rate: 15999.986, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 4095996.500, SCLK: 511999.562500, diva: 1, divb: 0
I (11100) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (11110) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (11110) LYRAT_MINI_V1_1: I2S1, MCLK output by GPIO0
I (11120) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (11130) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
E (11130) ALGORITHM_STREAM: data_need_be_resampled 0
E (11140) ALGORITHM_STREAM: data_need_be_resampled 0
I (11140) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (11150) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (11150) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (11160) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
I (11160) AUDIO_ELEMENT: EL->multi_in.max_rb_num 0
I (11170) AUDIO_ELEMENT: EL->multi_out.max_rb_num 0
E (11180) ALGORITHM_STREAM: reset channel number of record signal : 2, sample rate of record signal: 16000
I (11190) AUDIO_PIPELINE: link el->rb, el:0x3f814254, tag:i2s, rb:0x3f81555c
I (11190) AUDIO_PIPELINE: link el->rb, el:0x3f81442c, tag:algo, rb:0x3f81759c
I (11200) AUDIO_PIPELINE: link el->rb, el:0x3f815174, tag:filter, rb:0x3f8195dc
I (11210) AUDIO_PIPELINE: link el->rb, el:0x3f8152a4, tag:sip_enc, rb:0x3f819618
I (11220) AUDIO_ELEMENT: [i2s-0x3f814254] Element task created
W (11220) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (11230) AUDIO_ELEMENT: [filter-0x3f815174] Element task created
W (11240) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (11250) AUDIO_ELEMENT: [sip_enc-0x3f8152a4] Element task created
I (11250) AUDIO_ELEMENT: [raw-0x3f8153cc] Element task created
I (11260) AUDIO_ELEMENT: [algo-0x3f81442c] Element task created
I (11270) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:4229284 Bytes, Inter:206888 Bytes, Dram:150512 Bytes

I (11280) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:1
I (11290) I2S_STREAM: AUDIO_STREAM_READER,Rate:16000,ch:2
I (11280) RSP_FILTER: sample rate of source data : 8000, channel of source data : 1, sample rate of destination data : 16000, channel of destination data : 2
I (11290) I2S: APLL: Req RATE: 16000, real rate: 15999.986, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 4095996.500, SCLK: 511999.562500, diva: 1, divb: 0
I (11290) AUDIO_ELEMENT: [filter] AEL_MSG_CMD_RESUME,state:1
I (11330) RSP_FILTER: sample rate of source data : 16000, channel of source data : 1, sample rate of destination data : 8000, channel of destination data : 1
I (11340) AUDIO_ELEMENT: [sip_enc] AEL_MSG_CMD_RESUME,state:1
I (11350) AUDIO_ELEMENT: [algo] AEL_MSG_CMD_RESUME,state:1
I (11350) AUDIO_PIPELINE: Pipeline started
I (11360) VOIP_EXAMPLE: SIP recorder has been created
W (11360) AUIDO_MEM: Can't support stack on external memory due to ESP32 chip is 1
I (11370) SIP_RTP: receive task, local addr=192.168.1.8:31413
:1100280) SIP_RTP: send task, remote addr=192.168.1.5
E (11400) ALGORITHM_STREAM: algo->record.is_after_reset_res_info 1
E (11400) ALGORITHM_STREAM: algo->reference.is_after_reset_res_info 1
E (11400) ALGORITHM_STREAM: data_need_be_resampled 0
E (11410) ALGORITHM_STREAM: data_need_be_resampled 0
W (25050) ADC_BTN: Old ID:5, New ID:4
I (25250) SIP: User call sip BYE
I (25290) SIP: [1970-01-01/00:00:12]=======WRITE 0621 bytes>>
I (25290) SIP:

BYE sip:8001@192.168.1.5:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.5;branch=z9hG4bKYXH61892ea15eb4a14f;rport
From: <sip:8002@192.168.1.5>;tag=-1798470490
To: <sip:8001@192.168.1.5>;tag=bdffa4abc99e187b
Contact: <sip:8002@192.168.1.8:10845>
Max-Forwards: 70
Call-ID: f37dcb1bda048147bdd4229b99080dc2D20211013
CSeq: 4 BYE
Expires: 3600
User-Agent: ESP32 SIP/2.0
Content-Length: 0
Authorization: Digest username="8002", realm="myvoipapp.com", nonce="B4802BDF7751AF9AD5EE51676D233B19", uri="sip:192.168.1.5:5060", response="77b7123133c0d9fe2d1842ab9d8bec5f", algorithm=MD5, nc=00000002, cnonce="6737865a5797117d"


I (25340) SIP: [1970-01-01/00:00:12]=======================>>
I (25350) SIP: [1970-01-01/00:00:12]<<=====READ 0421 bytes==
I (25350) SIP:

SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.5:5060;branch=z9hG4bKYXH61892ea15eb4a14f;received=192.168.1.8;rport=10845
From: <sip:8002@192.168.1.5>;tag=-1798470490
To: <sip:8001@192.168.1.5>;tag=bdffa4abc99e187b
CSeq: 4 BYE
Call-ID: f37dcb1bda048147bdd4229b99080dc2D20211013
Allow: ACK,BYE,CANCEL,INFO,INVITE,MESSAGE,NOTIFY,OPTIONS,PRACK,REFER,REGISTER,SUBSCRIBE
Contact: <sip:8001@192.168.1.5>
Content-Length: 0


I (25390) SIP: [1970-01-01/00:00:12]<<======================
W (25400) SIP: CHANGE STATE FROM 32, TO 2, :func: _sip_request_bye:1408
I (25410) SIP_RTP: send task stopped
I (25410) VOIP_EXAMPLE: SIP_EVENT_AUDIO_SESSION_END
W (25480) AUDIO_PIPELINE: There are no listener registered
I (25480) AUDIO_PIPELINE: audio_pipeline_unlinked
W (25480) AUDIO_ELEMENT: [raw] Element has not create when AUDIO_ELEMENT_TERMINATE
W (25490) AUDIO_ELEMENT: [sip_dec] Element has not create when AUDIO_ELEMENT_TERMINATE
W (25500) AUDIO_ELEMENT: [filter] Element has not create when AUDIO_ELEMENT_TERMINATE
W (25510) AUDIO_ELEMENT: [i2s] Element has not create when AUDIO_ELEMENT_TERMINATE
W (25520) AUDIO_ELEMENT: IN-[algo] AEL_IO_ABORT
W (25520) AUDIO_ELEMENT: IN-[filter] AEL_IO_ABORT
W (25530) AUDIO_ELEMENT: IN-[sip_enc] AEL_IO_ABORT
W (25530) AUDIO_PIPELINE: There are no listener registered
I (25540) AUDIO_PIPELINE: audio_pipeline_unlinked
W (25540) AUDIO_ELEMENT: [i2s] Element has not create when AUDIO_ELEMENT_TERMINATE
W (25550) AUDIO_ELEMENT: [filter] Element has not create when AUDIO_ELEMENT_TERMINATE
W (25560) AUDIO_ELEMENT: [sip_enc] Element has not create when AUDIO_ELEMENT_TERMINATE
W (25570) AUDIO_ELEMENT: [raw] Element has not create when AUDIO_ELEMENT_TERMINATE
W (25580) AUDIO_ELEMENT: [algo] Element has not create when AUDIO_ELEMENT_TERMINATE
I (25590) SIP_RTP: receive task stopped
I (25590) SIP_RTP: RTP stopped
I (25590) VOIP_EXAMPLE: SIP_EVENT_HANGUP