search

esphome / issues

Issue Tracker for ESPHome
https://esphome.io/
290 stars 36 forks source link

Conflict between I2S Media Player and ILI9341 display #3421

Open jamesmyatt opened 2 years ago

jamesmyatt commented 2 years ago

The problem

When using both the I2S media player and ILI9341 display, then the media player is unable to play anything. Specifically, playing media just stops immediately (see logs). The display is working fine.

Changing the display to a different driver, e.g. ssd1306_i2c, also works fine. So it's definitely an interaction between these two specific components.

Which version of ESPHome has the issue?

2022.6.2

What type of installation are you using?

pip

Which version of Home Assistant has the issue?

2022.6.?

What platform are you using?

ESP32

Board

ESP32 WROOM devkit

Component causing the issue

i2s_audio and ili9341

Example YAML snippet

time:
  - platform: homeassistant
    id: esptime
    timezone: !secret timezone

# SPI bus
spi:
  clk_pin: 18
  mosi_pin: 23
  miso_pin: 19

# Display
font:
  - file: "gfonts://Bebas Neue@regular"
    id: font2
    size: 110
  - file: "gfonts://Ubuntu Condensed@regular"
    id: font3
    size: 24

color:
  - id: color_time
    red: 80%
    green: 90%
    blue: 100%
    white: 0%

display:
  - platform: ili9341
    model: TFT 2.4
    cs_pin: 5
    dc_pin: 16
    led_pin: 17
    reset_pin: 4
    rotation: 270°
    update_interval: 1s

    lambda: |-
      it.fill(Color::BLACK);

      // Print time in HH:MM format
      it.strftime(0, 200, id(font2), id(color_time), TextAlign::BASELINE_LEFT, "%H:%M", id(esptime).now());
      it.strftime(0, 230, id(font3), id(color_time), TextAlign::BASELINE_LEFT, "%A, %d %B %Y", id(esptime).now());

# Media player
media_player:
  - platform: i2s_audio
    name: "${devicename} Media Player"
    dac_type: external
    i2s_lrclk_pin: 33
    i2s_dout_pin: 26
    i2s_bclk_pin: 25
    mode: mono
    on_play:
      - logger.log: "Playback started!"
    on_pause:
      - logger.log: "Playback paused!"
    on_idle:
      - logger.log: "Playback finished!"

Anything in the logs that might be useful for us?

[22:14:19][D][media_player:059]: 'eh-a9a730 Media Player' - Setting
[22:14:19][D][media_player:066]:   Media URL: http://192.168.1.6:8123/api/tts_proxy/303f39ed1f3700e1a17bd25528ae64c88b65f991_en_-_google_translate.mp3
[22:14:19][D][main:415]: Playback started!
[22:14:19][D][main:409]: Playback finished!

Additional information

No response

nielsnl68 commented 2 years ago

I will check this out soon. In the main time could you update your script with the whole script (except the passwords etc.) then i can compare with my results later.

jamesmyatt commented 2 years ago

Thanks @nielsnl68. I'll do this either tonight or tomorrow.

jamesmyatt commented 2 years ago

I've uploaded some configs to https://gist.github.com/jamesmyatt/39d0bd0d057110193d3a2e6b297869f6

These results are now using ESPHome 2022.9.1. I'll do some more digging. I don't think it's the ADC or Neopixel, but I need to be more systematic.

jamesmyatt commented 2 years ago

OK I've added a reduced.yaml which is a simplified version that's also not working. And cutting it down more does get it to work, so my suspicion is that it's actually a RAM issue.

jamesmyatt commented 2 years ago

@nielsnl68 Did you get a chance to look at this?

nielsnl68 commented 2 years ago

Sorry @jamesmyatt, i was not sure of this was still needed.

Now i have just tried it with my espMuze Proto media-player and it still works. The only thing is that it does not have a real display on it but it should have the same effect as with a display.

jamesmyatt commented 2 years ago

Could the difference be the PSRAM? I'm using an ESP32 D1 mini clone, so it's using a WROOM module, while the espMuse uses the WROVER module.

Whether the display is attached or not shouldn't change anything.

nielsnl68 commented 2 years ago

Also with my M5Atom Echo works still with the display running.

laenbdarceq commented 2 years ago

I can see the same exact problem with the very minimal configuration here below. The board I am using is this one : https://joy-it.net/en/products/SBC-NodeMCU-ESP32 (512kB SRAM, 4MB flash).

The display is 320x240 pixel and is used in grayscale mode, so the buffer should be around 75kB. esphome tells me it is using 43kB (out of 320kB available). So there should still be around 200kB available for the stream (128 kbps) buffering and other variables. Is there any big RAM user I miss here, or is it actually not a RAM issue ? 

esphome:
  name: sandbox
  platform: ESP32
  board: nodemcu-32s

logger:

api:
  password: !secret api_password

ota:
  password: !secret ota_password

wifi:
  ssid: !secret wifi_ssid
  password: !secret wifi_password

button:
  - platform: template
    id: start_audio
    name: "Start Audio"
    on_press:
      - logger.log: "Start Button Pressed"
      - media_player.volume_set:
          id: i2splayer
          volume: 0%
      - media_player.play_media:
          id: i2splayer
          media_url: !secret media_url
  - platform: template
    id: stop_audio
    name: "Stop Audio"
    on_press:
      - logger.log: "Stop Button Pressed"
      - media_player.stop:
          id: i2splayer

media_player:
  platform: i2s_audio
  name: ESPHome I2S Media Player
  id: i2splayer
  dac_type: external
  i2s_lrclk_pin: GPIO23
  i2s_dout_pin: GPIO22
  i2s_bclk_pin: GPIO21
  mode: mono
  on_play:
    then:
      # - light.turn_on: board_light
      - logger.log: "Playback started"
  on_idle:
    then:
      # - light.turn_off: board_light
      - logger.log: "Idle"
  on_pause:
    then:
      # - light.turn_off: board_light
      - logger.log: "Paused"

spi:
  clk_pin: GPIO14
  mosi_pin: GPIO13
  miso_pin: GPIO12

display:
  - platform: ili9341
    model: TFT 2.4
    cs_pin: 27
    dc_pin: 26
    led_pin: 25  ### see note below ###
    reset_pin: 33
    rotation: 270°
    color_palette: GRAYSCALE
    lambda: |-
      it.fill(Color::BLACK);
laenbdarceq commented 2 years ago

A little bit more information : I hooked up to the audio_info function from ESP32- audioI2S which allows to get some logs about what the library is doing. Here is what I get : 

[17:50:49][D][button:013]: 'Start Audio' Pressed.
[17:50:49][D][main:230]: Start Button Pressed
[17:50:49][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[17:50:49][D][media_player:069]:   Volume: 0.00
[17:50:49][D][main:310]: Idle
[17:50:49][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[17:50:49][D][media_player:066]:   Media URL: http://radios.rtbf.be/classic21-128.mp3
[17:50:49][D][main:107]: audio_info: PSRAM not found, inputBufferSize: 6399 bytes
[17:50:49][D][main:107]: audio_info: buffers freed, free Heap: 115360 bytes
[17:50:49][D][main:107]: audio_info: Connect to new host: "http://radios.rtbf.be/classic21-128.mp3"
[17:50:49][D][main:107]: audio_info: Connect to "radios.rtbf.be" on port 80, extension "/classic21-128.mp3"
[17:50:49][D][main:107]: audio_info: Connection has been established in 74 ms, free Heap: 123208 bytes
[17:50:49][D][main:316]: Playback started
[17:50:49][D][main:107]: audio_info: HTTP/1.1 302 redirect
[17:50:49][D][main:107]: audio_info: content-length: 0
[17:50:49][D][main:107]: audio_info: server: Varnish
[17:50:49][D][main:107]: audio_info: retry-after: 0
[17:50:49][D][main:107]: audio_info: redirect to new host "https://radio.rtbf.be/c21/mp3-160/rv"
[17:50:49][D][main:107]: audio_info: buffers freed, free Heap: 113696 bytes
[17:50:49][D][main:107]: audio_info: Connect to new host: "https://radio.rtbf.be/c21/mp3-160/rv"
[17:50:49][D][main:107]: audio_info: Connect to "radio.rtbf.be" on port 443, extension "/c21/mp3-160/rv"
[17:50:51][D][main:107]: audio_info: SSL has been established in 1402 ms, free Heap: 82496 bytes
[17:50:51][D][main:107]: audio_info: HTTP/1.0 302 Found
[17:50:51][D][main:107]: audio_info: access-control-allow-origin: *
[17:50:51][D][main:107]: audio_info: content-type: audio/mpeg, format is mp3
[17:50:51][D][main:310]: Idle
nielsnl68 commented 2 years ago

i see a couple of HTTP/1.0 302 Found errors. <= mening that the content that was first at the given url is moved to an other url.

I get https://redbeemedia.streamabc.net/redbm-classic21-mp3-160-3491794?sABC=6359620q%230%234s1212noo68488so76p75r32so3n3r02%23ei&aw_0_1st.playerid=rv&amsparams=playerid:rv;skey:1666802189 when i open https://radio.rtbf.be/c21/mp3-160/rv in my browser.

Could you try with an other stream or use TTS to send a spoken words to your device.

laenbdarceq commented 2 years ago

Yes I can. It actually brings some interesting cases (see logs below):

  1. Stream http://radios.rtbf.be/classic21-128.mp3 with spi and display : NOK
    • Note that this stream involves a 302 REDIRECT to an https stream
    • Also note that, when connected through USB to the board, I get an interesting [E][mp3_decoder.cpp:1555] MP3Decoder_AllocateBuffers(): not enough memory to allocate mp3decoder buffers error
  2. Stream http://mp3.ffh.de/radioffh/hqlivestream.mp3 with spi and display : OK
  3. Stream http://radios.rtbf.be/classic21-128.mp3 without spi and display : OK

Does that make any sense ?

Logs for 1. :

[22:18:55][D][api:102]: Accepted ::FFFF:C0A8:C90A
[22:18:55][D][api.connection:917]: Home Assistant 2022.10.5 (::FFFF:C0A8:C90A): Connected successfully
[22:19:04][D][button:013]: 'Start Audio' Pressed.
[22:19:04][D][main:230]: Start Button Pressed
[22:19:04][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[22:19:04][D][media_player:069]:   Volume: 0.00
[22:19:04][D][main:310]: Idle
[22:19:04][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[22:19:04][D][media_player:066]:   Media URL: http://radios.rtbf.be/classic21-128.mp3
[22:19:04][D][main:107]: audio_info: PSRAM not found, inputBufferSize: 6399 bytes
[22:19:04][D][main:107]: audio_info: buffers freed, free Heap: 130660 bytes
[22:19:04][D][main:107]: audio_info: Connect to new host: "http://radios.rtbf.be/classic21-128.mp3"
[22:19:04][D][main:107]: audio_info: Connect to "radios.rtbf.be" on port 80, extension "/classic21-128.mp3"
[22:19:04][D][main:107]: audio_info: Connection has been established in 61 ms, free Heap: 127996 bytes
[22:19:04][D][main:316]: Playback started
[22:19:04][D][main:107]: audio_info: HTTP/1.1 302 redirect
[22:19:04][D][main:107]: audio_info: content-length: 0
[22:19:04][D][main:107]: audio_info: server: Varnish
[22:19:04][D][main:107]: audio_info: retry-after: 0
[22:19:04][D][main:107]: audio_info: redirect to new host "https://radio.rtbf.be/c21/mp3-160/rv"
[22:19:04][D][main:107]: audio_info: buffers freed, free Heap: 130336 bytes
[22:19:05][D][main:107]: audio_info: Connect to new host: "https://radio.rtbf.be/c21/mp3-160/rv"
[22:19:05][D][main:107]: audio_info: Connect to "radio.rtbf.be" on port 443, extension "/c21/mp3-160/rv"
[22:19:06][D][main:107]: audio_info: SSL has been established in 1605 ms, free Heap: 83780 bytes
[22:19:06][D][main:107]: audio_info: HTTP/1.0 302 Found
[22:19:06][D][main:107]: audio_info: access-control-allow-origin: *
[22:19:06][D][main:107]: audio_info: content-type: audio/mpeg, format is mp3
[22:19:06][E][mp3_decoder.cpp:1555] MP3Decoder_AllocateBuffers(): not enough memory to allocate mp3decoder buffers
[22:19:06][D][main:310]: Idle

Logs for 2.: 

[22:21:52][D][api:102]: Accepted ::FFFF:C0A8:C90A
[22:21:52][D][api.connection:917]: Home Assistant 2022.10.5 (::FFFF:C0A8:C90A): Connected successfully
[22:21:56][D][button:013]: 'Start Audio' Pressed.
[22:21:56][D][main:230]: Start Button Pressed
[22:21:56][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[22:21:56][D][media_player:069]:   Volume: 0.00
[22:21:56][D][main:310]: Idle
[22:21:56][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[22:21:56][D][media_player:066]:   Media URL: http://mp3.ffh.de/radioffh/hqlivestream.mp3
[22:21:56][D][main:107]: audio_info: PSRAM not found, inputBufferSize: 6399 bytes
[22:21:56][D][main:107]: audio_info: buffers freed, free Heap: 130680 bytes
[22:21:56][D][main:107]: audio_info: Connect to new host: "http://mp3.ffh.de/radioffh/hqlivestream.mp3"
[22:21:56][D][main:107]: audio_info: Connect to "mp3.ffh.de" on port 80, extension "/radioffh/hqlivestream.mp3"
[22:21:56][D][main:107]: audio_info: Connection has been established in 85 ms, free Heap: 128000 bytes
[22:21:56][D][main:316]: Playback started
[22:21:57][D][main:107]: audio_info: HTTP/1.0 200 OK
[22:21:57][D][main:107]: audio_info: icy-audio-info: ice-samplerate=44100;ice-bitrate=128;ice-channels=2
[22:21:57][D][main:107]: audio_info: icy-name: HIT RADIO FFH
[22:21:57][D][main:107]: audio_info: content-type: audio/mpeg, format is mp3
[22:21:57][D][main:107]: audio_info: MP3Decoder has been initialized, free Heap: 105416 bytes
[22:21:57][D][main:107]: audio_info: instance-id: c28334c2aa877de0022778b0e3bd2169
[22:21:57][D][main:107]: audio_info: server: AIS Streaming Server 9.0.6
[22:21:57][D][main:107]: audio_info: Switch to DATA, metaint is 16000
[22:21:58][D][main:107]: audio_info: stream ready
[22:21:58][D][main:107]: audio_info: buffer filled in 261 ms
[22:21:58][D][main:107]: audio_info: syncword found at pos 0
[22:21:58][D][main:107]: audio_info: Channels: 2
[22:21:58][D][main:107]: audio_info: SampleRate: 44100
[22:21:58][D][main:107]: audio_info: BitsPerSample: 16
[22:21:58][D][main:107]: audio_info: BitRate: 128000
[22:21:58][D][main:107]: audio_info: StreamTitle=''
[22:21:58][D][main:107]: audio_info: durationMilliseconds='10083'
[22:22:08][D][main:107]: audio_info: StreamTitle='Glockenbach feat. ClockClock - Brooklyn'

Logs for 3.:

[21:46:56][D][button:013]: 'Start Audio' Pressed.
[21:46:56][D][main:168]: Start Button Pressed
[21:46:56][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[21:46:56][D][media_player:069]:   Volume: 0.00
[21:46:56][D][main:248]: Idle
[21:46:56][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[21:46:56][D][media_player:066]:   Media URL: http://radios.rtbf.be/classic21-128.mp3
[21:46:56][D][main:284]: audio_info: PSRAM not found, inputBufferSize: 6399 bytes
[21:46:56][D][main:284]: audio_info: buffers freed, free Heap: 182492 bytes
[21:46:56][D][main:284]: audio_info: Connect to "radio.rtbf.be" on port 443, extension "/c21/mp3-160/rv"
[21:46:57][D][main:284]: audio_info: SSL has been established in 1146 ms, free Heap: 157476 bytes
[21:46:57][D][main:284]: audio_info: HTTP/1.0 302 Found
[21:46:57][D][main:284]: audio_info: access-control-allow-origin: *
[21:46:57][D][main:284]: audio_info: content-type: audio/mpeg, format is mp3
[21:46:57][D][main:284]: audio_info: MP3Decoder has been initialized, free Heap: 129920 bytes
[21:46:57][D][main:284]: audio_info: redirect to new host "https://redbeemedia.streamabc.net/redbm-classic21-mp3-160-3491794?sABC=63598ro1%230%23qn7ss965snn4q1q72n03n1791n787n06%23ei&aw_0_1st.playerid=rv&amsparams=playerid:rv;skey:1666813617"
[21:46:57][D][main:284]: audio_info: buffers freed, free Heap: 203576 bytes
[21:46:57][D][main:284]: audio_info: Connect to new host: "https://redbeemedia.streamabc.net/redbm-classic21-mp3-160-3491794?sABC=63598ro1%230%23qn7ss965snn4q1q72n03n1791n787n06%23ei&aw_0_1st.playerid=rv&amsparams=playerid:rv;skey:1666813617"
[21:46:57][D][main:284]: audio_info: Connect to "redbeemedia.streamabc.net" on port 443, extension "/redbm-classic21-mp3-160-3491794?sABC=63598ro1%230%23qn7ss965snn4q1q72n03n1791n787n06%23ei&aw_0_1st.playerid=rv&amsparams=playerid:rv;skey:1666813617"
[21:46:59][D][main:284]: audio_info: SSL has been established in 1886 ms, free Heap: 164316 bytes
[21:47:00][D][main:284]: audio_info: HTTP/1.0 200 OK
[21:47:00][D][main:284]: audio_info: access-control-allow-headers: Origin, Accept, X-Requested-With, Content-Type, Icy-MetaData
[21:47:00][D][main:284]: audio_info: access-control-allow-methods: GET, OPTIONS, SOURCE, PUT, HEAD, STATS
[21:47:00][D][main:284]: audio_info: access-control-allow-origin: *
[21:47:00][D][main:284]: audio_info: content-type: audio/mpeg, format is mp3
[21:47:00][D][main:284]: audio_info: MP3Decoder has been initialized, free Heap: 122640 bytes
[21:47:00][D][main:284]: audio_info: date: Wed, 26 Oct 2022 19:46:59 UTC
[21:47:00][D][main:284]: audio_info: server: QuantumCast Streamer (Version  SHA:9adbc312e56fcacc69a7ae5b0ff0427d40bd9fec 22.09.17 18:17:39)
[21:47:00][D][main:284]: audio_info: vary: Origin
[21:47:00][D][main:284]: audio_info: x-quantumcast-listener: da7ff965faa4d1d72a03a1791a787a06
[21:47:00][D][main:284]: audio_info: x-quantumcast-session: cdcotcuc64cs72ra7jrg
[21:47:00][D][main:284]: audio_info: ice-audio-info: samplerate=44100;bitrate=160;channels=2
[21:47:00][D][main:284]: audio_info: icy-name: Classic21
[21:47:00][D][main:284]: audio_info: Switch to DATA, metaint is 8192
[21:47:00][D][main:284]: audio_info: stream ready
[21:47:00][D][main:284]: audio_info: buffer filled in 6 ms
[21:47:00][D][main:284]: audio_info: syncword found at pos 0
[21:47:00][D][main:284]: audio_info: MP3 decode error -2 : MAINDATA_UNDERFLOW
[21:47:00][D][main:284]: audio_info: syncword found at pos 0
[21:47:00][D][main:284]: audio_info: Channels: 2
[21:47:00][D][main:284]: audio_info: SampleRate: 44100
[21:47:00][D][main:284]: audio_info: BitsPerSample: 16
[21:47:00][D][main:284]: audio_info: BitRate: 160000
[21:47:00][D][main:284]: audio_info: StreamTitle='Classic21'
[21:47:04][D][main:284]: audio_info: StreamTitle='STANFORDS - WEIGHTLESS WAITRESS'
[21:47:12][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[21:47:12][D][media_player:069]:   Volume: 0.35
[21:47:12][D][main:254]: Playback started
[21:47:13][D][media_player:059]: 'ESPHome I2S Media Player' - Setting
[21:47:13][D][media_player:069]:   Volume: 0.00
[21:47:13][D][main:254]: Playback started
[21:51:34][I][ota:109]: Boot seems successful, resetting boot loop counter.
[21:51:34][D][esp32.preferences:113]: Saving 1 preferences to flash...
[21:51:34][D][esp32.preferences:142]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[21:52:18][D][main:284]: audio_info: StreamTitle='JANE DOE - BIG BAM BOUM'
[21:53:51][D][main:284]: audio_info: slow stream, dropouts are possible
jamesmyatt commented 2 years ago

How do you enable the audio info?

laenbdarceq commented 2 years ago

How do you enable the audio info?

In your main.cpp, after the // =========== AUTO GENERATED CODE END ============ line (and out of the setup() function), just add:

void audio_info(const char *info){
    ESP_LOGD("main", "audio_info: %s", info);
}
laenbdarceq commented 2 years ago

By the way, searching on "MP3Decoder_AllocateBuffers(): not enough memory to allocate mp3decoder buffers" led me to this issue : https://github.com/schreibfaul1/ESP32-audioI2S/issues/126 . So I believe it is definitely a problem of not enough RAM, which is worsened by the SSL connection. Probably not an actual interaction with the ILI9341 component, but caused by the number of pixels of that display and the size of its buffer which is hugging the RAM.

I have to check if my board has PSRAM and if so, how to enable it. Following the ESP32-audioI2S issue it could possibly resolve this issue.

jamesmyatt commented 2 years ago

PSRAM is mostly found on ESP32-WROVER or ESP32-A1S modules. ESP32-WROOM and ESP32-S modules don't have PSRAM. For custom boards, you have to check.

Your ESP32 NodeMCU uses the WROOM module, so it won't have PSRAM.

laenbdarceq commented 1 year ago

Hi again, I'm not sure it is the right place to ask this question, so please redirect me if it is not. I now have an ESP32-WROVER board (this one : https://www.upesy.com/products/upesy-esp32-wrover-devkit-board), but I still get a "PSRAM" not found. I used board: esp-wrover-kit . Is there anything else I should change to enable the PSRAM to be used by the esp32-audioI2S library ?