search

espressif / esp-adf

Espressif Audio Development Framework
Other
1.53k stars 671 forks source link

http stream connection resets , no reconnection (AUD-3710) #787

Closed arsz6733 closed 2 years ago

arsz6733 commented 2 years ago

Environment

Problem Description

Server resets the http stream connection - app doesn't reconnect //Detailed problem description goes here. I've been using cli example to test http_stream. I have faced an issue for a mp3 file in which connection gets closed after 2:30 minutes.

There are 2 problems here:

1- why does connection with this specific link get closed after 2:30 minutes: I don't have any problem with the link in the http_stream example. Here is the link of file which I have problem with (http://sitopet.com/app/file/cat/music/alone-in-home/track1.mp3) I have tried to change these configs but nothing has changed. .timeout_ms in http_stream.c from 30 seconds to 60 seconds HTTP_STREAM_BUFFER_SIZE in http_stream.c from 2048 to 4096 HTTP_STREAM_RINGBUFFER_SIZE in http_stream.h from 20 1024 to 120 1024 HTTP_STREAM_TASK_CORE in http_stream.h from 0 to 1

2- why doesn't the connection reconnect after getting closed?

Steps to reproduce

  1. build and run cli example ( I have removed sd card parts in this example since it's a custom board)
  2. join wifi connection
  3. play http://sitopet.com/app/file/cat/music/alone-in-home/track1.mp3

Debug Logs

(46016) CONSOLE_EXAMPLE: app_audio playat/music/alone-in-home/track1.mp3
I (46016) CONSOLE_EXAMPLE: play index= -1, URI:http://sitopet.com/app/file/cat/music/alone-in-home/track1.mp3, byte_pos:0
I (46036) ESP_AUDIO_CTRL: Enter play procedure, src:0
I (46036) ESP_AUDIO_CTRL: Play procedure, URL is ok, src:0
I (46046) ESP_AUDIO_CTRL: Request_CMD_Queue CMD:0, Available:5, que:0x3ffe1a50
I (46046) ESP_AUDIO_TASK: It's a decoder
I (46046) ESP_AUDIO_CTRL: Func:_ctrl_play, Line:771, MEM Total:4264971 Bytes, Inter:127247 Bytes, Dram:110291 Bytes

I (46056) ESP_AUDIO_TASK: 1.CUR IN:[IN_http],CODEC:[DEC_mp3],RESAMPLE:[48000],OUT:[OUT_iis],rate:0,ch:0,pos:0
I (46076) ESP_AUDIO_TASK: 2.Handles,IN:0x3f8011c4,CODEC:0x3f801990,FILTER:0x3f8027e4,OUT:0x3f80232c
W (46086) AUDIO_PIPELINE: Without stop, st:1
W (46086) AUDIO_PIPELINE: Without wait stop, st:1
I (46096) AUDIO_PIPELINE: audio_pipeline_unlinked
W (46096) AUDIO_PIPELINE: There are no listener registered
I (46116) ESP_AUDIO_TASK: 2.2 Update all pipeline
I (46116) ESP_AUDIO_TASK: 2.3 Linked new pipeline
I (46126) AUDIO_PIPELINE: link el->rb, el:0x3f8011c4, tag:IN_http, rb:0x3f809914
I (46126) AUDIO_PIPELINE: link el->rb, el:0x3f801990, tag:DEC_mp3, rb:0x3f809950
I (46136) AUDIO_PIPELINE: link el->rb, el:0x3f8027e4, tag:Audio_forge, rb:0x3f80998c
I (46146) ESP_AUDIO_TASK: 3. Previous starting...
I (46146) AUDIO_ELEMENT: [IN_http-0x3f8011c4] Element task created
I (46156) AUDIO_ELEMENT: [IN_http] AEL_MSG_CMD_RESUME,state:1
I (46156) AUDIO_ELEMENT: [DEC_mp3-0x3f801990] Element task created
I (46176) AUDIO_ELEMENT: [DEC_mp3] AEL_MSG_CMD_RESUME,state:1
I (46176) MP3_DECODER: MP3 opened
I (46176) ESP_AUDIO_TASK: Blocking play until received AEL_MSG_CMD_REPORT_MUSIC_INFO
I (46596) HTTP_STREAM: total_bytes=9730114
I (46606) ESP_AUDIO_TASK: Recv Element[IN_http-0x3f8011c4] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (46646) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f801990] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (46656) ESP_AUDIO_TASK: Received muisc info then on play
I (46666) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0
I (46666) AUDIO_ELEMENT: [Audio_forge-0x3f8027e4] Element task created
I (46686) AUDIO_ELEMENT: [Audio_forge] AEL_MSG_CMD_RESUME,state:1
I (46686) AUDIO_FORGE: audio_forge opened
I (46686) AUDIO_ELEMENT: [OUT_iis-0x3f80232c] Element task created
I (46686) AUDIO_FORGE: audio_forge reopen
I (46696) AUDIO_ELEMENT: [OUT_iis] AEL_MSG_CMD_RESUME,state:1
I (46716) I2S_STREAM: AUDIO_STREAM_WRITER
I (46716) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f8027e4] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNINGI (46716) ESP_AUDIO_CTRL: Exit play procedure, ret:0

esp32> I (46736) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f80232c] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (46746) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_RUNNING, 0, src:0, is_stopping:0
I (46746) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:984, MEM Total:4175707 Bytes, Inter:100575 Bytes, Dram:83619 Bytes

I (46786) CONSOLE_EXAMPLE: esp_auido status:1,err:0

E (204106) TRANSPORT_BASE: poll_read select error 104, errno = Connection reset by peer, fd = 54
W (204116) HTTP_STREAM: No more data,errno:0, total_bytes:1906688, rlen = -1
I (204116) AUDIO_ELEMENT: IN-[IN_http] AEL_IO_DONE,0
I (204126) ESP_AUDIO_TASK: Recv Element[IN_http-0x3f8011c4] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (204966) AUDIO_ELEMENT: IN-[DEC_mp3] AEL_IO_DONE,-2
I (205136) MP3_DECODER: Closed
I (205136) ESP_AUDIO_TASK: Received last pos: 1900223 bytes
I (205146) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f801990] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (205246) AUDIO_ELEMENT: IN-[Audio_forge] AEL_IO_DONE,-2
I (205246) AUDIO_FORGE: audio forge closed
I (205246) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f8027e4] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (205286) AUDIO_ELEMENT: IN-[OUT_iis] AEL_IO_DONE,-2
I (205326) ESP_AUDIO_TASK: Received last time: 158586 ms
I (205326) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f80232c] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (205336) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_FINISHED, 0, src:0, is_stopping:0
I (205346) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:984, MEM Total:4241739 Bytes, Inter:106751 Bytes, Dram:89795 Bytes

W (205356) ESP_AUDIO_TASK: Destroy the old pipeline, FINISHED
W (205366) ESP_AUDIO_TASK: The old pipeline destroyed, FINISHED
I (205366) CONSOLE_EXAMPLE: esp_auido status:4,err:0

I (205376) ESP_AUDIO_CTRL: Total:1900223, get duration:158351 ms by bps:96000
I (205376) CONSOLE_EXAMPLE: [ * ] End of time:158586 ms, duration:158351 ms
I (205386) CONSOLE_EXAMPLE: Func:esp_audio_state_task, Line:529, MEM Total:4264907 Bytes, Inter:127247 Bytes, Dram:110291 Bytes
arsz6733 commented 2 years ago

more logs with more depth 

I (26815) AUDIO_ELEMENT: [DEC_mp3-0x3f80f770] Element task created
D (26815) HTTP_STREAM: _http_open
I (26825) AUDIO_ELEMENT: [DEC_mp3] AEL_MSG_CMD_RESUME,state:1
D (26825) HTTP_STREAM: URI=http://sitopet.com/app/file/cat/music/alone-in-home/track1.mp3
I (26835) ESP_AUDIO_TASK: Blocking play until received AEL_MSG_CMD_REPORT_MUSIC_INFO
I (26835) MP3_DECODER: MP3 opened
D (26845) HTTP_CLIENT: Begin connect to: http://sitopet.com:80
D (26865) esp-tls: host:sitopet.com: strlen 11
D (26865) esp-tls: [sock=55] Resolved IPv4 address: 160.153.131.155
D (26875) esp-tls: [sock=55] Connecting to server. HOST: sitopet.com, Port: 80
D (27245) HTTP_CLIENT: Write header[3]: GET /app/file/cat/music/alone-in-home/track1.mp3 HTTP/1.1
User-Agent: ESP32 HTTP Client/1.0
Host: sitopet.com
Content-Length: 0

D (27655) HTTP_CLIENT: on_message_begin
D (27655) HTTP_CLIENT: HEADER=Date:Fri, 18 Mar 2022 21:00:17 GMT
D (27655) HTTP_CLIENT: HEADER=Server:Apache
D (27665) HTTP_CLIENT: HEADER=Upgrade:h2,h2c
D (27665) HTTP_CLIENT: HEADER=Connection:Upgrade
D (27665) HTTP_CLIENT: HEADER=Last-Modified:Wed, 28 Jul 2021 21:59:04 GMT
D (27675) HTTP_CLIENT: HEADER=ETag:"35a0085-947842-5c836183e949a"
D (27685) HTTP_CLIENT: HEADER=Accept-Ranges:bytes
D (27695) HTTP_CLIENT: HEADER=Content-Length:9730114
D (27695) HTTP_CLIENT: HEADER=Vary:Accept-Encoding
D (27705) HTTP_CLIENT: HEADER=Content-Type:audio/mpeg
D (27705) HTTP_STREAM: Content-Type = audio/mpeg
D (27705) HTTP_CLIENT: http_on_headers_complete, status=200, offset=290, nread=290
D (27715) HTTP_CLIENT: http_on_body 3806
D (27715) HTTP_CLIENT: content_length = 9730114
I (27725) HTTP_STREAM: total_bytes=9730114
D (27725) HTTP_STREAM: req lengh=1024, read=1024, pos=0/9730114
I (27725) ESP_AUDIO_TASK: Recv Element[IN_http-0x3f80f608] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNINGD (27735) HTTP_STREAM: req lengh=1024, read=1024, pos=1024/9730114

D (27755) HTTP_STREAM: req lengh=1024, read=1024, pos=2048/9730114
D (27765) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (27765) HTTP_CLIENT: need_read=290, byte_to_read=290, rlen=290, ridx=734
D (27775) HTTP_CLIENT: http_on_body 290
D (27775) HTTP_STREAM: req lengh=1024, read=1024, pos=3072/9730114
D (27785) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (27795) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (27805) HTTP_CLIENT: http_on_body 1024
D (27805) HTTP_STREAM: req lengh=1024, read=1024, pos=4096/9730114
D (27815) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (27815) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (27825) HTTP_CLIENT: http_on_body 1024
D (27825) HTTP_STREAM: req lengh=1024, read=1024, pos=5120/9730114
D (27835) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (27835) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (27855) HTTP_CLIENT: http_on_body 1024
D (27855) HTTP_STREAM: req lengh=1024, read=1024, pos=6144/9730114
D (27855) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (27865) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (27875) HTTP_CLIENT: http_on_body 1024
D (27875) HTTP_STREAM: req lengh=1024, read=1024, pos=7168/9730114
D (27875) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (27895) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (27895) HTTP_CLIENT: http_on_body 1024
D (27905) HTTP_STREAM: req lengh=1024, read=1024, pos=8192/9730114
D (27905) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
I (27905) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f80f770] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNINGD (27915) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0

D (27925) HTTP_CLIENT: http_on_body 1024
I (27925) ESP_AUDIO_TASK: Received muisc info then on play
D (27935) HTTP_STREAM: req lengh=1024, read=1024, pos=9216/9730114
I (27945) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0
D (27955) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
I (27955) AUDIO_ELEMENT: [Audio_forge-0x3f8100ac] Element task created
D (27965) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
I (27965) AUDIO_ELEMENT: [Audio_forge] AEL_MSG_CMD_RESUME,state:1
I (27975) AUDIO_FORGE: audio_forge opened
I (27975) AUDIO_ELEMENT: [OUT_iis-0x3f80f918] Element task created
I (27995) AUDIO_FORGE: audio_forge reopen
I (27995) AUDIO_ELEMENT: [OUT_iis] AEL_MSG_CMD_RESUME,state:1
I (28005) I2S_STREAM: AUDIO_STREAM_WRITER
I (28005) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f8100ac] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNINGD (27975) HTTP_CLIENT: http_on_body 1024

D (28025) HTTP_STREAM: req lengh=1024, read=1024, pos=10240/9730114
I (28025) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f80f918] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
D (28025) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
I (28045) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_RUNNING, 0, src:0, is_stopping:0
D (28055) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (28065) HTTP_CLIENT: http_on_body 1024l_task, Line:984, MEM Total:4133379 Bytes, Inter:119347 Bytes, Dram:101863 Bytes

I (28085) ESP_AUDIO_CTRL: Exit play procedure, ret:0
I (28085) CONSOLE_EXAMPLE: esp_auido status:1,err:0

D (28085) HTTP_STREAM: req lengh=1024, read=1024, pos=11264/9730114
D (28105) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (28115) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (28115) HTTP_CLIENT: http_on_body 1024
D (28115) HTTP_STREAM: req lengh=1024, read=1024, pos=12288/9730114
D (28125) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114

...

D (184645) HTTP_CLIENT: http_on_body 1024
D (184655) HTTP_STREAM: req lengh=1024, read=1024, pos=1897472/9730114
D (184725) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (184725) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (184735) HTTP_CLIENT: http_on_body 1024
D (184735) HTTP_STREAM: req lengh=1024, read=1024, pos=1898496/9730114
D (184835) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (184835) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (184835) HTTP_CLIENT: http_on_body 1024
D (184845) HTTP_STREAM: req lengh=1024, read=1024, pos=1899520/9730114
D (184905) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
E (184905) TRANSPORT_BASE: poll_read select error 104, errno = Connection reset by peer, fd = 55
D (184915) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=-1, ridx=0
D (184925) HTTP_CLIENT: Data processed 1900544 != Data specified in content length 9730114
W (184935) HTTP_STREAM: No more data,errno:0, total_bytes:1900544, rlen = -1
D (184945) HTTP_STREAM: Direct URI. Stream will be stopped
I (184945) AUDIO_ELEMENT: IN-[IN_http] AEL_IO_DONE,0
D (184955) HTTP_STREAM: _http_close
I (184955) ESP_AUDIO_TASK: Recv Element[IN_http-0x3f80f608] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (185765) AUDIO_ELEMENT: IN-[DEC_mp3] AEL_IO_DONE,-2
I (185915) MP3_DECODER: Closed
I (185915) ESP_AUDIO_TASK: Received last pos: 1893963 bytes
I (185915) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f80f770] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (186015) AUDIO_ELEMENT: IN-[Audio_forge] AEL_IO_DONE,-2
I (186015) AUDIO_FORGE: audio forge closed
I (186015) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f8100ac] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (186065) AUDIO_ELEMENT: IN-[OUT_iis] AEL_IO_DONE,-2
I (186105) ESP_AUDIO_TASK: Received last time: 158064 ms
I (186105) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f80f918] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (186115) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_FINISHED, 0, src:0, is_stopping:0
I (186125) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:984, MEM Total:4202475 Bytes, Inter:125183 Bytes, Dram:107699 Bytes

W (186145) ESP_AUDIO_TASK: Destroy the old pipeline, FINISHED
W (186145) ESP_AUDIO_TASK: The old pipeline destroyed, FINISHED
I (186155) CONSOLE_EXAMPLE: esp_auido status:4,err:0

I (186155) ESP_AUDIO_CTRL: Total:1893963, get duration:157830 ms by bps:96000
I (186165) CONSOLE_EXAMPLE: [ * ] End of time:158064 ms, duration:157830 ms
I (186175) CONSOLE_EXAMPLE: Func:esp_audio_state_task, Line:595, MEM Total:4225635 Bytes, Inter:145611 Bytes, Dram:128127 Bytes

D (209105) TRANSPORT_BASE: remain data in cache, need to read again
D (269315) TRANSPORT_BASE: remain data in cache, need to read again
D (329535) TRANSPORT_BASE: remain data in cache, need to read again
D (389735) TRANSPORT_BASE: remain data in cache, need to read again
D (449945) TRANSPORT_BASE: remain data in cache, need to read again
arsz6733 commented 2 years ago

I changed the DEFAULT_ELEMENT_BUFFER_LENGTH to 4*1024 ! now it tries to get http data on 4096 bytes buffer. still has the problem but it has shown new behavior. I don't know whether it is directly related or no

Here is the log

D (168025) HTTP_CLIENT: http_on_body 4096
D (168035) HTTP_STREAM: req lengh=4096, read=4096, pos=1908736/9730114
D (168355) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (168355) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=4096, ridx=0
D (168355) HTTP_CLIENT: http_on_body 4096
D (168365) HTTP_STREAM: req lengh=4096, read=4096, pos=1912832/9730114
D (168695) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (168695) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=4096, ridx=0
D (168695) HTTP_CLIENT: http_on_body 4096
D (168715) HTTP_STREAM: req lengh=4096, read=4096, pos=1916928/9730114
D (169035) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (169035) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=4096, ridx=0
D (169035) HTTP_CLIENT: http_on_body 4096
D (169045) HTTP_STREAM: req lengh=4096, read=4096, pos=1921024/9730114
D (169375) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (169375) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=3658, ridx=0
D (169375) HTTP_CLIENT: http_on_body 3658
D (169395) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
D (169395) HTTP_CLIENT: need_read=438, byte_to_read=438, rlen=-1, ridx=3658
W (169405) HTTP_CLIENT: esp_transport_read returned:-1 and errno:128
D (169405) HTTP_STREAM: req lengh=4096, read=3658, pos=1925120/9730114
D (169415) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=9730114
E (169425) TRANSPORT_BASE: tcp_read error, errno=Socket is not connected
D (169425) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=-1, ridx=0
W (169445) HTTP_CLIENT: esp_transport_read returned:-1 and errno:128
D (169445) HTTP_CLIENT: Data processed 1928778 != Data specified in content length 9730114
W (169455) HTTP_STREAM: No more data,errno:128, total_bytes:1928778, rlen = -1
W (169465) HTTP_STREAM: Got 128 errno, reconnect to peer
D (169465) HTTP_STREAM: _http_close
D (169465) HTTP_STREAM: _http_open
D (169475) HTTP_STREAM: URI=http://sitopet.com/app/file/cat/music/alone-in-home/track1.mp3
D (169485) HTTP_CLIENT: Begin connect to: http://sitopet.com:80
D (169495) esp-tls: host:sitopet.com: strlen 11
D (169495) esp-tls: [sock=55] Resolved IPv4 address: 160.153.131.155
D (169495) esp-tls: [sock=55] Connecting to server. HOST: sitopet.com, Port: 80
D (169845) HTTP_CLIENT: Write header[4]: GET /app/file/cat/music/alone-in-home/track1.mp3 HTTP/1.1
User-Agent: ESP32 HTTP Client/1.0
Host: sitopet.com
Range: bytes=1928778-
Content-Length: 0

D (170075) HTTP_CLIENT: on_message_begin
D (170075) HTTP_CLIENT: HEADER=Date:Fri, 18 Mar 2022 21:30:41 GMT
D (170075) HTTP_CLIENT: HEADER=Server:Apache
D (170085) HTTP_CLIENT: HEADER=Upgrade:h2,h2c
D (170085) HTTP_CLIENT: HEADER=Connection:Upgrade
D (170085) HTTP_CLIENT: HEADER=Last-Modified:Wed, 28 Jul 2021 21:59:04 GMT
D (170095) HTTP_CLIENT: HEADER=ETag:"35a0085-947842-5c836183e949a"
D (170105) HTTP_CLIENT: HEADER=Accept-Ranges:bytes
D (170115) HTTP_CLIENT: HEADER=Content-Length:7801336
D (170115) HTTP_CLIENT: HEADER=Vary:Accept-Encoding
D (170125) HTTP_CLIENT: HEADER=Content-Range:bytes 1928778-9730113/9730114
D (170125) HTTP_CLIENT: HEADER=Content-Type:audio/mpeg
D (170135) HTTP_STREAM: Content-Type = audio/mpeg
D (170135) HTTP_CLIENT: http_on_headers_complete, status=206, offset=349, nread=349
D (170145) HTTP_CLIENT: http_on_body 3747
D (170145) HTTP_CLIENT: content_length = 7801336
I (170145) HTTP_STREAM: total_bytes=9730114
D (170165) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (170165) HTTP_CLIENT: need_read=349, byte_to_read=349, rlen=349, ridx=3747
D (170175) HTTP_CLIENT: http_on_body 349
D (170175) HTTP_STREAM: req lengh=4096, read=4096, pos=1928778/9730114
D (170185) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (170185) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1299, ridx=0
D (170195) HTTP_CLIENT: http_on_body 1299
D (170205) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (174355) HTTP_CLIENT: need_read=2797, byte_to_read=2797, rlen=1106, ridx=1299
D (174355) HTTP_CLIENT: http_on_body 1106
D (174355) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (175375) HTTP_CLIENT: need_read=1691, byte_to_read=1691, rlen=1370, ridx=2405
D (175375) HTTP_CLIENT: http_on_body 1370
D (175375) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (176405) HTTP_CLIENT: need_read=321, byte_to_read=321, rlen=321, ridx=3775
D (176405) HTTP_CLIENT: http_on_body 321
D (176405) HTTP_STREAM: req lengh=4096, read=4096, pos=1932874/9730114
D (176415) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (176425) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1049, ridx=0
D (176425) HTTP_CLIENT: http_on_body 1049
D (176425) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (177445) HTTP_CLIENT: need_read=3047, byte_to_read=3047, rlen=1370, ridx=1049
D (177445) HTTP_CLIENT: http_on_body 1370
D (177445) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (178445) HTTP_CLIENT: need_read=1677, byte_to_read=1677, rlen=1370, ridx=2419
D (178455) HTTP_CLIENT: http_on_body 1370
D (178455) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (179475) HTTP_CLIENT: need_read=307, byte_to_read=307, rlen=307, ridx=3789
D (179475) HTTP_CLIENT: http_on_body 307
D (179475) HTTP_STREAM: req lengh=4096, read=4096, pos=1936970/9730114
D (179485) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (179495) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1063, ridx=0
D (179495) HTTP_CLIENT: http_on_body 1063
D (179495) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (180495) HTTP_CLIENT: need_read=3033, byte_to_read=3033, rlen=1370, ridx=1063
D (180495) HTTP_CLIENT: http_on_body 1370
D (180495) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (181525) HTTP_CLIENT: need_read=1663, byte_to_read=1663, rlen=1370, ridx=2433
D (181525) HTTP_CLIENT: http_on_body 1370
D (181525) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (182345) HTTP_CLIENT: need_read=293, byte_to_read=293, rlen=293, ridx=3803
D (182345) HTTP_CLIENT: http_on_body 293
D (182345) HTTP_STREAM: req lengh=4096, read=4096, pos=1941066/9730114
D (182355) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (182355) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1077, ridx=0
D (182375) HTTP_CLIENT: http_on_body 1077
D (182375) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (183365) HTTP_CLIENT: need_read=3019, byte_to_read=3019, rlen=1370, ridx=1077
D (183365) HTTP_CLIENT: http_on_body 1370
D (183365) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (184385) HTTP_CLIENT: need_read=1649, byte_to_read=1649, rlen=1370, ridx=2447
D (184385) HTTP_CLIENT: http_on_body 1370
D (184395) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (185415) HTTP_CLIENT: need_read=279, byte_to_read=279, rlen=279, ridx=3817
D (185415) HTTP_CLIENT: http_on_body 279
D (185415) HTTP_STREAM: req lengh=4096, read=4096, pos=1945162/9730114
D (185425) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (185435) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1091, ridx=0
D (185435) HTTP_CLIENT: http_on_body 1091
D (185435) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (186435) HTTP_CLIENT: need_read=3005, byte_to_read=3005, rlen=1370, ridx=1091
D (186435) HTTP_CLIENT: http_on_body 1370
D (186435) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (187465) HTTP_CLIENT: need_read=1635, byte_to_read=1635, rlen=1370, ridx=2461
D (187465) HTTP_CLIENT: http_on_body 1370
D (187465) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (188485) HTTP_CLIENT: need_read=265, byte_to_read=265, rlen=265, ridx=3831
D (188485) HTTP_CLIENT: http_on_body 265
D (188485) HTTP_STREAM: req lengh=4096, read=4096, pos=1949258/9730114
D (188495) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (188505) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1105, ridx=0
D (188505) HTTP_CLIENT: http_on_body 1105
D (188515) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (189505) HTTP_CLIENT: need_read=2991, byte_to_read=2991, rlen=1370, ridx=1105
D (189515) HTTP_CLIENT: http_on_body 1370
D (189515) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (190325) HTTP_CLIENT: need_read=1621, byte_to_read=1621, rlen=1370, ridx=2475
D (190325) HTTP_CLIENT: http_on_body 1370
D (190325) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (191355) HTTP_CLIENT: need_read=251, byte_to_read=251, rlen=251, ridx=3845
D (191355) HTTP_CLIENT: http_on_body 251
D (191355) HTTP_STREAM: req lengh=4096, read=4096, pos=1953354/9730114
D (191365) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (191375) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1119, ridx=0
D (191385) HTTP_CLIENT: http_on_body 1119
D (191385) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (191765) TRANSPORT_BASE: remain data in cache, need to read again
D (192375) HTTP_CLIENT: need_read=2977, byte_to_read=2977, rlen=1370, ridx=1119
D (192375) HTTP_CLIENT: http_on_body 1370
D (192375) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (193395) HTTP_CLIENT: need_read=1607, byte_to_read=1607, rlen=1370, ridx=2489
D (193405) HTTP_CLIENT: http_on_body 1370
D (193405) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (194455) HTTP_CLIENT: need_read=237, byte_to_read=237, rlen=237, ridx=3859
D (194455) HTTP_CLIENT: http_on_body 237
D (194455) HTTP_STREAM: req lengh=4096, read=4096, pos=1957450/9730114
D (194465) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (194475) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1133, ridx=0
D (194475) HTTP_CLIENT: http_on_body 1133
D (194485) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (195445) HTTP_CLIENT: need_read=2963, byte_to_read=2963, rlen=1370, ridx=1133
D (195445) HTTP_CLIENT: http_on_body 1370
D (195445) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (196475) HTTP_CLIENT: need_read=1593, byte_to_read=1593, rlen=1370, ridx=2503
D (196475) HTTP_CLIENT: http_on_body 1370
D (196475) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (197495) HTTP_CLIENT: need_read=223, byte_to_read=223, rlen=223, ridx=3873
D (197495) HTTP_CLIENT: http_on_body 223
D (197495) HTTP_STREAM: req lengh=4096, read=4096, pos=1961546/9730114
D (197505) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (197515) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1147, ridx=0
D (197525) HTTP_CLIENT: http_on_body 1147
D (197525) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (198515) HTTP_CLIENT: need_read=2949, byte_to_read=2949, rlen=1370, ridx=1147
D (198525) HTTP_CLIENT: http_on_body 1370
D (198525) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (199335) HTTP_CLIENT: need_read=1579, byte_to_read=1579, rlen=1370, ridx=2517
D (199335) HTTP_CLIENT: http_on_body 1370
D (199345) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (200365) HTTP_CLIENT: need_read=209, byte_to_read=209, rlen=209, ridx=3887
D (200365) HTTP_CLIENT: http_on_body 209
D (200365) HTTP_STREAM: req lengh=4096, read=4096, pos=1965642/9730114
D (200375) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (200385) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1161, ridx=0
D (200385) HTTP_CLIENT: http_on_body 1161
D (200385) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (201385) HTTP_CLIENT: need_read=2935, byte_to_read=2935, rlen=1370, ridx=1161
D (201385) HTTP_CLIENT: http_on_body 1370
D (201385) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (202415) HTTP_CLIENT: need_read=1565, byte_to_read=1565, rlen=1370, ridx=2531
D (202415) HTTP_CLIENT: http_on_body 1370
D (202415) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (203435) HTTP_CLIENT: need_read=195, byte_to_read=195, rlen=195, ridx=3901
D (203435) HTTP_CLIENT: http_on_body 195
D (203435) HTTP_STREAM: req lengh=4096, read=4096, pos=1969738/9730114
D (203445) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (203455) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1175, ridx=0
D (203465) HTTP_CLIENT: http_on_body 1175
D (203465) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (203515) HTTP_CLIENT: need_read=2921, byte_to_read=2921, rlen=1370, ridx=1175
D (203515) HTTP_CLIENT: http_on_body 1370
D (203515) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (204455) HTTP_CLIENT: need_read=1551, byte_to_read=1551, rlen=1551, ridx=2545
D (204465) HTTP_CLIENT: http_on_body 1551
D (204465) HTTP_STREAM: req lengh=4096, read=4096, pos=1973834/9730114
D (204475) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (204475) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=3929, ridx=0
D (204485) HTTP_CLIENT: http_on_body 3929
D (204485) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (204495) HTTP_CLIENT: need_read=167, byte_to_read=167, rlen=167, ridx=3929
D (204505) HTTP_CLIENT: http_on_body 167
D (204515) HTTP_STREAM: req lengh=4096, read=4096, pos=1977930/9730114
D (204515) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
D (204525) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=1203, ridx=0
D (204525) HTTP_CLIENT: http_on_body 1203
D (204525) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
E (204545) TRANSPORT_BASE: poll_read select error 104, errno = Connection reset by peer, fd = 55
D (204555) HTTP_CLIENT: need_read=2893, byte_to_read=2893, rlen=-1, ridx=1203
D (204555) HTTP_STREAM: req lengh=4096, read=1203, pos=1982026/9730114
D (204565) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=7801336
E (204565) TRANSPORT_BASE: poll_read select error 0, errno = Success, fd = 55
D (204585) HTTP_CLIENT: need_read=4096, byte_to_read=4096, rlen=-1, ridx=0
D (204585) HTTP_CLIENT: Data processed 54451 != Data specified in content length 7801336
W (204595) HTTP_STREAM: No more data,errno:0, total_bytes:1983229, rlen = -1
D (204605) HTTP_STREAM: Direct URI. Stream will be stopped
I (204605) AUDIO_ELEMENT: IN-[IN_http] AEL_IO_DONE,0
D (204615) HTTP_STREAM: _http_close
I (204615) ESP_AUDIO_TASK: Recv Element[IN_http-0x3f80f5d4] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (205115) AUDIO_ELEMENT: IN-[DEC_mp3] AEL_IO_DONE,-2
I (205275) MP3_DECODER: Closed
I (205275) ESP_AUDIO_TASK: Received last pos: 1979167 bytes
I (205275) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f80f760] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (205365) AUDIO_ELEMENT: IN-[Audio_forge] AEL_IO_DONE,-2
I (205365) AUDIO_FORGE: audio forge closed
I (205365) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f81009c] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (205415) AUDIO_ELEMENT: IN-[OUT_iis] AEL_IO_DONE,-2
I (205455) ESP_AUDIO_TASK: Received last time: 164645 ms
I (205455) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f80f908] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (205465) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_FINISHED, 0, src:0, is_stopping:0
I (205475) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:984, MEM Total:4196367 Bytes, Inter:125195 Bytes, Dram:107711 Bytes

W (205485) ESP_AUDIO_TASK: Destroy the old pipeline, FINISHED
W (205485) ESP_AUDIO_TASK: The old pipeline destroyed, FINISHED
I (205505) CONSOLE_EXAMPLE: esp_auido status:4,err:0

I (205505) ESP_AUDIO_CTRL: Total:1972839, get duration:164403 ms by bps:96000
I (205515) CONSOLE_EXAMPLE: [ * ] End of time:164645 ms, duration:164403 ms
I (205525) CONSOLE_EXAMPLE: Func:esp_audio_state_task, Line:595, MEM Total:4225671 Bytes, Inter:145623 Bytes, Dram:128139 Bytes

D (251975) TRANSPORT_BASE: remain data in cache, need to read again
D (312185) TRANSPORT_BASE: remain data in cache, need to read again
D (372395) TRANSPORT_BASE: remain data in cache, need to read again
D (432605) TRANSPORT_BASE: remain data in cache, need to read again
D (492815) TRANSPORT_BASE: remain data in cache, need to read again
arsz6733 commented 2 years ago

Finally I managed to find a dirty fix for that. I altered the code inside [esp_http_client.c- Func : esp_http_client_read] .

I'm definitely sure that this is not the best solution for the problem.

`

    if (rlen <= 0) {
            ++errno = esp_transport_get_errno(client->transport);
        if (errno != 0) {
            esp_log_level_t sev = ESP_LOG_WARN;
            /* On connection close from server, recv should ideally return 0 but we have error conversion
             * in `tcp_transport` SSL layer which translates it `-1` and hence below additional checks */
            ++--if (rlen == -1  && client->response->is_chunked) {
                /* Explicit call to parser for invoking `message_complete` callback */
                http_parser_execute(client->parser, client->parser_settings, res_buffer->data, 0);
                /* ...and lowering the message severity, as closed connection from server side is expected in chunked transport */
                sev = ESP_LOG_DEBUG;
            }
            ESP_LOG_LEVEL(sev, TAG, "esp_transport_read returned:%d and errno:%d ", rlen, errno);
        }

`

After fixing reconnection I sometimes see a lag in the voice exactly the time it wants to start the new connection. from the http_on_body parameter, it is obvious that it's not using it's best performance until it again reconnects, however I'm not sure whether it's a problem related to the server or the client. 

 (1911155) HTTP_STREAM: req lengh=1024, read=1024, pos=11462256/13237905
D (1911245) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=3681313
D (1911245) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1, ridx=0
D (1911265) HTTP_CLIENT: http_on_body 1
D (1911265) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=3681313
D (1911265) HTTP_CLIENT: need_read=1023, byte_to_read=1023, rlen=-1, ridx=1
D (1911275) HTTP_STREAM: req lengh=1024, read=1, pos=11463280/13237905
D (1911285) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=3681313
E (1911285) TRANSPORT_BASE: tcp_read error, errno=Socket is not connected
D (1911295) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=-1, ridx=0
W (1911295) HTTP_CLIENT: esp_transport_read returned:-1 and errno:128
D (1911315) HTTP_CLIENT: Data processed 1906689 != Data specified in content length 3681313
W (1911325) HTTP_STREAM: No more data,errno:128, total_bytes:11463281, rlen = -1
W (1911325) HTTP_STREAM: Got 128 errno, reconnect to peer
D (1911335) HTTP_STREAM: _http_close
D (1911335) HTTP_STREAM: _http_open
D (1911335) HTTP_STREAM: URI=http://sitopet.com/app/file/cat/music/alone-in-home/track2.mp3
D (1911345) HTTP_CLIENT: Begin connect to: http://sitopet.com:80
D (1911345) esp-tls: host:sitopet.com: strlen 11
D (1911365) esp-tls: [sock=55] Resolved IPv4 address: 160.153.131.155
D (1911365) esp-tls: [sock=55] Connecting to server. HOST: sitopet.com, Port: 80
D (1911655) HTTP_CLIENT: Write header[4]: GET /app/file/cat/music/alone-in-home/track2.mp3 HTTP/1.1
User-Agent: ESP32 HTTP Client/1.0
Host: sitopet.com
Range: bytes=11463281-
Content-Length: 0

D (1911875) HTTP_CLIENT: on_message_begin
D (1911875) HTTP_CLIENT: HEADER=Date:Fri, 18 Mar 2022 23:31:23 GMT
D (1911875) HTTP_CLIENT: HEADER=Server:Apache
D (1911885) HTTP_CLIENT: HEADER=Upgrade:h2,h2c
D (1911885) HTTP_CLIENT: HEADER=Connection:Upgrade
D (1911885) HTTP_CLIENT: HEADER=Last-Modified:Wed, 28 Jul 2021 21:59:04 GMT
D (1911905) HTTP_CLIENT: HEADER=ETag:"35a008b-c9fe91-5c83618410983"
D (1911905) HTTP_CLIENT: HEADER=Accept-Ranges:bytes
D (1911915) HTTP_CLIENT: HEADER=Content-Length:1774624
D (1911915) HTTP_CLIENT: HEADER=Vary:Accept-Encoding
D (1911925) HTTP_CLIENT: HEADER=Content-Range:bytes 11463281-13237904/13237905
D (1911925) HTTP_CLIENT: HEADER=Content-Type:audio/mpeg
D (1911935) HTTP_STREAM: Content-Type = audio/mpeg
D (1911935) HTTP_CLIENT: http_on_headers_complete, status=206, offset=352, nread=352
D (1911945) HTTP_CLIENT: http_on_body 3744
D (1911945) HTTP_CLIENT: content_length = 1774624
I (1911955) HTTP_STREAM: total_bytes=13237905
D (1911965) HTTP_STREAM: req lengh=1024, read=1024, pos=11463281/13237905
D (1911965) HTTP_STREAM: req lengh=1024, read=1024, pos=11464305/13237905
D (1911975) HTTP_STREAM: req lengh=1024, read=1024, pos=11465329/13237905
D (1911985) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1911985) HTTP_CLIENT: need_read=352, byte_to_read=352, rlen=352, ridx=672
D (1911995) HTTP_CLIENT: http_on_body 352
D (1911995) HTTP_STREAM: req lengh=1024, read=1024, pos=11466353/13237905
D (1912015) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1912015) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1912025) HTTP_CLIENT: http_on_body 1024
D (1912025) HTTP_STREAM: req lengh=1024, read=1024, pos=11467377/13237905
D (1912035) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1912035) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=272, ridx=0
D (1912045) HTTP_CLIENT: http_on_body 272
D (1912055) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1915955) HTTP_CLIENT: need_read=752, byte_to_read=752, rlen=752, ridx=272
D (1915955) HTTP_CLIENT: http_on_body 752
D (1915955) HTTP_STREAM: req lengh=1024, read=1024, pos=11468401/13237905
D (1915965) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1915975) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=354, ridx=0
D (1915975) HTTP_CLIENT: http_on_body 354
D (1915995) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1916975) HTTP_CLIENT: need_read=670, byte_to_read=670, rlen=670, ridx=354
D (1916985) HTTP_CLIENT: http_on_body 670
D (1916985) HTTP_STREAM: req lengh=1024, read=1024, pos=11469425/13237905
D (1916995) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1916995) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=700, ridx=0
D (1917005) HTTP_CLIENT: http_on_body 700
D (1917015) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1918005) HTTP_CLIENT: need_read=324, byte_to_read=324, rlen=324, ridx=700
D (1918005) HTTP_CLIENT: http_on_body 324
D (1918005) HTTP_STREAM: req lengh=1024, read=1024, pos=11470449/13237905
D (1918015) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1918025) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1918025) HTTP_CLIENT: http_on_body 1024
D (1918035) HTTP_STREAM: req lengh=1024, read=1024, pos=11471473/13237905
D (1918035) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1918055) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=22, ridx=0
D (1918055) HTTP_CLIENT: http_on_body 22
D (1918055) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1919025) HTTP_CLIENT: need_read=1002, byte_to_read=1002, rlen=1002, ridx=22
D (1919025) HTTP_CLIENT: http_on_body 1002
D (1919025) HTTP_STREAM: req lengh=1024, read=1024, pos=11472497/13237905
D (1919035) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1919045) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=368, ridx=0
D (1919055) HTTP_CLIENT: http_on_body 368
D (1919055) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1920055) HTTP_CLIENT: need_read=656, byte_to_read=656, rlen=656, ridx=368
D (1920055) HTTP_CLIENT: http_on_body 656
D (1920055) HTTP_STREAM: req lengh=1024, read=1024, pos=11473521/13237905
D (1920065) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1920075) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=714, ridx=0
D (1920075) HTTP_CLIENT: http_on_body 714
D (1920085) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1921075) HTTP_CLIENT: need_read=310, byte_to_read=310, rlen=310, ridx=714
D (1921075) HTTP_CLIENT: http_on_body 310
D (1921075) HTTP_STREAM: req lengh=1024, read=1024, pos=11474545/13237905
D (1921085) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1921095) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1921095) HTTP_CLIENT: http_on_body 1024
D (1921105) HTTP_STREAM: req lengh=1024, read=1024, pos=11475569/13237905
D (1921115) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1921125) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=36, ridx=0
D (1921125) HTTP_CLIENT: http_on_body 36
D (1921135) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1921895) HTTP_CLIENT: need_read=988, byte_to_read=988, rlen=988, ridx=36
D (1921895) HTTP_CLIENT: http_on_body 988
D (1921895) HTTP_STREAM: req lengh=1024, read=1024, pos=11476593/13237905
D (1921905) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1921915) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=382, ridx=0
D (1921925) HTTP_CLIENT: http_on_body 382
D (1921925) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1922915) HTTP_CLIENT: need_read=642, byte_to_read=642, rlen=642, ridx=382
D (1922915) HTTP_CLIENT: http_on_body 642
D (1922915) HTTP_STREAM: req lengh=1024, read=1024, pos=11477617/13237905
D (1922925) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1922935) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=728, ridx=0
D (1922935) HTTP_CLIENT: http_on_body 728
D (1922945) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1923945) HTTP_CLIENT: need_read=296, byte_to_read=296, rlen=296, ridx=728
D (1923945) HTTP_CLIENT: http_on_body 296
D (1923945) HTTP_STREAM: req lengh=1024, read=1024, pos=11478641/13237905
D (1923955) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1923965) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1923975) HTTP_CLIENT: http_on_body 1024
D (1923975) HTTP_STREAM: req lengh=1024, read=1024, pos=11479665/13237905
D (1923975) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1923995) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=50, ridx=0
D (1923995) HTTP_CLIENT: http_on_body 50
D (1924005) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1924965) HTTP_CLIENT: need_read=974, byte_to_read=974, rlen=974, ridx=50
D (1924965) HTTP_CLIENT: http_on_body 974
D (1924965) HTTP_STREAM: req lengh=1024, read=1024, pos=11480689/13237905
D (1924975) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1924985) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=396, ridx=0
D (1924985) HTTP_CLIENT: http_on_body 396
D (1925005) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1925985) HTTP_CLIENT: need_read=628, byte_to_read=628, rlen=628, ridx=396
D (1925985) HTTP_CLIENT: http_on_body 628
D (1925995) HTTP_STREAM: req lengh=1024, read=1024, pos=11481713/13237905
D (1926005) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1926005) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=742, ridx=0
D (1926015) HTTP_CLIENT: http_on_body 742
D (1926025) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1926395) TRANSPORT_BASE: remain data in cache, need to read again
D (1927015) HTTP_CLIENT: need_read=282, byte_to_read=282, rlen=282, ridx=742
D (1927015) HTTP_CLIENT: http_on_body 282
D (1927015) HTTP_STREAM: req lengh=1024, read=1024, pos=11482737/13237905
D (1927025) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1927035) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1927045) HTTP_CLIENT: http_on_body 1024
D (1927045) HTTP_STREAM: req lengh=1024, read=1024, pos=11483761/13237905
D (1927045) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1927065) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=64, ridx=0
D (1927065) HTTP_CLIENT: http_on_body 64
D (1927075) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1928035) HTTP_CLIENT: need_read=960, byte_to_read=960, rlen=960, ridx=64
D (1928035) HTTP_CLIENT: http_on_body 960
D (1928035) HTTP_STREAM: req lengh=1024, read=1024, pos=11484785/13237905
D (1928045) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1928055) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=410, ridx=0
D (1928055) HTTP_CLIENT: http_on_body 410
D (1928075) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1929065) HTTP_CLIENT: need_read=614, byte_to_read=614, rlen=614, ridx=410
D (1929065) HTTP_CLIENT: http_on_body 614
D (1929065) HTTP_STREAM: req lengh=1024, read=1024, pos=11485809/13237905
D (1929075) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1929085) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=756, ridx=0
D (1929085) HTTP_CLIENT: http_on_body 756
D (1929095) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1930085) HTTP_CLIENT: need_read=268, byte_to_read=268, rlen=268, ridx=756
D (1930085) HTTP_CLIENT: http_on_body 268
D (1930085) HTTP_STREAM: req lengh=1024, read=1024, pos=11486833/13237905
D (1930095) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1930105) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1930115) HTTP_CLIENT: http_on_body 1024
D (1930115) HTTP_STREAM: req lengh=1024, read=1024, pos=11487857/13237905
D (1930115) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1930135) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=78, ridx=0
D (1930145) HTTP_CLIENT: http_on_body 78
D (1930145) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1930905) HTTP_CLIENT: need_read=946, byte_to_read=946, rlen=946, ridx=78
D (1930905) HTTP_CLIENT: http_on_body 946
D (1930905) HTTP_STREAM: req lengh=1024, read=1024, pos=11488881/13237905
D (1930915) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1930925) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=424, ridx=0
D (1930925) HTTP_CLIENT: http_on_body 424
D (1930935) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1931925) HTTP_CLIENT: need_read=600, byte_to_read=600, rlen=600, ridx=424
D (1931925) HTTP_CLIENT: http_on_body 600
D (1931925) HTTP_STREAM: req lengh=1024, read=1024, pos=11489905/13237905
D (1931945) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1931945) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=770, ridx=0
D (1931945) HTTP_CLIENT: http_on_body 770
D (1931965) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1932955) HTTP_CLIENT: need_read=254, byte_to_read=254, rlen=254, ridx=770
D (1932955) HTTP_CLIENT: http_on_body 254
D (1932955) HTTP_STREAM: req lengh=1024, read=1024, pos=11490929/13237905
D (1932965) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1932975) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1932985) HTTP_CLIENT: http_on_body 1024
D (1932985) HTTP_STREAM: req lengh=1024, read=1024, pos=11491953/13237905
D (1932985) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1933005) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=92, ridx=0
D (1933015) HTTP_CLIENT: http_on_body 92
D (1933015) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1933975) HTTP_CLIENT: need_read=932, byte_to_read=932, rlen=932, ridx=92
D (1933975) HTTP_CLIENT: http_on_body 932
D (1933975) HTTP_STREAM: req lengh=1024, read=1024, pos=11492977/13237905
D (1933985) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1933995) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=438, ridx=0
D (1933995) HTTP_CLIENT: http_on_body 438
D (1934015) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1934995) HTTP_CLIENT: need_read=586, byte_to_read=586, rlen=586, ridx=438
D (1935005) HTTP_CLIENT: http_on_body 586
D (1935005) HTTP_STREAM: req lengh=1024, read=1024, pos=11494001/13237905
D (1935015) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1935025) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=784, ridx=0
D (1935025) HTTP_CLIENT: http_on_body 784
D (1935035) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1935075) HTTP_CLIENT: need_read=240, byte_to_read=240, rlen=240, ridx=784
D (1935075) HTTP_CLIENT: http_on_body 240
D (1935075) HTTP_STREAM: req lengh=1024, read=1024, pos=11495025/13237905
D (1935085) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1935095) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1935095) HTTP_CLIENT: http_on_body 1024
D (1935105) HTTP_STREAM: req lengh=1024, read=1024, pos=11496049/13237905
D (1935105) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1935125) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=106, ridx=0
D (1935125) HTTP_CLIENT: http_on_body 106
D (1935135) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1936025) HTTP_CLIENT: need_read=918, byte_to_read=918, rlen=918, ridx=106
D (1936025) HTTP_CLIENT: http_on_body 918
D (1936025) HTTP_STREAM: req lengh=1024, read=1024, pos=11497073/13237905
D (1936035) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1936045) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1936045) HTTP_CLIENT: http_on_body 1024
D (1936065) HTTP_STREAM: req lengh=1024, read=1024, pos=11498097/13237905
D (1936065) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1936075) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1936075) HTTP_CLIENT: http_on_body 1024
D (1936085) HTTP_STREAM: req lengh=1024, read=1024, pos=11499121/13237905
D (1936095) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
D (1936095) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1936105) HTTP_CLIENT: http_on_body 1024
D (1936105) HTTP_STREAM: req lengh=1024, read=1024, pos=11500145/13237905
D (1936115) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1774624
E (1936115) TRANSPORT_BASE: poll_read select error 104, errno = Connection reset by peer, fd = 55
D (1936135) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=-1, ridx=0
W (1936145) HTTP_CLIENT: esp_transport_read returned:-1 and errno:104
D (1936145) HTTP_CLIENT: Data processed 37888 != Data specified in content length 1774624
W (1936155) HTTP_STREAM: No more data,errno:104, total_bytes:11501169, rlen = -1
W (1936165) HTTP_STREAM: Got 104 errno, reconnect to peer
D (1936165) HTTP_STREAM: _http_close
D (1936165) HTTP_STREAM: _http_open
D (1936175) HTTP_STREAM: URI=http://sitopet.com/app/file/cat/music/alone-in-home/track2.mp3
D (1936185) HTTP_CLIENT: Begin connect to: http://sitopet.com:80
D (1936195) esp-tls: host:sitopet.com: strlen 11
D (1936195) esp-tls: [sock=55] Resolved IPv4 address: 160.153.131.155
D (1936205) esp-tls: [sock=55] Connecting to server. HOST: sitopet.com, Port: 80
D (1936435) HTTP_CLIENT: Write header[4]: GET /app/file/cat/music/alone-in-home/track2.mp3 HTTP/1.1
User-Agent: ESP32 HTTP Client/1.0
Host: sitopet.com
Range: bytes=11501169-
Content-Length: 0

D (1936635) HTTP_CLIENT: on_message_begin
D (1936645) HTTP_CLIENT: HEADER=Date:Fri, 18 Mar 2022 23:31:47 GMT
D (1936645) HTTP_CLIENT: HEADER=Server:Apache
D (1936655) HTTP_CLIENT: HEADER=Upgrade:h2,h2c
D (1936655) HTTP_CLIENT: HEADER=Connection:Upgrade
D (1936655) HTTP_CLIENT: HEADER=Last-Modified:Wed, 28 Jul 2021 21:59:04 GMT
D (1936665) HTTP_CLIENT: HEADER=ETag:"35a008b-c9fe91-5c83618410983"
D (1936675) HTTP_CLIENT: HEADER=Accept-Ranges:bytes
D (1936675) HTTP_CLIENT: HEADER=Content-Length:1736736
D (1936675) HTTP_CLIENT: HEADER=Vary:Accept-Encoding
D (1936685) HTTP_CLIENT: HEADER=Content-Range:bytes 11501169-13237904/13237905
D (1936685) HTTP_CLIENT: HEADER=Content-Type:audio/mpeg
D (1936705) HTTP_STREAM: Content-Type = audio/mpeg
D (1936705) HTTP_CLIENT: http_on_headers_complete, status=206, offset=352, nread=352
D (1936715) HTTP_CLIENT: http_on_body 3744
D (1936715) HTTP_CLIENT: content_length = 1736736
I (1936725) HTTP_STREAM: total_bytes=13237905
D (1936725) HTTP_STREAM: req lengh=1024, read=1024, pos=11501169/13237905
D (1936735) HTTP_STREAM: req lengh=1024, read=1024, pos=11502193/13237905
D (1936745) HTTP_STREAM: req lengh=1024, read=1024, pos=11503217/13237905
D (1936755) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1736736
D (1936765) HTTP_CLIENT: need_read=352, byte_to_read=352, rlen=352, ridx=672
D (1936765) HTTP_CLIENT: http_on_body 352
D (1936775) HTTP_STREAM: req lengh=1024, read=1024, pos=11504241/13237905
D (1936775) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1736736
D (1936785) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1936785) HTTP_CLIENT: http_on_body 1024
D (1936785) HTTP_STREAM: req lengh=1024, read=1024, pos=11505265/13237905
D (1936805) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1736736
D (1936815) HTTP_CLIENT: need_read=1024, byte_to_read=1024, rlen=1024, ridx=0
D (1936815) HTTP_CLIENT: http_on_body 1024
D (1936815) HTTP_STREAM: req lengh=1024, read=1024, pos=11506289/13237905
D (1936825) HTTP_CLIENT: is_data_remain=1, is_chunked=0, content_length=1736736
HengYongChao commented 2 years ago

Hi @arsz6733

I am inclined to be your network problem, I used the cli routine to play the mp3 link you provided and did not reproduce your problem.

ADF: f6b3aac67e536fe0d8149198ffc3426c738e5e3c IDF: d83021a6e8550b4d462e11d61aaab0214dc03f5a Board: Lyrat mini v1.2

The CLI example plays the mp3 file in its entirety.

I (1030638) CONSOLE_EXAMPLE: app_audio playalone-in-home/track1.mp3
I (1030648) CONSOLE_EXAMPLE: play index= -1, URI:http://sitopet.com/app/file/cat/music/alone-in-home/track1.mp3, byte_pos:0
I (1030658) ESP_AUDIO_CTRL: Enter play procedure, src:0
I (1030658) ESP_AUDIO_CTRL: Play procedure, URL is ok, src:0
I (1030668) ESP_AUDIO_CTRL: Request_CMD_Queue CMD:0, Available:5, que:0x3ffe2068
I (1030668) ESP_AUDIO_TASK: It's a decoder
I (1030668) ESP_AUDIO_CTRL: Func:_ctrl_play, Line:771, MEM Total:4228791 Bytes, Inter:123623 Bytes, Dram:101523 Bytes

I (1030678) ESP_AUDIO_TASK: 1.CUR IN:[IN_http],CODEC:[DEC_mp3],RESAMPLE:[48000],OUT:[OUT_iis],rate:0,ch:0,pos:0
I (1030708) ESP_AUDIO_TASK: 2.Handles,IN:0x3f807ec4,CODEC:0x3f808694,FILTER:0x3f809580,OUT:0x3f809040
W (1030718) AUDIO_PIPELINE: Without stop, st:1
W (1030718) AUDIO_PIPELINE: Without wait stop, st:1
I (1030728) AUDIO_PIPELINE: audio_pipeline_unlinked
W (1030728) AUDIO_PIPELINE: There are no listener registered
I (1030738) ESP_AUDIO_TASK: 2.2 Update all pipeline
I (1030738) ESP_AUDIO_TASK: 2.3 Linked new pipeline
I (1030748) AUDIO_PIPELINE: link el->rb, el:0x3f807ec4, tag:IN_http, rb:0x3f810540
I (1030758) AUDIO_PIPELINE: link el->rb, el:0x3f808694, tag:DEC_mp3, rb:0x3f81057c
I (1030768) AUDIO_PIPELINE: link el->rb, el:0x3f809580, tag:Audio_forge, rb:0x3f8105b8
I (1030768) ESP_AUDIO_TASK: 3. Previous starting...
I (1030778) AUDIO_ELEMENT: [IN_http-0x3f807ec4] Element task created
I (1030788) AUDIO_ELEMENT: [IN_http] AEL_MSG_CMD_RESUME,state:1
I (1030798) AUDIO_ELEMENT: [DEC_mp3-0x3f808694] Element task created
I (1030798) AUDIO_ELEMENT: [DEC_mp3] AEL_MSG_CMD_RESUME,state:1
I (1030818) MP3_DECODER: MP3 opened
I (1030818) ESP_AUDIO_TASK: Blocking play until received AEL_MSG_CMD_REPORT_MUSIC_INFO
I (1031898) HTTP_STREAM: total_bytes=9730114
I (1031898) ESP_AUDIO_TASK: Recv Element[IN_http-0x3f807ec4] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (1031928) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f808694] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (1031968) ESP_AUDIO_TASK: Received muisc info then on play
I (1031968) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0
I (1031978) AUDIO_ELEMENT: [Audio_forge-0x3f809580] Element task created
I (1031988) AUDIO_ELEMENT: [Audio_forge] AEL_MSG_CMD_RESUME,state:1
I (1031988) AUDIO_FORGE: audio_forge opened
I (1031988) AUDIO_ELEMENT: [OUT_iis-0x3f809040] Element task created
I (1032008) AUDIO_FORGE: audio_forge reopen
I (1032008) AUDIO_ELEMENT: [OUT_iis] AEL_MSG_CMD_RESUME,state:1
I (1032018) I2S_STREAM: AUDIO_STREAM_WRITER
I (1032028) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f809580] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (1032038) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f809040] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNINGI (1032028) ESP_AUDIO_CTRL: Exit play procedure, ret:0
esp32> 0m
I (1032058) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_RUNNING, 0, src:0, is_stopping:0
I (1032058) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:984, MEM Total:4128475 Bytes, Inter:87055 Bytes, Dram:64955 Bytes

I (1032078) CONSOLE_EXAMPLE: esp_auido status:1,err:0

W (1842338) HTTP_STREAM: No more data,errno:0, total_bytes:9730114, rlen = 0
I (1842338) AUDIO_ELEMENT: IN-[IN_http] AEL_IO_DONE,0
I (1842358) ESP_AUDIO_TASK: Recv Element[IN_http-0x3f807ec4] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (1843198) AUDIO_ELEMENT: IN-[DEC_mp3] AEL_IO_DONE,-2
I (1843378) MP3_DECODER: Closed
I (1843378) ESP_AUDIO_TASK: Received last pos: 9729986 bytes
I (1843378) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f808694] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (1843468) AUDIO_ELEMENT: IN-[Audio_forge] AEL_IO_DONE,-2
I (1843468) AUDIO_FORGE: audio forge closed
I (1843468) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f809580] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (1843518) AUDIO_ELEMENT: IN-[OUT_iis] AEL_IO_DONE,-2
I (1843558) ESP_AUDIO_TASK: Received last time: 811514 ms
I (1843558) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f809040] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED
I (1843568) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_FINISHED, 0, src:0, is_stopping:0
I (1843578) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:984, MEM Total:4204619 Bytes, Inter:103219 Bytes, Dram:81119 Bytes

W (1843588) ESP_AUDIO_TASK: Destroy the old pipeline, FINISHED
W (1843588) ESP_AUDIO_TASK: The old pipeline destroyed, FINISHED
I (1843608) CONSOLE_EXAMPLE: esp_auido status:4,err:0

I (1843608) ESP_AUDIO_CTRL: Total:9723658, get duration:810304 ms by bps:96000
I (1843618) CONSOLE_EXAMPLE: [ * ] End of time:811514 ms, duration:810304 ms
I (1843628) CONSOLE_EXAMPLE: Func:esp_audio_state_task, Line:518, MEM Total:4228855 Bytes, Inter:123715 Bytes, Dram:101615 Bytes
arsz6733 commented 2 years ago

Hi @HengYongChao

Thank you for your answer.

I tested now and the problem didn't show up again. It's definitely a server problem (configuration maybe), but how the code reacted to that wasn't correct ( you can see my log). I don't know how I can reproduce the problem but I had this problem for a few days in a row

Update : I could falsely reproduce the problem by disconnecting the internet for a second!(Internet not wifi) I don't how exactly that is related to that but same log showed up

jason-mao commented 2 years ago

@arsz6733 I found an related issue and fixed on 7600869c35342abb5219211f133b44910b2e577c.

I'm going to close this issue. Please reopen this if you have any questions or need any further assistance.

shootao commented 2 years ago

Hi @arsz6733 :

Thank you for reply

Regarding the issue that errno is 114, we actually have the function to continue the transmission of breakpoints. There are corresponding patches in ADF 2.3, or you can directly update ADF to 2.4 or master.For more information, please refer to patch related readme