OutputStream only starts after 60 seconds =30x1024 bytes

[SiWoC]

I have a Sunton board which has an ESP32-S3 and a DAC (and a touchscreen, but that's not in play yet).
I have started with the streams-sd_mp3-i2s sample and introduced a VolumeStream to decrease the volume, other than that and the pin-config it's basically unchanged, so now I have this.

#include "board_settings.h"

#include "AudioTools.h"

#include <SPI.h>
#include <SD.h>
#include "AudioTools.h"
#include "AudioCodecs/CodecMP3Helix.h"

AudioInfo info(44100,2,16);
I2SStream i2s_out; // final output of decoded stream
VolumeStream vol(i2s_out); // VolumeStream is doing it's thing "over" the i2s_out output stream
EncodedAudioStream decoder(&vol, new MP3DecoderHelix()); // Decoding mp3 to the volume-stream
StreamCopy copier;
File audioFile;

void setup(){
  Serial.begin(115200);
  AudioLogger::instance().begin(Serial, AudioLogger::Info);  

  // Open file from SD
  SD.begin(SD_CS);
  audioFile = SD.open("/TheGame.mp3");

  // setup I2S based on sampling rate provided by decoder
  auto config = i2s_out.defaultConfig(TX_MODE);
  config.copyFrom(info);
  config.pin_bck = I2S_BCLK;
  config.pin_ws = I2S_LRC;
  config.pin_data = I2S_DOUT;
  i2s_out.begin(config);

  // setup volume
  vol.begin(config);
  vol.setVolume(0.5);  // half the volume

  // add volumeStream as subscriber to decoder.AudioChange
  // don't know if/why this is needed
  // decoder.setNotifyAudioChange(vol);
  decoder.begin();

  // begin copy
  copier.begin(decoder, audioFile);

}

void loop(){
  copier.copy();
}

The sound is being played over the DAC, but it starts only after 60 seconds, after the copier has copied 30 buffers of 1K
I have tried with and without the decoder.setNotifyAudioChange(vol) line, but no change either way

[I] StreamCopy.h : 143 - StreamCopy::copy 1024 -> 1024 -> 1024 bytes - in 1 hops

When I put the logging on Debug I can see MP3DecoderHelix::infoCallback only firing after the 30x1024 and only then something is going to the VolumeStream

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3808,len:0x44c
load:0x403c9700,len:0xbe4
load:0x403cc700,len:0x2a68
entry 0x403c98d4
[D] I2SStream.h : 60 - bool audio_tools::I2SStream::begin(audio_tools::I2SConfig)
[D] I2SESP32.h : 47 - bool audio_tools::I2SDriverESP32::begin(audio_tools::I2SConfigESP32)
[D] I2SESP32.h : 152 - bool audio_tools::I2SDriverESP32::begin(audio_tools::I2SConfigESP32, int, int)
[I] AudioTypes.h : 104 - sample_rate: 44100
[I] AudioTypes.h : 105 - channels: 2
[I] AudioTypes.h : 106 - bits_per_sample: 16
[I] I2SConfigESP32.h : 90 - rx/tx mode: TX_MODE
[I] I2SConfigESP32.h : 91 - port_no: 0
[I] I2SConfigESP32.h : 92 - is_master: Master
[I] I2SConfigESP32.h : 93 - sample rate: 44100
[I] I2SConfigESP32.h : 94 - bits per sample: 16
[I] I2SConfigESP32.h : 95 - number of channels: 2
[I] I2SConfigESP32.h : 96 - signal_type: Digital
[I] I2SConfigESP32.h : 98 - i2s_format: I2S_STD_FORMAT
[I] I2SConfigESP32.h : 100 - auto_clear: true
[I] I2SConfigESP32.h : 102 - use_apll: true
[I] I2SConfigESP32.h : 107 - buffer_count:6
[I] I2SConfigESP32.h : 108 - buffer_size:512
[I] I2SConfigESP32.h : 113 - pin_bck: 0
[I] I2SConfigESP32.h : 115 - pin_ws: 18
[I] I2SConfigESP32.h : 117 - pin_data: 17
[D] I2SESP32.h : 184 - i2s_driver_install
[D] I2SESP32.h : 201 - i2s_set_pin
[D] I2SESP32.h : 212 - i2s_zero_dma_buffer
[D] I2SESP32.h : 216 - begin - started
[D] VolumeStream.h : 99 - bool audio_tools::VolumeStream::begin(audio_tools::VolumeStreamConfig)
[I] VolumeStream.h : 198 - setVolume: 1.000000
[I] VolumeStream.h : 198 - setVolume: 1.000000
[I] VolumeStream.h : 198 - setVolume: 0.300000
[I] VolumeStream.h : 198 - setVolume: 0.300000
[I] AudioEncoded.h : 269 - virtual void audio_tools::EncodedAudioOutput::setNotifyAudioChange(audio_tools::AudioInfoSupport&)
[D] CodecMP3Helix.h : 122 - virtual void audio_tools::MP3DecoderHelix::setNotifyAudioChange(audio_tools::AudioInfoSupport&)
[D] AudioEncoded.h : 329 - virtual bool audio_tools::EncodedAudioOutput::begin()
[D] AudioEncoded.h : 331 - virtual bool audio_tools::EncodedAudioOutput::begin()
[D] AudioEncoded.h : 28 - virtual void audio_tools::AudioDecoder::setAudioInfo(audio_tools::AudioInfo)
[D] CodecMP3Helix.h : 77 - virtual void audio_tools::MP3DecoderHelix::begin()
[D] MetaDataFilter.h : 30 - void audio_tools::MetaDataFilter<Decoder>::begin() [with Decoder = libhelix::MP3DecoderHelix]
[D] AudioStreams.h : 163 - audio_tools::AudioStreamWrapper::AudioStreamWrapper(Stream&)
[I] StreamCopy.h : 74 - buffer_size=1024
[D] StreamCopy.h : 97 - copy 
[D] StreamCopy.h : 177 - available: 5085722
[D] StreamCopy.h : 332 - write: 1024
[D] AudioEncoded.h : 366 - EncodedAudioOutput::write: 1024
......................30x 1024 bytes
[D] StreamCopy.h : 332 - write: 1024
[D] AudioEncoded.h : 366 - EncodedAudioOutput::write: 1024
[D] CodecMP3Helix.h : 106 - virtual size_t audio_tools::MP3DecoderHelix::write(const void*, size_t): 1024
[D] AudioEncoded.h : 382 - EncodedAudioOutput::write: 1024 -> 1024
[D] StreamCopy.h : 338 - write: 1024 -> 1024
[I] StreamCopy.h : 143 - StreamCopy::copy  1024 -> 1024 -> 1024 bytes - in 1 hops
[D] StreamCopy.h : 97 - copy 
[D] StreamCopy.h : 177 - available: 5056026
[D] StreamCopy.h : 332 - write: 1024
[D] AudioEncoded.h : 366 - EncodedAudioOutput::write: 1024
[D] CodecMP3Helix.h : 106 - virtual size_t audio_tools::MP3DecoderHelix::write(const void*, size_t): 1024
[D] AudioEncoded.h : 382 - EncodedAudioOutput::write: 1024 -> 1024
[D] StreamCopy.h : 338 - write: 1024 -> 1024
[I] StreamCopy.h : 143 - StreamCopy::copy  1024 -> 1024 -> 1024 bytes - in 1 hops
[D] StreamCopy.h : 97 - copy 
[D] StreamCopy.h : 177 - available: 5055002
[D] StreamCopy.h : 332 - write: 1024
[D] AudioEncoded.h : 366 - EncodedAudioOutput::write: 1024
[D] CodecMP3Helix.h : 106 - virtual size_t audio_tools::MP3DecoderHelix::write(const void*, size_t): 1024
[D] CodecMP3Helix.h : 131 - static void audio_tools::MP3DecoderHelix::infoCallback(MP3FrameInfo&, void*)
[D] VolumeStream.h : 164 - virtual void audio_tools::VolumeStream::setAudioInfo(audio_tools::AudioInfo)
[I] I2SStream.h : 76 - virtual void audio_tools::I2SStream::setAudioInfo(audio_tools::AudioInfo)
[D] AudioStreams.h : 51 - virtual void audio_tools::AudioStream::setAudioInfo(audio_tools::AudioInfo)
[I] AudioTypes.h : 104 - sample_rate: 44100
[I] AudioTypes.h : 105 - channels: 2
[I] AudioTypes.h : 106 - bits_per_sample: 16
[D] VolumeStream.h : 143 - VolumeStream::write: 4608
[D] I2SStream.h : 94 - I2SStream::write: 4608
[D] I2SESP32.h : 85 - size_t audio_tools::I2SDriverESP32::writeBytes(const void*, size_t)
[D] I2SESP32.h : 92 - i2s_write 4608 -> 4608 bytes
[D] VolumeStream.h : 143 - VolumeStream::write: 4608
[D] I2SStream.h : 94 - I2SStream::write: 4608
[D] I2SESP32.h : 85 - size_t audio_tools::I2SDriverESP32::writeBytes(const void*, size_t)
[D] I2SESP32.h : 92 - i2s_write 4608 -> 4608 bytes
[D] AudioEncoded.h : 382 - EncodedAudioOutput::write: 1024 -> 1024
[D] StreamCopy.h : 338 - write: 1024 -> 1024
[I] StreamCopy.h : 143 - StreamCopy::copy  1024 -> 1024 -> 1024 bytes - in 1 hops
[D] StreamCopy.h : 97 - copy 
[D] StreamCopy.h : 177 - available: 5053978
[D] StreamCopy.h : 332 - write: 1024
.......................rest of the song

I'm building/uploading this through PlatformIO.
The board_settings.h contain my board's pins:

/*
* settings, pinconfig of the Sunton ESP32-8048S070C
* A board with an ESP32-S3 and a 7" touchscreen
*/

// SD pins
#define SD_CS         10
#define SPI_MOSI      11
#define SPI_MISO      13
#define SPI_SCK       12

// Digital out
#define I2S_BCLK      0
#define I2S_LRC       18
#define I2S_DOUT      17

Any idea what I'm missing?

[SiWoC]

Same problem when I do this with the AudioPlayer sample
https://github.com/pschatzmann/arduino-audio-tools/blob/main/examples/examples-player/player-sd-i2s/player-sd-i2s.ino

[pschatzmann]

Never heard of anything like this. MP3 produces some silence in the beginning for 1 to 2 seconds but not for 1 minute

You can try to send the output to a csvstream to visualize the decoded data in order to figure out if the issue is with your codec or your file

You can also try to decrease the i2s buffers.

[SiWoC]

player-url-i2s
Doesn't have the problem, it starts right away.

Thanks Phil for your suggestion, will try it. And see what I can find.
Hope your operation went well, get well soon

[SiWoC]

With a CsvOutput

CsvOutput<int16_t> csvStream(Serial);
EncodedAudioStream decoder(&csvStream, new MP3DecoderHelix()); // Decoding mp3 to the volume-stream

I still only see the CSV's output after 25x1024, see attached log
device-monitor-231201-170559.log

So it went from 30 to 25 (thinking)
... I also changed the song to something which would start "loud" (and not with 0's in the csv) but they have the same bitrate, 3:31 vs 3:22, 4.84Mb vs 4.64Mb, but I can't see how those would make a difference

[SiWoC]

I tried to change to the MP3DecoderMAD
EncodedAudioStream decoder(&csvStream, new MP3DecoderMAD()); // Decoding mp3 to the csv-stream
That shows only 4x1024, but no data/sound (only zeros 0,0) for 10 seconds and then starts showing data, after about 24x1024

[SiWoC]

Combination MP3DecoderMAD to VolumeStream to I2S gives sound directly.
But very poor quality, stuttering.