search

jorgenkraghjakobsen / snapclient

WIP snapclient on ESP32
237 stars 48 forks source link

Edit the code to work on different Hardware Platform #4

Open karimSad opened 4 years ago

karimSad commented 4 years ago

Hi Jorgen,

I have some questions that would help me to run your nice repo on my standard development board ESP32-LyraT V4.3).

In Lyra board, an internal codec ES8388 and internal power amplifier (instead of MerusAudio) are used in the Lyra board.

The internal codec of the Lyra board is connected to the esp32-wrover module via i2s interface for audio and i2c for control.

My approach to let my board work with snapclient was:

The code was compiled without problems. But when I flash the code, I am getting weird behavior.

My questions: (also understanding questions) :))

Thanks in advanced for your answer

Regards,

jorgenkraghjakobsen commented 4 years ago

Hi Karim Sure - I have 2 older Lyra boards here but never put much attention - time you known and the fact that I have first hand access to codec/audio amplifiers. I my setup i have a codec build into my audio power amplifier. Here codec is only and digital to analog converter that is integrated into the audio power amplifier. On the Lyra board the codec is a real codec that can do analog to digital for mic and aux input and digital to analog for the two analog input audio amplifiers. It is a bit old style as microphones and amplifers do digital I2S interface directly to the esp32. On the Lyra setup your approach is correct - call the appropriate Lyra ES8388 setup instead of my setup_ma12070 and you should be good to go. One thing that needs to be aligned is the I2S data format from ESP32 to the ES8388 - this is handled in dsp_processor.c For MA12070P we are using 32bits/48000kHz - But I recall my early Lyra experiments ran default 16bits/48000kHz Hope I pointed you in some direction. /j

karimSad commented 4 years ago

Hi Jorgen,

thanks a lot for your quick respone. Another question is :)

Now I can connect to snapserver and I am getting the following:

` Setup ringbuffer using PSRAM Buffer_struct ok Buffer_stoarge ok Ringbuf ok Ringbuffer ok I (10256) SNAPCAST: Connected to AP I (10266) SNAPCAST: Enable mdns I (10286) SNAPCAST: Lookup snapcast service on netowork I (10376) SNAPCAST: SNTP time set from server number :1 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (14376) SNAPCAST: Found 4902a8c0 I (14376) SNAPCAST: ... allocated socket I (14386) SNAPCAST: ... connected I (14396) SNAPCAST: Buffer length: 1000 I (14396) SNAPCAST: Ringbuffer size:192000 I (14396) SNAPCAST: Latency: 0 I (14396) SNAPCAST: Mute: 0 I (14406) SNAPCAST: Setting volume: 100 I (14416) SNAPCAST: Received codec header message

I (14416) SNAPCAST: Codec : flac , Size: 1362

I (14416) SNAPCAST: Opus sampleformat: 570425344:32772:32772

I (14426) SNAPCAST: Failed to init opus coder I (14436) SNAPCAST: Initialized opus Decoder: -1 E (14436) SNAPCAST: Decode error : -1

wait ... buffer : 0 E (14466) SNAPCAST: Decode error : -1

E (14486) SNAPCAST: Decode error : -1

E (14496) SNAPCAST: Decode error : -1

E (14516) SNAPCAST: Decode error : -1

E (14526) SNAPCAST: Decode error : -1

E (14556) SNAPCAST: Decode error : -1

E (14576) SNAPCAST: Decode error : -1

E (14616) SNAPCAST: Decode error : -1

E (14636) SNAPCAST: Decode error : -1

`

So, from menuconfig -> ESP32 audio buffer and I2s pin config I did the following configs: Master i2s bck = 5 Master i2s data lrck = 25 Master i2s data out = 26 Slave i2s bck = 5 Slave i2s data lrck = 25 Slave i2s data out = 35

I think these configs are not used

from components/rtprx/rtprx.c I changed i2s pin configs as follows: i2s_pin_config_t pin_config = { .bck_io_num = 5, //CONFIG_EXAMPLE_I2S_BCK_PIN, .ws_io_num = 25, //CONFIG_EXAMPLE_I2S_LRCK_PIN, .data_out_num = 26, //CONFIG_EXAMPLE_I2S_DATA_PIN, .data_in_num = 35 //Not used }; I commented the following code lines: ma_write(0x20,1,0x0040,cmd,1); and ma120_setup_audio(0x20);

Questions :) 1- Do you think this is the right pin configs or am I missing something. I am some how here not understanding well, why in your case you are using two cases (master and salve) but in Lyra they are using just four pins for i2s interface

2- In Lyra Board there is, as said before, an internal codec. But in this repo there are built-in decoder opus_decoder_create. So in my case, i must output the audio direct from the DAC and i should avoid pass ringbuffer through the codec which will decode the decoded data again. Do you think am i right or i am missing something.

3- To use Ringbuffer from main.c: I used this line in main.c RingbufHandle_t s_ringbuf_i2s = NULL; and in components/dsp_processor/dsp_processor.c I replaced this line static RingbufHandle_t s_ringbuf_i2s = NULL; by this line extern RingbufHandle_t s_ringbuf_i2s; Then I called s_ringbuf_i2s from ADF APIs from main.c. Do you think this approach is right?

Regards,

jorgenkraghjakobsen commented 4 years ago

Hi Karim Cool -
From you code is see that your Snapcast server is setup to code audio using the FLAC coder. Change the /etc/snapserver.conf to opus 48khz 16bit 2ch 

# Default sample format
sampleformat = 48000:16:2

# Default transport codec
# (flac|ogg|opus|pcm)[:options]
# Type codec:? to get codec specific options
codec = opus

  1. rptrx/rtprx.c code are not used. The I2S is pin config are setup in dsp_processor/dsp_processer.c function setup_dsp_i2s(..) pin config sourced from kconfig in dsp_processor/ For normal stereo dsp flow only the master I2S inst is needed. For some dsp flows i do left, right and bass for and need an additional I2S to be synced and linked in as slave. Save that feature for later.

  2. Yes quit. :-) The Snapcast server sends 5 ms chunks of PCM samples that has been coded with the opus encoder. On the ESP32 client side we take chunks of opus coded data and pass that through the opus decoder to get to PCM data. The PCM data 2 x 16-bits x 48000 KHz is what we need to buffer for 1000ms and stream to our I2S driver using the i2s_write() function call. The I2S driver used DMA to ensure constant flow of audio data on you I2S interface lines bck, ws and data. Not 100% sure but also think ES8388 needed a mclk that is 2 x bck. If that is the case the ADF es8388 has the code to setup a gpio to for that.

  3. Just keep the ringbuffer stuff as implemented in code.

I have fired up my LyraT board and is adapting the code to support that as well. That task is on my do list anyway.

/j

jorgenkraghjakobsen commented 4 years ago

Hi Karim Code now run on LyraT 4.3 - very fast prove of consept - Non ADF audio flot just setup ES8388 and power amp. /j

karimSad commented 4 years ago

Hi Jorgen,

very happy for these news :) I am not near to my board. Tomorrow I would test it on my Lyra board. Thanks a lot.

Best Regards, Karim

karimSad commented 4 years ago

Hi Jorgen,

well, unfortunatelly the snapclient on my Lyra is not working yet. There is no error but it can not connect to the snapserver i created on my machine. I tested my snapserver with snapdroid app from google store and it is working. from the console in my snapserver i am not getting the "hello" message from the Lyra (client).

My terminal from Lyra after connecting to the wifi AP is as follows: Setup ringbuffer using PSRAM Buffer_struct ok Buffer_stoarge ok Ringbuf ok Ringbuffer ok I (8708) SNAPCAST: Connected to AP I (8708) SNAPCAST: Enable mdns I (8718) SNAPCAST: Lookup snapcast service on netowork wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (11068) SNAPCAST: SNTP time set from server number :1 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 W (11818) SNAPCAST: No results found! wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (12818) SNAPCAST: Lookup snapcast service on netowork wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 W (15918) SNAPCAST: No results found! wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (16918) SNAPCAST: Lookup snapcast service on netowork wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 W (20018) SNAPCAST: No results found! wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (21018) SNAPCAST: Lookup snapcast service on netowork wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 W (24118) SNAPCAST: No results found! wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (25118) SNAPCAST: Lookup snapcast service on netowork wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (26128) SNAPCAST: SNTP diff us: 277216 , 292276 I (26128) SNAPCAST: SNTP diff us: -15.06 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0

I gave the host IP of my snapserver and port = 1704. I tried also port = 1705 and port =1780 (http stream)

So, it is silly question:)) you were able to connect to snapserver?

Thanks in advance Karim

Update:

jorgenkraghjakobsen commented 4 years ago

Hi This is the log of my snapserver 

./snapserver 
2020-06-13 22-35-48.483 [Info] (main) Adding stream: pipe:///tmp/snapfifo?name=default
2020-06-13 22-35-48.484 [Notice] (init) Settings file: "/home/jakobsen/.config/snapserver/server.json"
2020-06-13 22-35-48.501 [Info] (Avahi) Adding service 'Snapcast' 
2020-06-13 22-35-48.516 [Info] (start) Creating TCP acceptor for address: 0.0.0.0, port: 1705
2020-06-13 22-35-48.517 [Info] (start) Creating HTTP acceptor for address: 0.0.0.0, port: 1780
2020-06-13 22-35-48.517 [Info] (PcmStream) PcmStream sampleFormat: 48000:16:2
2020-06-13 22-35-48.518 [Info] (PcmStream) metadata={
2020-06-13 22-35-48.518 [Info] (PcmStream)     "STREAM": "default"
2020-06-13 22-35-48.518 [Info] (PcmStream) }
2020-06-13 22-35-48.518 [Info] (onMetaChanged) onMetaChanged (default)
2020-06-13 22-35-48.518 [Info] (PipeStream) PipeStream mode: create
2020-06-13 22-35-48.518 [Info] (start) Stream: {"fragment":"","host":"","path":"/tmp/snapfifo","query":{"chunk_ms":"20","codec":"opus","name":"default","sampleformat":"48000:16:2"},"raw":"pipe:////tmp/snapfifo?chunk_ms=20&codec=opus&name=default&sampleformat=48000:16:2","scheme":"pipe"}
2020-06-13 22-35-48.519 [Info] (initEncoder) Opus bitrate: 192000 bps, complexity: 10
2020-06-13 22-35-48.522 [Error] (PosixStream) Exception: end of file
2020-06-13 22-35-48.522 [Info] (start) Creating stream acceptor for address: 0.0.0.0, port: 1704
2020-06-13 22-35-48.522 [Info] (main) number of threads: 4, hw threads: 4
2020-06-13 22-35-49.568 [Info] (Avahi) Service 'Snapcast' successfully established.
2020-06-13 22-35-52.443 [Notice] (handleAccept) StreamServer::NewConnection: 192.168.1.233
2020-06-13 22-35-52.453 [Info] (onMessageReceived) Hello from 30:AE:A4:45:EE:FC, host: ESP32-Caster, v0.0.2, ClientName: libsnapcast, OS: esp32, Arch: xtensa, Protocol version: 2
2020-06-13 22-37-57.008 [Info] (onStateChanged) onStateChanged (default): 2
2020-06-13 22-38-04.291 [Info] (onStateChanged) onStateChanged (default): 1
2020-06-13 22-38-18.469 [Notice] (handleAccept) StreamServer::NewConnection: 192.168.1.233
2020-06-13 22-38-18.477 [Info] (onMessageReceived) Hello from 30:AE:A4:45:EE:FC, host: ESP32-Caster, v0.0.2, ClientName: libsnapcast, OS: esp32, Arch: xtensa, Protocol version: 2

Last 4 lines is my esp32 client connection

Your setup is looping in this code 

while ( !r || err )
    {  ESP_LOGI(TAG, "Lookup snapcast service on netowork");
       esp_err_t err = mdns_query_ptr("_snapcast", "_tcp", 3000, 20,  &r);
       if(err){
         ESP_LOGE(TAG, "Query Failed");
       }
       if(!r){
         ESP_LOGW(TAG, "No results found!");
       }
       vTaskDelay(1000/portTICK_PERIOD_MS); 
    }

Try to comment that out and hardcode ip of your snap server here 

servaddr.sin_family = AF_INET;
servaddr.sin_addr.s_addr = inet_addr("192.168.1.158");
servaddr.sin_port = htons(r->port);

/j

jorgenkraghjakobsen commented 4 years ago

I have checked in my snapcast server conf in the directory snapcast /j

karimSad commented 4 years ago

thanks a lot. I would give my feedback here as I get my board running.

jorgenkraghjakobsen commented 4 years ago

Also snap volume control to the ADF hal abstration - now need to do a hal driver for my own amp :-)

karimSad commented 4 years ago

well, at least i think that i know where is the problem :=)) I am using Ubuntu under windows as WSL. And the Mdns service seems not to work yet correctly. Here is the link

karimSad commented 4 years ago

Hi Jorgen,

due to several network problems was my board not working. Now it is working but for maximum 30 seconds then it makes a new restart :)

karimSad commented 4 years ago

Hallo Jorgen,

a short question :) In your Lyra board or even in your custom board, the audio is working fine for a relative long time or the program is falling down and RTOS is restarting again?

In my case, it is almost not working. So i wanted to know if it is from my wifi network or from the code itself on esp32

jorgenkraghjakobsen commented 4 years ago

My code is rocking - Is your snapserver on a linux instance running under windows. Can you try to test it vs a client on a nother pc. My client keep on for ever. Do you get 30 sec of audio or no audio at all? /j

karimSad commented 4 years ago

The 30 sec is kind of rare to get. My snapclient on the android is woking fine. So, I think that the wifi configs by me on the esp32 target are some how not set correctly.

My snapserver is working now on Raspbian OS in Raspberry pi.

karimSad commented 4 years ago

this is the terminal output after wifi init I also changed pcm_size from 120 to 960 in main.c

`I (7640) esp_netif_handlers: sta ip: 192.168.2.104, mask: 255.255.255.0, gw: 192 .168.2.1 I (7640) SNAPCAST: got ip:192.168.2.104 I (7640) SNAPCAST: connected to ap SSID:kontor password:1234 I (7650) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE Settime from sntp I (12660) SNAPCAST: Initializing SNTP Called I (12660) I2S: queue free spaces: 7 I (12660) I2S: DMA Malloc info, datalen=blocksize=1920, dma_buf_count=8 I (12680) I2S: APLL: Req RATE: 48000, real rate: 47999.961, BITS: 16, CLKM: 1, B CK_M: 8, MCLK: 12287990.000, SCLK: 1535998.750000, diva: 1, divb: 0 Setup ringbuffer using PSRAM Buffer_struct ok Buffer_stoarge ok Ringbuf ok Ringbuffer ok I (12690) SNAPCAST: Connected to AP I (12700) SNAPCAST: Enable mdns I (12700) SNAPCAST: Lookup snapcast service on netowork wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (15040) SNAPCAST: SNTP time set from server number :1 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (16800) SNAPCAST: Found 1e02a8c0 I (16800) SNAPCAST: ... allocated socket wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (17370) SNAPCAST: ... connected wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 wait ... buffer : 0 I (20680) SNAPCAST: Buffer length: 1000 I (20680) SNAPCAST: Ringbuffer size:192000 I (20680) SNAPCAST: Latency: 0 I (20680) SNAPCAST: Mute: 0 I (20680) SNAPCAST: Setting volume: 100 I (20690) SNAPCAST: Received codec header message

I (20690) SNAPCAST: Codec : opus , Size: 12

I (20700) SNAPCAST: Opus sampleformat: 48000:16:2

I (20700) SNAPCAST: Initialized opus Decoder: 0 I (20710) SNAPCAST: OPUS encoding buffer too small, resizing to 960 samples per channel I (22360) I2S: Chunk :960 105600 118380 I (22370) I2S: Chunk :960 104640 117780 I (22380) I2S: Chunk :960 103680 117180 I (22390) I2S: Chunk :960 106560 116640 I (22400) I2S: Chunk :960 105600 116100 I (22410) I2S: Chunk :960 108480 115620 I (22420) I2S: Chunk :960 111360 115200 I (22430) I2S: Chunk :960 110400 114780 I (22440) I2S: Chunk :960 109440 114360 I (22450) I2S: Chunk :960 108480 113940 I (22460) I2S: Chunk :960 107520 113520 I (22470) I2S: Chunk :960 106560 113100 I (22480) I2S: Chunk :960 105600 112680 I (22490) I2S: Chunk :960 104640 112260 I (22500) I2S: Chunk :960 103680 111840 I (22510) I2S: Chunk :960 102720 111420 Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandle d. Core 0 register dump: PC : 0x400d9617 PS : 0x00060930 A0 : 0x8008e7a4 A1 : 0x3f fe7800 A2 : 0x00000000 A3 : 0x00000158 A4 : 0x000000f0 A5 : 0x00 000000 A6 : 0x00000000 A7 : 0x000057ee A8 : 0x00000000 A9 : 0x3f fe77e0 A10 : 0x000008cb A11 : 0x3ffb0cbc A12 : 0x3f80013c A13 : 0x3f ff0820 A14 : 0x00000000 A15 : 0x3f800130 SAR : 0x0000001f EXCCAUSE: 0x00 00001c EXCVADDR: 0x00000000 LBEG : 0x4008a6b8 LEND : 0x4008a6e6 LCOUNT : 0x00 000000

ELF file SHA256: e4a826abdfe41079

Backtrace: 0x400d9614:0x3ffe7800 0x4008e7a1:0x3fff0a60 `

Thenicolaibulow commented 4 years ago

Hi guys,

I just wanted to chime in, and point out, that i'm having a very similar problem. At times my setup (Server running on ubuntu with pulse | /tmp/snapfifo, and two custom boards as my clients) does something quite similar.

Some times it'll run nicely for minuts, and then suddenly, without further ado, just crash. After playing quite a bit around with it, i've noticed some important factors:

At first my setup (just like Karimsad's) would crash, after the opus decodes was increasing in size. - It doesn't as often anymore, and this was on a earlier build anyways. I figure it's stille a buffer issue? It seems, that is the decoder still isn't happy, after the pcm_size is > 960, it'll try and double the size again, crashing the system.

Now i'm running into the same problem af karimsad. Whenever i turn off one client the other one dies every time, and panic's and dsp_processor.c line ~170. This is where Jørgen is doing the 16 - > 32 bit conversion, which i need.

I hope this might help you out a bit.

karimSad commented 4 years ago

Hi Nicolai,

but how did you changed to uplink of 5 GHz though the ESP32 supports (as I know) only 2.5 GHz. Or you are using another Hardware Platform?

Thenicolaibulow commented 4 years ago

Yes, you're right (unfortunately..) the esp only supports 2.4GHz, however the machine running my server is capable of doing 5GHz. It was very apparent, that drastically reduced the amount of lost packages when I change the server wifi.

As I've just moved into a new apartment, I wasn't aware of just how bad the wifi interference is here. The 2.4GHz band seriously crowded. Luckily, very few of my neighbors are using 5GHz wifi! :D

jorgenkraghjakobsen commented 4 years ago

Hi N and K The minimum buffer value that can be set at the snap server is 400 ms - Set it lower it will minimize to 400 ms. On the client side I have implemented a switch to run with or with out PSRAM. On non PSRAM esp32 module the server buffer setting is ignore and hardcode to 150ms. And yes it seems that you are experience WLAN network errors - I also had that issues when my server was on wifi as well. My problems dissolved after I hooked my workstation/server on my wired network. I have optimized my WLAN access point and my esp32 config for low latency - there is a concept called pkg aggregation that bundle smaller packet in bigger pkg to optimize for through put - but we want low latency. My WLAN access point is ZyXEL NWA3560-n Here I have disabled A-MPDU Aggregation and A-MSDU Aggregation Like wise on the ESP32 WiFi I have disable [ ] WiFi AMPDU TX [ ] WiFi AMPDU RX under components/wifi/ in menuconfig This help out a lot on my RTP low latency UDP audio streaming I was working with prior to the Snap stuff.

You mite want to do this optimizations as well.

Odd problem with one client taken the other one down as well. As understand each client has its own communication and audio flow with the server. Removing one would give more bandwidth to the other. I have only ran max 3 client, one on my workstation, one on my android and the esp32 client. /j

Thenicolaibulow commented 4 years ago

Aha!

Thanks for clarifying, Jørgen. I'll take a look at my esp-wifi & router settings! We can agree that it sounds odd that one client would take down the other - what connection to one another would they have?? I'll post a client and server log. - maybe you'll notice something, that I've overlooked.

othiman commented 2 years ago

Hi.

I try to compile and run snapclient for the ESP32_LyraT 4.3 board.

What I have done so far (under MacOS Big Sur):

After that I get the log from the end of this post via idf.py monitor. That looks quite OK, but I do not hear any sound from the connected headphones. Two things look suspicious to me:

Can someone give me a hint what I am doing wrong?

Best regards, Thomas

--- idf_monitor on /dev/cu.SLAB_USBtoUART 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x1f (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:2
load:0x3fff0030,len:6724
load:0x40078000,len:14908
load:0x40080400,len:3792
0x40080400: _init at ??:?

entry 0x40080694
I (27) boot: ESP-IDF v4.4-dev-3235-g3e370c4296 2nd stage bootloader
I (27) boot: compile time 23:36:59
I (27) boot: chip revision: 1
I (31) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (38) boot.esp32: SPI Speed      : 40MHz
I (43) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 4MB
I (52) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (61) boot: ## Label            Usage          Type ST Offset   Length
I (68) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (76) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (83) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (91) boot:  3 factory          factory app      00 00 00010000 00100000
I (98) boot:  4 ota_0            OTA app          00 10 00110000 00100000
I (106) boot:  5 ota_1            OTA app          00 11 00210000 00100000
I (113) boot: End of partition table
I (118) boot: Defaulting to factory image
I (122) boot_comm: chip revision: 1, min. application chip revision: 0
I (130) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=235d8h (144856) map
I (191) esp_image: segment 1: paddr=00033600 vaddr=3ffb0000 size=03940h ( 14656) load
I (197) esp_image: segment 2: paddr=00036f48 vaddr=40080000 size=090d0h ( 37072) load
I (212) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=a7f38h (687928) map
I (461) esp_image: segment 4: paddr=000e7f60 vaddr=400890d0 size=120c0h ( 73920) load
I (492) esp_image: segment 5: paddr=000fa028 vaddr=50000000 size=00010h (    16) load
I (505) boot: Loaded app from partition at offset 0x10000
I (505) boot: Disabling RNG early entropy source...
I (517) psram: This chip is ESP32-D0WD
I (519) spiram: Found 64MBit SPI RAM device
I (519) spiram: SPI RAM mode: flash 40m sram 40m
I (522) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (529) cpu_start: Pro cpu up.
I (533) cpu_start: Starting app cpu, entry point is 0x400815ec
0x400815ec: call_start_cpu1 at /Users/othiman/esp/esp-idf/components/esp_system/port/cpu_start.c:155

I (0) cpu_start: App cpu up.
I (1424) spiram: SPI SRAM memory test OK
I (1432) cpu_start: Pro cpu start user code
I (1432) cpu_start: cpu freq: 240000000
I (1432) cpu_start: Application information:
I (1435) cpu_start: Project name:     snapclient
I (1440) cpu_start: App version:      ad192d9-dirty
I (1446) cpu_start: Compile time:     Sep 30 2021 14:05:42
I (1452) cpu_start: ELF file SHA256:  32ee50bbe7ab9b2e...
I (1458) cpu_start: ESP-IDF:          v4.4-dev-3235-g3e370c4296
I (1465) heap_init: Initializing. RAM available for dynamic allocation:
I (1472) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1478) heap_init: At 3FFB9478 len 00026B88 (154 KiB): DRAM
I (1485) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1491) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1498) heap_init: At 4009B190 len 00004E70 (19 KiB): IRAM
I (1504) spiram: Adding pool of 4095K of external SPI memory to heap allocator
I (1513) spi_flash: detected chip: generic
I (1517) spi_flash: flash io: dio
I (1522) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1531) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1571) SNAPCAST: Start codec chip
I (1581) gpio: GPIO[19]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 
I (1591) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (1591) ES8388_DRIVER: init,out:02, in:00
I (1601) SNAPCAST: Audio board_init done
0.000262 0.000523 0.000262 -1.953721 0.954768 
0.000262 0.000523 0.000262 -1.953721 0.954768 
0.977122 -1.954244 0.977122 -1.953721 0.954768 
0.977122 -1.954244 0.977122 -1.953721 0.954768 
0.977122 -1.954244 0.977122 -1.953721 0.954768 
0.977122 -1.954244 0.977122 -1.953721 0.954768 
1.008064 -1.960688 0.954108 -1.961058 0.961802 
1.008064 -1.960688 0.954108 -1.961058 0.961802 
I (1651) wifi:wifi driver task: 3ffcaf60, prio:23, stack:6656, core=0
I (1651) system_api: Base MAC address is not set
I (1651) system_api: read default base MAC address from EFUSE
I (1671) wifi:wifi firmware version: d683787
I (1671) wifi:wifi certification version: v7.0
I (1671) wifi:config NVS flash: enabled
I (1671) wifi:config nano formating: disabled
I (1671) wifi:Init data frame dynamic rx buffer num: 32
I (1681) wifi:Init management frame dynamic rx buffer num: 32
I (1681) wifi:Init management short buffer num: 32
I (1691) wifi:Init static tx buffer num: 16
I (1691) wifi:Init tx cache buffer num: 32
I (1701) wifi:Init static rx buffer size: 1600
I (1701) wifi:Init static rx buffer num: 10
I (1701) wifi:Init dynamic rx buffer num: 32
I (1711) wifi_init: tcpip mbox: 32
I (1711) wifi_init: udp mbox: 6
I (1721) wifi_init: tcp mbox: 6
I (1721) wifi_init: tcp tx win: 5744
I (1721) wifi_init: tcp rx win: 5744
I (1731) wifi_init: tcp mss: 1440
I (1731) wifi_init: WiFi IRAM OP enabled
I (1741) wifi_init: WiFi RX IRAM OP enabled
I (1741) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1841) wifi:mode : sta (ac:67:b2:6f:9b:84)
I (1841) wifi:enable tsf
I (1851) WIFI: wifi_init_sta finished.
I (1861) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1
I (1861) wifi:state: init -> auth (b0)
I (6641) wifi:state: auth -> init (200)
I (6641) wifi:new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:1
I (6641) WIFI: retry to connect to the AP
I (6641) WIFI: connect to the AP fail
I (8691) WIFI: retry to connect to the AP
I (8691) WIFI: connect to the AP fail
I (8701) wifi:new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:1
I (8701) wifi:state: init -> auth (b0)
I (10271) wifi:state: auth -> assoc (0)
I (10281) wifi:state: assoc -> run (10)
I (10331) wifi:connected with OthisWLAN, aid = 5, channel 11, BW20, bssid = 5c:49:79:24:b2:e0
I (10331) wifi:security: WPA3-SAE, phy: bgn, rssi: -63
I (10331) wifi:pm start, type: 1

I (10401) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (11131) esp_netif_handlers: sta ip: 192.168.123.67, mask: 255.255.255.0, gw: 192.168.123.1
I (11131) WIFI: got ip:192.168.123.67
I (11131) WIFI: connected to ap SSID:OthisWLAN
I (11141) SNAPCAST: Connected to AP
I (11141) SNAPCAST: Setup ws server
I (11141) server_handle_task: task starting
I (11151) server_task: server listening
I (11151) NETF: Setup mdns
I (11161) OTA: idf.py build ; curl snapclient.local:8032 --data-binary @- < build/snapclient.bin
I (11171) I2S: Call dsp setup
I (11171) I2S: queue free spaces: 7
I (11181) I2S: APLL Enabled, coefficient: sdm0=2, sdm1=154, sdm2=4, odir=5
I (11181) I2S: DMA Malloc info, datalen=blocksize=3840, dma_buf_count=8
E (11191) I2S: i2s_check_set_mclk(253): ESP32 only support to set GPIO0/GPIO1/GPIO3 as mclk signal, error GPIO number:1073654224
E (11201) I2S: i2s_set_pin(314): mclk config failed
I (11211) I2S: I2S interface master setup
I (11211) I2S: Setup i2s dma and interface
Setup ringbuffer using PSRAM 
Buffer_struct ok
Buffer_stoarge ok
Ringbuf ok
Ringbuffer ok
I (11231) SNAPCAST: ... allocated socket
I (11251) SNAPCAST: ... connected
I (11281) SNAPCAST: Buffer length:  1000
I (11281) SNAPCAST: Ringbuffer size:192000
I (11281) SNAPCAST: Latency:        0
I (11281) SNAPCAST: Mute:           0
I (11291) SNAPCAST: Setting volume: 100
I (11301) SNAPCAST: Received codec header message

I (11301) SNAPCAST: Opus sampleformat: 48000:16:2

I (11311) SNAPCAST: Initialized opus Decoder: 0
I (11311) SNAPCAST: Codec : opus , Size: 12 

I (11311) SNAPCAST: OPUS encoding buffer too small, resizing to 120 samples per channel
I (11321) SNAPCAST: OPUS encoding buffer too small, resizing to 240 samples per channel
I (11331) SNAPCAST: OPUS encoding buffer too small, resizing to 480 samples per channel
I (11371) I2S: 1000 -943723477 syncing ... 
I (11371) I2S: 1000 -943723477 SYNCED 
I (11371) I2S: Chunk :1920 0 ms
I (11501) SNAPCAST: OPUS encoding buffer too small, resizing to 960 samples per channel
I (12651) I2S: Chunk :1920 247 ms
I (13771) I2S: Chunk :1920 6 ms
I (14871) I2S: Chunk :1920 17 ms
I (15611) I2S: Error readding audio from ring buf : read 1716 of 3840 , missing 2124
I (15611) I2S: Read the next 2124 
I (15981) I2S: Chunk :1920 30 ms
I (17081) I2S: Chunk :1920 30 ms
I (18191) I2S: Chunk :1920 16 ms
I (19321) I2S: Chunk :1920 37 ms
I (19711) I2S: Error readding audio from ring buf : read 1524 of 1920 , missing 396
I (19711) I2S: Read the next 396 
I (20421) I2S: Chunk :3840 20 ms
I (21531) I2S: Chunk :1920 40 ms
I (22631) I2S: Chunk :1920 47 ms
I (23731) I2S: Chunk :1920 49 ms
I (23771) I2S: Error readding audio from ring buf : read 1320 of 1920 , missing 600
I (23771) I2S: Read the next 600 
I (24821) I2S: Chunk :1920 51 ms
I (25911) I2S: Chunk :1920 40 ms
I (27021) I2S: Chunk :1920 57 ms
I (27811) I2S: Error readding audio from ring buf : read 1128 of 1920 , missing 792
I (27811) I2S: Read the next 792 
I (28111) I2S: Chunk :1920 51 ms
I (29221) I2S: Chunk :1920 33 ms
I (30311) I2S: Chunk :1920 42 ms
I (31401) I2S: Chunk :1920 28 ms
I (31841) I2S: Error readding audio from ring buf : read 924 of 1920 , missing 996
I (31841) I2S: Read the next 996 
I (32491) I2S: Chunk :1920 60 ms
I (33591) I2S: Chunk :1920 35 ms
I (34661) I2S: Chunk :1920 40 ms
I (35731) I2S: Chunk :3840 54 ms
I (35831) I2S: Error readding audio from ring buf : read 732 of 1920 , missing 1188
I (35831) I2S: Read the next 1188 
I (36811) I2S: Chunk :1920 46 ms
I (37901) I2S: Chunk :1920 44 ms
I (38971) I2S: Chunk :1920 27 ms
I (39821) I2S: Error readding audio from ring buf : read 528 of 1920 , missing 1392
I (39821) I2S: Read the next 1392 
I (40051) I2S: Chunk :1920 69 ms
I (41141) I2S: Chunk :1920 48 ms
I (42181) I2S: Chunk :1920 16 ms
I (43211) I2S: Chunk :1920 21 ms
I (43681) I2S: Error readding audio from ring buf : read 336 of 1920 , missing 1584
I (43691) I2S: Read the next 1584 
I (44241) I2S: Chunk :1920 2 ms
I (45311) I2S: Chunk :1920 48 ms
I (46391) I2S: Chunk :1920 53 ms
I (47471) I2S: Chunk :1920 14 ms
I (47631) I2S: Error readding audio from ring buf : read 132 of 1920 , missing 1788
I (47631) I2S: Read the next 1788 
I (48551) I2S: Chunk :1920 43 ms