feelfreelinux / cspot

A Spotify Connect player targeting, but not limited to embedded devices (ESP32).
Other
497 stars 46 forks source link

AC101 Not Found #78

Closed Timvrakas closed 3 years ago

Timvrakas commented 3 years ago

despite the issues I ran into in #77, I went ahead and tried on my ESP32 Audio Kit V2.2, which has an ESP32-A1S module.

I (26) boot: ESP-IDF 4.3.1 2nd stage bootloader
I (27) boot: compile time 01:12:31
I (27) boot: chip revision: 1
I (29) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (36) qio_mode: Enabling default flash chip QIO
I (42) boot.esp32: SPI Speed      : 40MHz
I (46) boot.esp32: SPI Mode       : QIO
I (51) boot.esp32: SPI Flash Size : 4MB
I (55) boot: Enabling RNG early entropy source...
I (61) boot: Partition Table:
I (64) boot: ## Label            Usage          Type ST Offset   Length
I (72) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (79) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (87) boot:  2 factory          factory app      00 00 00010000 00200000
I (94) boot:  3 storage          Unknown data     01 82 00210000 00100000
I (102) boot: End of partition table
I (106) boot_comm: chip revision: 1, min. application chip revision: 0
I (113) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=3ef7ch (257916) map
I (207) esp_image: segment 1: paddr=0004efa4 vaddr=3ffbdb60 size=01074h (  4212) load
I (208) esp_image: segment 2: paddr=00050020 vaddr=400d0020 size=d6260h (877152) map
I (501) esp_image: segment 3: paddr=00126288 vaddr=3ffbebd4 size=03bd4h ( 15316) load
I (507) esp_image: segment 4: paddr=00129e64 vaddr=40080000 size=18540h ( 99648) load
I (545) esp_image: segment 5: paddr=001423ac vaddr=50000000 size=00010h (    16) load
I (558) boot: Loaded app from partition at offset 0x10000
I (558) boot: Disabling RNG early entropy source...
I (569) psram: This chip is ESP32-D0WD
I (570) spiram: Found 64MBit SPI RAM device
I (570) spiram: SPI RAM mode: flash 80m sram 80m
I (575) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (582) cpu_start: Pro cpu up.
I (586) cpu_start: Starting app cpu, entry point is 0x40082264
I (0) cpu_start: App cpu up.
I (1089) spiram: SPI SRAM memory test OK
I (1097) cpu_start: Pro cpu start user code
I (1097) cpu_start: cpu freq: 240000000
I (1097) cpu_start: Application information:
I (1100) cpu_start: Project name:     cspot-esp32
I (1105) cpu_start: App version:      8c72600
I (1110) cpu_start: Compile time:     Nov 19 2021 01:58:19
I (1117) cpu_start: ELF file SHA256:  b0b475de610b6221...
I (1123) cpu_start: ESP-IDF:          4.3.1
I (1128) heap_init: Initializing. RAM available for dynamic allocation:
I (1135) heap_init: At 3FFAE6E0 len 0000F480 (61 KiB): DRAM
I (1141) heap_init: At 3FFC7DE8 len 00018218 (96 KiB): DRAM
I (1147) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1154) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1160) heap_init: At 40098540 len 00007AC0 (30 KiB): IRAM
I (1167) spiram: Adding pool of 4084K of external SPI memory to heap allocator
I (1175) spi_flash: detected chip: generic
I (1179) spi_flash: flash io: qio
I (1192) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1194) spiram: Reserving pool of 64K of internal memory for DMA/internal allocations
I (1304) cspot: Partition size: total: 956561, used: 1004
I (1324) wifi:wifi driver task: 3ffbbb7c, prio:23, stack:6656, core=0
I (1324) system_api: Base MAC address is not set
I (1324) system_api: read default base MAC address from EFUSE
I (1324) wifi:wifi firmware version: 88c8747
I (1334) wifi:wifi certification version: v7.0
I (1334) wifi:config NVS flash: enabled
I (1334) wifi:config nano formating: disabled
I (1344) wifi:Init data frame dynamic rx buffer num: 40
I (1344) wifi:Init management frame dynamic rx buffer num: 40
I (1354) wifi:Init management short buffer num: 32
I (1354) wifi:Init static tx buffer num: 12
I (1364) wifi:Init tx cache buffer num: 32
I (1364) wifi:Init static rx buffer size: 1600
I (1364) wifi:Init static rx buffer num: 12
I (1374) wifi:Init dynamic rx buffer num: 40
I (1374) wifi_init: tcpip mbox: 32
I (1384) wifi_init: udp mbox: 32
I (1384) wifi_init: tcp mbox: 32
I (1384) wifi_init: tcp tx win: 8192
I (1394) wifi_init: tcp rx win: 32768
I (1394) wifi_init: tcp mss: 1440
I (1404) wifi_init: WiFi IRAM OP enabled
I (1404) example_connect: Connecting to shafer...
I (1414) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1504) wifi:mode : sta (34:ab:95:73:3f:d4)
I (1504) wifi:enable tsf
I (1504) example_connect: Waiting for IP(s)
I (3544) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1
I (4194) wifi:state: init -> auth (b0)
I (4204) wifi:state: auth -> assoc (0)
I (4204) wifi:state: assoc -> run (10)
I (4214) wifi:connected with shafer, aid = 1, channel 11, BW20, bssid = d6:2c:55:7d:89:15
I (4214) wifi:security: WPA2-PSK, phy: bgn, rssi: -39
I (4224) wifi:pm start, type: 1

I (4404) wifi:AP's beacon interval = 307200 us, DTIM period = 3
I (4814) esp_netif_handlers: example_connect: sta ip: 192.168.2.3, mask: 255.255.255.0, gw: 192.168.2.1
I (4814) example_connect: Got IPv4 event: Interface "example_connect: sta" address: 192.168.2.3
I (5314) example_connect: Got IPv6 event: Interface "example_connect: sta" address: fe80:0000:0000:0000:36ab:95ff:fe73:3fd4, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5314) example_connect: Connected to example_connect: sta
I (5324) example_connect: - IPv4 address: 192.168.2.3
I (5324) example_connect: - IPv6 address: fe80:0000:0000:0000:36ab:95ff:fe73:3fd4, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5334) TAG: Connected to AP, start spotify receiver
D Session.cpp:27: Connecting with AP <guc3-accesspoint-a-404s.ap.spotify.com:4070>
D PlainConnection.cpp:67: Connected to spotify server
D Session.cpp:30: Sending APHello packet...
D Session.cpp:80: Processing AP hello response...
D Session.cpp:82: Received AP hello response
D Session.cpp:123: Received shannon keys
D Session.cpp:59: Authorization successful
D MercuryManager.cpp:170: Got ping, syncing timestamp
W (5844) AC101: No AC101 detected
E (5844) i2c: i2c_master_cmd_begin(1166): i2c driver not installed
E (5854) i2c: i2c_master_cmd_begin(1166): i2c driver not installed
E (5854) i2c: i2c_master_cmd_begin(1166): i2c driver not installed
E (5864) i2c: i2c_master_cmd_begin(1166): i2c driver not installed
E (5874) i2c: i2c_master_cmd_begin(1166): i2c driver not installed
E (5874) i2c: i2c_master_cmd_begin(1166): i2c driver not installed
D MercuryManager.cpp:283: executing MercuryType SUB
D MercuryManager.cpp:204: Received packet with code 2 of length 336
D MercuryManager.cpp:204: Received packet with code 118 of length 2
D MercuryManager.cpp:204: Received packet with code 27 of length 2
D MercuryManager.cpp:211: Received country code: US
D MercuryManager.cpp:204: Received packet with code 80 of length 6107
D MercuryManager.cpp:204: Received packet with code 105 of length 0
D MercuryManager.cpp:204: Received packet with code 31 of length 17
D MercuryManager.cpp:204: Received packet with code 74 of length 4
D MercuryManager.cpp:204: Received packet with code 179 of length 50
D MercuryManager.cpp:283: executing MercuryType SEND
D SpircController.cpp:29: Sent kMessageTypeHello!
D MercuryManager.cpp:204: Received packet with code 178 of length 50
D MercuryManager.cpp:204: Received packet with code 181 of length 489
D SpircController.cpp:46: Notify frame
D MercuryManager.cpp:204: Received packet with code 181 of length 489
D SpircController.cpp:46: Notify frame
D MercuryManager.cpp:204: Received packet with code 181 of length 2269
D SpircController.cpp:101: Load frame!
I PlayerState.cpp:114: ---- Track count 81
D MercuryManager.cpp:283: executing MercuryType GET
D MercuryManager.cpp:283: executing MercuryType SEND
D MercuryManager.cpp:204: Received packet with code 178 of length 1044
D MercuryManager.cpp:242:  MercuryType::UNSUB response->parts[0].size() = 813
I SpotifyTrack.cpp:76: Track name: Dog Years
D SpotifyTrack.cpp:87: trackInfo.restriction.size() = 1
D MercuryManager.cpp:204: Received packet with code 178 of length 50
D MercuryManager.cpp:204: Received packet with code 13 of length 20
I SpotifyTrack.cpp:142: Successfully got audio key!
D AudioChunkManager.cpp:15: Chunk requested 0
D AudioChunkManager.cpp:80: ID: 0: header decrypt!
D AudioChunkManager.cpp:15: Chunk requested 1
D AudioChunkManager.cpp:92: ID: 0: Starting decrypt!
D AudioChunkManager.cpp:80: ID: 1: header decrypt!
D AudioChunkManager.cpp:92: ID: 1: Starting decrypt!
D MercuryManager.cpp:283: executing MercuryType SEND
D ChunkedAudioStream.cpp:320: Change in current chunk 0
D AudioChunkManager.cpp:15: Chunk requested 2
D ChunkedAudioStream.cpp:320: Change in current chunk 81
D ChunkedAudioStream.cpp:320: Change in current chunk 81
D ChunkedAudioStream.cpp:201: EOL!
D ChunkedAudioStream.cpp:201: EOL!
D ChunkedAudioStream.cpp:320: Change in current chunk 81
D ChunkedAudioStream.cpp:201: EOL!
D ChunkedAudioStream.cpp:320: Change in current chunk 81
D ChunkedAudioStream.cpp:201: EOL!
D ChunkedAudioStream.cpp:320: Change in current chunk 81
D ChunkedAudioStream.cpp:201: EOL!
D MercuryManager.cpp:204: Received packet with code 178 of length 50
D ChunkedAudioStream.cpp:201: EOL!
D ChunkedAudioStream.cpp:320: Change in current chunk 0
D ChunkedAudioStream.cpp:320: Change in current chunk 81
D ChunkedAudioStream.cpp:320: Change in current chunk 81
D ChunkedAudioStream.cpp:320: Change in current chunk 81
D ChunkedAudioStream.cpp:201: EOL!
D ChunkedAudioStream.cpp:320: Change in current chunk 0
D AudioChunkManager.cpp:80: ID: 2: header decrypt!
D ChunkedAudioStream.cpp:86: --- Loaded file
D AudioChunkManager.cpp:15: Chunk requested 3
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:231: Waiting for chunk to load
D AudioChunkManager.cpp:92: ID: 2: Starting decrypt!
D AudioChunkManager.cpp:80: ID: 3: header decrypt!
D AudioChunkManager.cpp:92: ID: 3: Starting decrypt!
D ChunkedAudioStream.cpp:242: Actual request 19
D ChunkedAudioStream.cpp:326: Chunk Req 19
D AudioChunkManager.cpp:15: Chunk requested 4
D ChunkedAudioStream.cpp:231: Waiting for chunk to load
D AudioChunkManager.cpp:80: ID: 4: header decrypt!
D AudioChunkManager.cpp:92: ID: 4: Starting decrypt!
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D ChunkedAudioStream.cpp:320: Change in current chunk 19
D MercuryManager.cpp:204: Received packet with code 181 of length 2269
D MercuryManager.cpp:283: executing MercuryType SEND
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.

Core  1 register dump:
PC      : 0x400fe76e  PS      : 0x00060930  A0      : 0x800d3ebc  A1      : 0x3ffcebe0
A2      : 0x00000000  A3      : 0x000000b0  A4      : 0x3ffc4e88  A5      : 0x3ffcec20
A6      : 0xffffffff  A7      : 0x00000000  A8      : 0x3ffc4e88  A9      : 0x3ffceb90
A10     : 0x00000001  A11     : 0x3ffcebf4  A12     : 0x00000000  A13     : 0x3ffb4b00
A14     : 0x3ffb4aac  A15     : 0x00000001  SAR     : 0x00000000  EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000018  LBEG    : 0x00000000  LEND    : 0x00000000  LCOUNT  : 0x00000000

Backtrace:0x400fe76b:0x3ffcebe0 0x400d3eb9:0x3ffcec20

ELF file SHA256: b0b475de610b6221

Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_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:7520
load:0x40078000,len:15468
load:0x40080400,len:4472
entry 0x400806a0
I (27) boot: ESP-IDF 4.3.1 2nd stage bootloader

When I try with the INTERNAL sink, I don't get a crash, but of course I get no sound from the board. I think the issue is that it's attempting to send audio data to an I2C device or driver that doesn't exist. Is this a hardware issue? Or am I not including the correct drivers for the AC101 codec on this module? I built from the 8c726008 commit, I only changed the SSID/Password, and built with pio run -t upload

Any ideas?

Timvrakas commented 3 years ago

Some more info: I ran an I2C scan and got the following:

     0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
00:          -- -- -- -- -- -- -- -- -- -- -- -- --
10: 10 -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
20: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
30: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
40: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
50: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
60: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
70: -- -- -- -- -- -- -- --

With SCL=32, SDA=33 I think is is a problem, because the address should be 0x1A, not 0x10.

Timvrakas commented 3 years ago

I de-lidded the module, and found within an ES8388: http://www.everest-semi.com/pdf/ES8388%20DS.pdf I will try to get this chip working, or order a compatible DAC.

feelfreelinux commented 3 years ago

I de-lidded the module, and found within an ES8388: http://www.everest-semi.com/pdf/ES8388%20DS.pdf I will try to get this chip working, or order a compatible DAC.

Thanks a lot for this info! Didn't know they sold them with a different chip. Could you send me a link to where you ordered that devboard?

Timvrakas commented 3 years ago

https://www.amazon.com/dp/B08PP93J6J This is the main reference for the board: https://github.com/Ai-Thinker-Open/ESP32-A1S-AudioKit Apparently the AC101 version is "status:halt production" The E28388 has support through https://github.com/espressif/esp-adf, so it should be possible to get working. However, in de-lidding I managed to knock off a few passives... I'll try repairing it this weekend.

Timvrakas commented 3 years ago

IMG_2310 I repaired my module (I think), but I can't get any audio out of it, from cspot or from the hacked together esp-adf system. Whenever I play audio I get clicking out of the port. Something is alive, but definitely amiss. I'm this is my first time with I2S / digital audio so I'm still figuring it out. I'll get back to cspot once I have some known-good hardware.

Timvrakas commented 3 years ago

Closing this. The lesson learned it that the Ai-Thinker hardware is a somewhat like rolling the dice, sometimes it works and sometimes they've changed it and even the provided examples don't produce any audio. I ordered a LyraT-Mini V2.1, which at least has a working demo.