Ring buffer implementation

First stab at implementing a ring buffer. Now tuning should be done.
The statistics report causes jitters and can be deactivated by lowering
the output verbosity.

main/Kconfig.projbuild

@@ -20,13 +20,7 @@ menu "Squeezelite-ESP32"
         	default "info"
         	help
         		Set logging level info|debug|sdebug 	
-        		
 	endmenu
-	config LOG_OPTION
-		string "squeezelite log option"
-		default "all=info"
-		help 
-			log=level	Set logging level, logs: all|slimproto|stream|decode|output, level: info|debug|sdebug
 	menu "Wifi Configuration"
     config WIFI_SSID
         string "WiFi SSID"
@@ -133,33 +127,76 @@ menu "Squeezelite-ESP32"
 	        config BTAUDIO
 	            bool "Bluetooth A2DP"
 	    endchoice
-	    
-	    config A2DP_SINK_NAME
-	        string "Name of Bluetooth A2DP device"
-	        depends on BTAUDIO
-	        default "SMSL BT4.2"
-	        help
-	            This is the name of the bluetooth speaker that Squeezelite will try connecting to.
-	   
-	    config A2DP_DEV_NAME
-	        string "Name of Squeezelite device to use when connecting to A2DP device"
-	        depends on BTAUDIO
-	        default "Squeezelite"
-	        help
-	            This is the name of the device that the Bluetooth speaker will see when it is connected to.
-	    config A2DP_CONTROL_DELAY_MS
-	        int "Control loop delay. "
-	        depends on BTAUDIO
-	        default 500
-	        help
-	            Decreasing this will lead to a more responsive BT control, but might lead to noisy log files if debug is enabled.
-	    config A2DP_CONNECT_TIMEOUT_MS
-	    	int "Time out duration when trying to connect to an A2DP audio sink"
-			depends on BTAUDIO
-	        default 1000
-	        help
-	            Increasing this value will give more chance for less stable connections to be established.	    		            
-	            
+	  	config OUTPUT_NAME 
+			string 
+			default ""
+		    default "BT" if BTAUDIO
+		    default "DAC" if DACAUDIO
+		config OUTPUT_RATES
+			string "Output rates"
+			default "48000,44100"
+			help
+				<rates>[:<delay>]	Sample rates supported, allows output to be off when squeezelite is started; rates = <maxrate>|<minrate>-<maxrate>|<rate1>,<rate2>,<rate3>; delay = optional delay switching rates in ms  
+    	if DACAUDIO
+		    config I2S_NUM         
+		        int "I2S channel (0 or 1). "
+		        default 0
+		        help
+		            I2S dma channel to use.  
+		    config I2S_BCK_IO         
+		        int "I2S Bit clock GPIO number. "
+		        default 26
+		        help
+		            I2S Bit Clock gpio pin to use.  
+		    config I2S_WS_IO         
+		        int "I2S Word Select GPIO number. "
+		        default 25
+		        help
+		            I2S Word Select gpio pin to use.
+		    config I2S_DO_IO         
+		        int "I2S Data I/O GPIO number. "
+		        default 22
+		        help
+		            I2S data I/O gpio pin to use.
+		    choice 
+	  			prompt "Bit Depth for I2S output"
+		        default I2S_BITS_PER_CHANNEL_16
+		        config I2S_BITS_PER_CHANNEL_24
+		            bool "24 Bits"
+		        config I2S_BITS_PER_CHANNEL_16
+		            bool "16 Bits"
+		        config I2S_BITS_PER_CHANNEL_8
+		            bool "8 Bits"
+		    endchoice
+			config I2S_BITS_PER_CHANNEL
+			    int
+			    default 16
+			    default 16 if I2S_BITS_PER_CHANNEL_16
+			    default 24 if I2S_BITS_PER_CHANNEL_24
+			    default 8 if I2S_BITS_PER_CHANNEL_8
+		endif # DACAUDIO
+		if BTAUDIO
+		    config A2DP_SINK_NAME
+		        string "Name of Bluetooth A2DP device"
+		        default "SMSL BT4.2"
+		        help
+		            This is the name of the bluetooth speaker that Squeezelite will try connecting to.
+		    config A2DP_DEV_NAME
+		        string "Name of Squeezelite device to use when connecting to A2DP device"
+		        default "Squeezelite"
+		        help
+		            This is the name of the device that the Bluetooth speaker will see when it is connected to.
+		    config A2DP_CONTROL_DELAY_MS
+		        int "Control loop delay. "
+		        default 500
+		        help
+		            Decreasing this will lead to a more responsive BT control, but might lead to noisy log files if debug is enabled.
+		    config A2DP_CONNECT_TIMEOUT_MS
+		    	int "Time out duration when trying to connect to an A2DP audio sink"
+		        default 1000
+		        help
+		            Increasing this value will give more chance for less stable connections to be established.	    		            
+		endif # BTAUDIO   
 	endmenu
 
 endmenu

main/component.mk

@@ -2,12 +2,13 @@
 # "main" pseudo-component makefile.
 #
 # (Uses default behaviour of compiling all source files in directory, adding 'include' to include path.)
-CFLAGS += -O3 -DPOSIX -DLINKALL -DLOOPBACK -DDACAUDIO -DNO_FAAD -DTREMOR_ONLY -DBYTES_PER_FRAME=4	\
+CFLAGS += -O3 -DPOSIX -DLINKALL -DLOOPBACK -DNO_FAAD -DEMBEDDED -DTREMOR_ONLY -DBYTES_PER_FRAME=4 	\
 	-I$(COMPONENT_PATH)/../components/codecs/inc			\
 	-I$(COMPONENT_PATH)/../components/codecs/inc/mad 		\
 	-I$(COMPONENT_PATH)/../components/codecs/inc/alac		\
 	-I$(COMPONENT_PATH)/../components/codecs/inc/helix-aac	\
-	-I$(COMPONENT_PATH)/../components/codecs/inc/vorbis
+	-I$(COMPONENT_PATH)/../components/codecs/inc/vorbis 
+	
 LDFLAGS += -s
 
 #	-I$(COMPONENT_PATH)/../components/codecs/inc/faad2

main/esp32.c

@@ -539,7 +539,6 @@ static int32_t bt_app_a2d_data_cb(uint8_t *data, int32_t len)
    	output.updated = gettime_ms();
    	output.frames_played_dmp = output.frames_played;
 	//if (output.threshold < 20) output.threshold = 20;
-	int ret;
 
 	frames_t wanted_frames=len/BYTES_PER_FRAME;
 	bt_optr = data; // needed for the _write_frames callback
@@ -581,7 +580,7 @@ static int32_t bt_app_a2d_data_cb(uint8_t *data, int32_t len)
 
 	return frames * BYTES_PER_FRAME;
 }
-static bool running_test;
+
 #ifdef BTAUDIO
 bool test_open(const char *device, unsigned rates[], bool userdef_rates) {
 

main/esp_app_main.c

@@ -115,6 +115,8 @@ static void wifi_scan(void)
 int main(int argc, char**argv);
 
 
+#define DO_EXPAND(VAL)  VAL ## 1
+#define EXPAND(VAL)     DO_EXPAND(VAL)
 void app_main()
 {
 	int i; 
@@ -122,8 +124,12 @@ void app_main()
 		"squeezelite-esp32",
 		"-C",
 		"1",
+		"-o",
+		CONFIG_OUTPUT_NAME,
 		"-n",
 		"ESP32",
+		"-r",
+		"OUTPUT_RATES",
 		"-d",
 		"slimproto=" CONFIG_LOGGING_SLIMPROTO,
 		"-d",
@@ -132,10 +138,6 @@ void app_main()
 		"decode=" CONFIG_LOGGING_DECODE,
 		"-d",
 		"output=" CONFIG_LOGGING_OUTPUT,
-#ifdef CONFIG_LOG_OPTION
-		"-d",
-		CONFIG_LOG_OPTION,
-#endif
 		"-b",
 		"500:2000"
 

main/main.c

@@ -525,7 +525,7 @@ int main(int argc, char **argv) {
 			pidfile = optarg;
 			break;
 #endif
-#if !DACAUDIO && !BTAUDIO
+#if !CONFIG_DACAUDIO && !CONFIG_BTAUDIO
 		case 'l':
 			list_devices();
 			exit(0);
@@ -749,9 +749,9 @@ int main(int argc, char **argv) {
 
 	stream_init(log_stream, stream_buf_size);
 
-#if BTAUDIO
+#if CONFIG_BTAUDIO
 	output_init_bt(log_output, output_device, output_buf_size, output_params, rates, rate_delay, idle);
-#elif DACAUDIO
+#elif CONFIG_DACAUDIO
 	output_init_dac(log_output, output_device, output_buf_size, output_params, rates, rate_delay, idle);
 #else
 	if (!strcmp(output_device, "-")) {
@@ -801,7 +801,7 @@ int main(int argc, char **argv) {
 	decode_close();
 	stream_close();
 
-#if DACAUDIO
+#if CONFIG_DACAUDIO
 	output_close_dac();	
 #elif BTAUDIO
 	output_close_bt();

main/output_bt.c

@@ -52,7 +52,7 @@ void output_init_bt(log_level level, char *device, unsigned output_buf_size, cha
 /*
  * Bluetooth audio source init Start
  */
-	device = "BT";
+	device = CONFIG_OUTPUT_NAME;
 	output_init_common(level, device, output_buf_size, rates, idle);
 
 
@@ -72,7 +72,7 @@ static int _write_frames(frames_t out_frames, bool silence, s32_t gainL, s32_t g
 
 	if (!silence ) {
 		DEBUG_LOG_TIMED(200,"Not silence, Writing audio out.");
-		/* TODO need 16 bit fix
+		// TODO need 16 bit fix
 
 		if (output.fade == FADE_ACTIVE && output.fade_dir == FADE_CROSS && *cross_ptr) {
 			_apply_cross(outputbuf, out_frames, cross_gain_in, cross_gain_out, cross_ptr);

main/output_dac.c

@@ -1,28 +1,44 @@
 
 #include "squeezelite.h"
 #include "driver/i2s.h"
-
+#include "perf_trace.h"
 #include <signal.h>
 
-#define I2S_NUM         (0)
-#define I2S_BCK_IO      (GPIO_NUM_26)
-#define I2S_WS_IO       (GPIO_NUM_25)
-#define I2S_DO_IO       (GPIO_NUM_22)
-#define I2S_DI_IO       (-1)
 
-#define TIMED_SECTION_START_MS_FORCE(x,force) { static time_t __aa_time_start = 0; if(hasTimeElapsed(&__aa_time_start,x,force)) {
-#define TIMED_SECTION_START_MS(x) 		{ static time_t __aa_time_start = 0; if(hasTimeElapsed(&__aa_time_start,x,false)){
-#define TIMED_SECTION_START_FORCE(x,force) 			TIMED_SECTION_START_MS(x * 1000UL,force)
-#define TIMED_SECTION_START(x) 			TIMED_SECTION_START_MS(x * 1000UL)
-#define TIMED_SECTION_END				}}
+#define DECLARE_ALL_MIN_MAX \
+	DECLARE_MIN_MAX(req, long,LONG); \
+	DECLARE_MIN_MAX(rec, long,LONG); \
+	DECLARE_MIN_MAX(over, long,LONG); \
+	DECLARE_MIN_MAX(o, long,LONG); \
+	DECLARE_MIN_MAX(s, long,LONG); \
+	DECLARE_MIN_MAX(d, long,LONG); \
+	DECLARE_MIN_MAX(loci2sbuf, long,LONG); \
+	DECLARE_MIN_MAX(buffering, long,LONG);\
+	DECLARE_MIN_MAX(i2s_time, long,LONG); \
+	DECLARE_MIN_MAX(i2savailable, long,LONG);
+#define RESET_ALL_MIN_MAX \
+	RESET_MIN_MAX(d,LONG); \
+	RESET_MIN_MAX(o,LONG); \
+	RESET_MIN_MAX(s,LONG); \
+	RESET_MIN_MAX(loci2sbuf, LONG); \
+	RESET_MIN_MAX(req,LONG);  \
+	RESET_MIN_MAX(rec,LONG);  \
+	RESET_MIN_MAX(over,LONG);  \
+	RESET_MIN_MAX(over,LONG);  \
+	RESET_MIN_MAX(i2savailable,LONG);\
+	RESET_MIN_MAX(i2s_time,LONG);
 
 static log_level loglevel;
-
+size_t dac_buffer_size =0;
 static bool running = true;
 static bool isI2SStarted=false;
 extern struct outputstate output;
 extern struct buffer *streambuf;
 extern struct buffer *outputbuf;
+extern u8_t *silencebuf;
+static struct buffer _dac_buffer_structure;
+struct buffer *dacbuffer=&_dac_buffer_structure;
+
 static i2s_config_t i2s_config;
 #if REPACK && BYTES_PER_FRAMES == 4
 #error "REPACK is not compatible with BYTES_PER_FRAME=4"
@@ -32,38 +48,22 @@ static i2s_config_t i2s_config;
 #define UNLOCK mutex_unlock(outputbuf->mutex)
 
 #define FRAME_BLOCK MAX_SILENCE_FRAMES
-#define DAC_OUTPUT_BUFFER_FRAMES FRAME_BLOCK
-#define DAC_OUTPUT_BUFFER_RESERVE FRAME_BLOCK/2
-#define I2S_FRAME_SIZE 256
-#define FRAME_TO_BYTES(f) f*BYTES_PER_FRAME
-#define BYTES_TO_FRAME(b) b/BYTES_PER_FRAME
-#define FRAMES_TO_MS(f) 1000*f/output.current_sample_rate
-#define BYTES_TO_MS(b) FRAMES_TO_MS(BYTES_TO_FRAME(b))
-
-#define SET_MIN_MAX(val,var) var=val; if(var<min_##var) min_##var=var; if(var>max_##var) max_##var=var
-#define RESET_MIN_MAX(var,mv) min_##var=mv##_MAX; max_##var=mv##_MIN
-#define DECLARE_MIN_MAX(var,t,mv) static t min_##var = mv##_MAX, max_##var = mv##_MIN; t var=0
-#define DECLARE_ALL_MIN_MAX DECLARE_MIN_MAX(req, long,LONG); DECLARE_MIN_MAX(o, long,LONG); DECLARE_MIN_MAX(s, long,LONG); DECLARE_MIN_MAX(d, long,LONG); DECLARE_MIN_MAX(duration, long,LONG);DECLARE_MIN_MAX(buffering, long,LONG);DECLARE_MIN_MAX(totalprocess, long,LONG);
-#define RESET_ALL_MIN_MAX RESET_MIN_MAX(d,LONG); RESET_MIN_MAX(o,LONG); RESET_MIN_MAX(s,LONG); RESET_MIN_MAX(req,LONG);  RESET_MIN_MAX(duration,LONG);RESET_MIN_MAX(buffering,LONG);RESET_MIN_MAX(totalprocess,LONG);
-extern u8_t *silencebuf;
 
-static u8_t *optr;
-static int bytes_per_frame;
+#define FRAME_TO_BYTES(f) f*out_bytes_per_frame
+#define BYTES_TO_FRAME(b) b/out_bytes_per_frame
+
+
+static int out_bytes_per_frame;
 static thread_type thread;
 
 static int _dac_write_frames(frames_t out_frames, bool silence, s32_t gainL, s32_t gainR,
 								s32_t cross_gain_in, s32_t cross_gain_out, ISAMPLE_T **cross_ptr);
 static void *output_thread();
-bool hasTimeElapsed(time_t * lastTime, time_t delayMS, bool bforce)
-{
-	if (*lastTime <= gettime_ms() ||bforce)
-	{
-		*lastTime = gettime_ms() + delayMS;
-		return true;
-	}
-	else
-		return false;
-}
+
+
+/****************************************************************************************
+ * set output volume
+ */
 void set_volume(unsigned left, unsigned right) {
 	LOG_DEBUG("setting internal gain left: %u right: %u", left, right);
 	LOCK;
@@ -72,62 +72,77 @@ void set_volume(unsigned left, unsigned right) {
 	UNLOCK;
 }
 
-
+/****************************************************************************************
+ * Initialize the DAC output
+ */
 void output_init_dac(log_level level, char *device, unsigned output_buf_size, char *params, unsigned rates[], unsigned rate_delay, unsigned idle) {
 	loglevel = level;
-	optr = malloc(FRAME_TO_BYTES(DAC_OUTPUT_BUFFER_FRAMES));
-	if (!optr) {
-		LOG_ERROR("unable to malloc buf");
-		return;
-	}
-	LOG_INFO("init output DAC");
-	
-	memset(&output, 0, sizeof(output));
 
-#if BYTES_PER_FRAME == 4
-	output.format = S16_LE;
-#else 
-	output.format = S32_LE;
-#endif	
-	output.start_frames = DAC_OUTPUT_BUFFER_FRAMES*2;
-	output.write_cb = &_dac_write_frames;
-	output.rate_delay = rate_delay;
+	LOG_INFO("Init output DAC.");
+
+	LOG_DEBUG("Setting output parameters.");
+
+	memset(&output, 0, sizeof(output));
 
-	if (params) {
-		if (!strcmp(params, "32"))	output.format = S32_LE;
-		if (!strcmp(params, "24")) output.format = S24_3LE;
-		if (!strcmp(params, "16")) output.format = S16_LE;
+	switch (CONFIG_I2S_BITS_PER_CHANNEL) {
+		case 24:
+			output.format = S24_BE;
+			break;
+		case 16:
+			output.format = S16_BE;
+			break;
+		case 8:
+			output.format = S8_BE;
+			break;
+		default:
+			LOG_ERROR("Unsupported bit depth %d",CONFIG_I2S_BITS_PER_CHANNEL);
+			break;
 	}
-	
 	// ensure output rate is specified to avoid test open
 	if (!rates[0]) {
 		rates[0] = 44100;
 	}
-
+	running=true;
+	// get common output configuration details
 	output_init_common(level, device, output_buf_size, rates, idle);
-	
+
+	out_bytes_per_frame = get_bytes_per_frame(output.format);
+
+	output.start_frames = FRAME_BLOCK;
+	output.write_cb = &_dac_write_frames;
+	output.rate_delay = rate_delay;
 
 	i2s_config.mode = I2S_MODE_MASTER | I2S_MODE_TX;                    // Only TX
 	i2s_config.sample_rate = output.current_sample_rate;
-	i2s_config.bits_per_sample = BYTES_PER_FRAME * 8/2;
+	i2s_config.bits_per_sample = get_bytes_per_frame(output.format) * 8/2;
 	i2s_config.channel_format = I2S_CHANNEL_FMT_RIGHT_LEFT;           //2-channels
-	i2s_config.communication_format = I2S_COMM_FORMAT_I2S
-					| (output.format==S16_LE||output.format==S32_LE||output.format==S24_3LE)?I2S_COMM_FORMAT_I2S_LSB:I2S_COMM_FORMAT_I2S_MSB;
-	i2s_config.dma_buf_count = 6; //todo: tune this parameter. Expressed in numbrer of buffers.
-	i2s_config.dma_buf_len = I2S_FRAME_SIZE; // todo: tune this parameter. Expressed in number of samples. Byte size depends on bit depth
+	i2s_config.communication_format = I2S_COMM_FORMAT_I2S| I2S_COMM_FORMAT_I2S_MSB;
+	// todo: tune this parameter. Expressed in number of samples. Byte size depends on bit depth.
+	i2s_config.dma_buf_count = 64; //todo: tune this parameter. Expressed in numbrer of buffers.
+	i2s_config.dma_buf_len =  128;
 	i2s_config.use_apll = false;
 	i2s_config.intr_alloc_flags = ESP_INTR_FLAG_LEVEL1; //Interrupt level 1
 
-	i2s_pin_config_t pin_config = { .bck_io_num = I2S_BCK_IO, .ws_io_num =
-			I2S_WS_IO, .data_out_num = I2S_DO_IO, .data_in_num = I2S_DI_IO //Not used
+	i2s_pin_config_t pin_config = { .bck_io_num = CONFIG_I2S_BCK_IO, .ws_io_num =
+			CONFIG_I2S_WS_IO, .data_out_num = CONFIG_I2S_DO_IO, .data_in_num = -1 //Not used
 			};
 	LOG_INFO("Initializing I2S with rate: %d, bits per sample: %d, buffer len: %d, number of buffers: %d ",
 			i2s_config.sample_rate, i2s_config.bits_per_sample, i2s_config.dma_buf_len, i2s_config.dma_buf_count);
-	i2s_driver_install(I2S_NUM, &i2s_config, 0, NULL);
-	i2s_set_pin(I2S_NUM, &pin_config);
-	i2s_set_clk(I2S_NUM, output.current_sample_rate, i2s_config.bits_per_sample, 2);
+	i2s_driver_install(CONFIG_I2S_NUM, &i2s_config, 0, NULL);
+	i2s_set_pin(CONFIG_I2S_NUM, &pin_config);
+	i2s_set_clk(CONFIG_I2S_NUM, output.current_sample_rate, i2s_config.bits_per_sample, 2);
 	isI2SStarted=false;
-	i2s_stop(I2S_NUM);
+	i2s_stop(CONFIG_I2S_NUM);
+
+	dac_buffer_size = 10*FRAME_BLOCK*get_bytes_per_frame(output.format);
+	LOG_DEBUG("Allocating local DAC transfer buffer of %u bytes.",dac_buffer_size);
+	buf_init(dacbuffer,dac_buffer_size );
+	if (!dacbuffer->buf) {
+		LOG_ERROR("unable to malloc i2s buffer");
+		exit(0);
+	}
+	LOG_SDEBUG("Current buffer free: %d",_buf_space(dacbuffer));
+
 
 #if LINUX || OSX || FREEBSD || POSIX
 	pthread_attr_t attr;
@@ -141,23 +156,33 @@ void output_init_dac(log_level level, char *device, unsigned output_buf_size, ch
 #if WIN
 	thread = CreateThread(NULL, OUTPUT_THREAD_STACK_SIZE, (LPTHREAD_START_ROUTINE)&output_thread, NULL, 0, NULL);
 #endif
+	LOG_INFO("Init completed.");
+
 }
 
+
+/****************************************************************************************
+ * Terminate DAC output
+ */
 void output_close_dac(void) {
 	LOG_INFO("close output");
 
 	LOCK;
 	running = false;
 	UNLOCK;
-	free(optr);
+	i2s_driver_uninstall(CONFIG_I2S_NUM);
 	output_close_common();
+	buf_destroy(dacbuffer);
 }
 
+/****************************************************************************************
+ * Write frames to the output buffer
+ */
 static int _dac_write_frames(frames_t out_frames, bool silence, s32_t gainL, s32_t gainR,
 								s32_t cross_gain_in, s32_t cross_gain_out, ISAMPLE_T **cross_ptr) {
 
-	u8_t *obuf;
-	
+	size_t actual_out_bytes=FRAME_TO_BYTES(out_frames);
+	assert(out_bytes_per_frame>0);
 	if (!silence) {
 		
 		if (output.fade == FADE_ACTIVE && output.fade_dir == FADE_CROSS && *cross_ptr) {
@@ -176,14 +201,12 @@ static int _dac_write_frames(frames_t out_frames, bool silence, s32_t gainL, s32
 				dsd_invert((u32_t *) outputbuf->readp, out_frames);
 		)
 		
-		memcpy(optr, outputbuf->readp, out_frames * BYTES_PER_FRAME);
+		memcpy(dacbuffer->writep, outputbuf->readp, actual_out_bytes);
 #else
 		obuf = outputbuf->readp;	
 #endif		
 
 	} else {
-	
-		obuf = silencebuf;
 #if !REPACK
 		IF_DSD(
 			if (output.outfmt != PCM) {
@@ -192,144 +215,154 @@ static int _dac_write_frames(frames_t out_frames, bool silence, s32_t gainL, s32
 			}
 		)
 
-		memcpy(optr, obuf, out_frames * BYTES_PER_FRAME);
+		memcpy(dacbuffer->writep, silencebuf,  actual_out_bytes);
 #endif		
 	}
 
 #if REPACK
 	_scale_and_pack_frames(optr, (s32_t *)(void *)obuf, out_frames, gainL, gainR, output.format);
 #endif	
-//	TIMED_SECTION_START_MS(500);
-//	LOG_INFO("Done moving data to out buffer");
-//	TIMED_SECTION_END;
-	return (int)out_frames;
+	_buf_inc_writep(dacbuffer,actual_out_bytes);
+	return (int)BYTES_TO_FRAME(actual_out_bytes);
 }
 
+
+/****************************************************************************************
+ * Wait for a duration based on a frame count
+ */
 void wait_for_frames(size_t frames)
 {
-	usleep((1000* frames/output.current_sample_rate) );
+	usleep((1000* frames/output.current_sample_rate*.90) );
 }
 
+/****************************************************************************************
+ * Main output thread
+ */
 static void *output_thread() {
-//	// buffer to hold output data so we can block on writing outside of output lock, allocated on init
-//	u8_t *obuf = malloc(FRAME_BLOCK * BYTES_PER_FRAME);
-	u8_t *opos=optr;
-	frames_t frames=0, requested_frames = 0;
-	size_t used_buffer=0;
-	static int count = 0, count2=0;
-	uint32_t start_writing=0, start_i2s=0;
-	DECLARE_ALL_MIN_MAX;
-
-	size_t i2s_bytes_write, i2s_bytes_to_write = 0;
-#if REPACK
-	LOCK;
-
-	switch (output.format) {
-	case S32_BE:
-	case S32_LE:
-		bytes_per_frame = 4 * 2; break;
-	case S24_3LE:
-	case S24_3BE:
-		bytes_per_frame = 3 * 2; break;
-	case S16_LE:
-	case S16_BE:
-		bytes_per_frame = 2 * 2; break;
-	default:
-		bytes_per_frame = 4 * 2; break;
-		break;
-	}
-
-	UNLOCK;
-#else	
-	bytes_per_frame = BYTES_PER_FRAME;
-#endif
+	frames_t frames=0;
+	frames_t available_frames_space=0;
+	size_t bytes_to_send_i2s=0, // Contiguous buffer which can be addressed
+		 i2s_bytes_written = 0; //actual size that the i2s port was able to write
+	uint32_t timer_start=0;
+	static int count = 0;
 
+	DECLARE_ALL_MIN_MAX;
 
 	while (running) {
-		start_writing=esp_timer_get_time();
+		i2s_bytes_written=0;
+		frames=0;
+		available_frames_space=0;
+		bytes_to_send_i2s=0, // Contiguous buffer which can be addressed
+		i2s_bytes_written = 0; //actual size that the i2s port was able to write
+		TIME_MEASUREMENT_START(timer_start);
+
 		LOCK;
-		
 		if (output.state == OUTPUT_OFF) {
 			UNLOCK;
 			LOG_INFO("Output state is off.");
-			isI2SStarted=false;
-			i2s_stop(I2S_NUM);
+			LOG_SDEBUG("Current buffer free: %10d, cont read: %10d",_buf_space(dacbuffer),_buf_cont_read(dacbuffer));
+			if(isI2SStarted) {
+				isI2SStarted=false;
+				i2s_stop(CONFIG_I2S_NUM);
+			}
 			usleep(500000);
 			continue;
-		}		
-		requested_frames = 0;
-		frames=0;
-		if(used_buffer==0)
-		{
-			// replenish buffer when it's empty
-			opos=optr;
-			requested_frames =DAC_OUTPUT_BUFFER_FRAMES;
-
-			frames = _output_frames( requested_frames ); // Keep the dma buffer full
-			used_buffer+=FRAME_TO_BYTES(frames);
-
 		}
+		LOG_SDEBUG("Current buffer free: %10d, cont read: %10d",_buf_space(dacbuffer),_buf_cont_read(dacbuffer));
+		available_frames_space = BYTES_TO_FRAME(min(_buf_space(dacbuffer), _buf_cont_write(dacbuffer)));
+		frames = _output_frames( available_frames_space ); // Keep the transfer buffer full
 		UNLOCK;
-		if(frames>0) SET_MIN_MAX((esp_timer_get_time()-start_writing)/1000,buffering);
-		// todo: call i2s_set_clock here if rate is changed
-
+		LOG_SDEBUG("Current buffer free: %10d, cont read: %10d",_buf_space(dacbuffer),_buf_cont_read(dacbuffer));
+		SET_MIN_MAX( TIME_MEASUREMENT_GET(timer_start),buffering);
+		SET_MIN_MAX( available_frames_space,req);
+		SET_MIN_MAX(frames,rec);
+		if(frames>0){
+				//LOG_DEBUG("Frames available : %u.",frames);
+		}
+		else
+		{
+			//LOG_DEBUG("No frame available");
+			usleep(100000);
+		}
 
-		if (used_buffer  )
+		SET_MIN_MAX(_buf_used(dacbuffer),loci2sbuf);
+		bytes_to_send_i2s = _buf_cont_read(dacbuffer);
+		SET_MIN_MAX(bytes_to_send_i2s,i2savailable);
+		if (bytes_to_send_i2s>0  )
 		{
-			start_i2s=esp_timer_get_time();
+			TIME_MEASUREMENT_START(timer_start);
 			if(!isI2SStarted)
 			{
 				isI2SStarted=true;
-				i2s_start(I2S_NUM);
+				LOG_INFO("Restarting I2S.");
+				i2s_start(CONFIG_I2S_NUM);
+				if( i2s_config.sample_rate != output.current_sample_rate)
+				{
+					i2s_config.sample_rate = output.current_sample_rate;
+					i2s_set_sample_rates(CONFIG_I2S_NUM, i2s_config.sample_rate);
+				}
 			}
-			i2s_write(I2S_NUM, opos,used_buffer, &i2s_bytes_write, portMAX_DELAY);
-			if(i2s_bytes_write!=used_buffer)
+			count++;
+			LOG_SDEBUG("Outputting to I2S");
+			LOG_SDEBUG("Current buffer free: %10d, cont read: %10d",_buf_space(dacbuffer),_buf_cont_read(dacbuffer));
+
+			i2s_write(CONFIG_I2S_NUM, dacbuffer->readp,bytes_to_send_i2s, &i2s_bytes_written, portMAX_DELAY);
+			_buf_inc_readp(dacbuffer,i2s_bytes_written);
+			if(i2s_bytes_written!=bytes_to_send_i2s)
 			{
-				LOG_WARN("I2S DMA Overflow! available bytes: %d, I2S wrote %d bytes", used_buffer,i2s_bytes_write);
+				LOG_WARN("I2S DMA Overflow! available bytes: %d, I2S wrote %d bytes", bytes_to_send_i2s,i2s_bytes_written);
+
 			}
-			used_buffer -= i2s_bytes_write;
-			opos+=i2s_bytes_write;
-			output.device_frames =BYTES_TO_FRAME(used_buffer);
+			LOG_SDEBUG("DONE Outputting to I2S. Wrote: %d bytes out of %d", i2s_bytes_written,bytes_to_send_i2s);
+			LOG_SDEBUG("Current buffer free: %10d, cont read: %10d",_buf_space(dacbuffer),_buf_cont_read(dacbuffer));
+
+
+			output.device_frames =0;
 			output.updated = gettime_ms();
-			output.frames_played_dmp = output.frames_played-output.device_frames;
-			SET_MIN_MAX((esp_timer_get_time()-start_i2s)/1000,duration);
+			output.frames_played_dmp = output.frames_played;
+			SET_MIN_MAX( TIME_MEASUREMENT_GET(timer_start),i2s_time);
+
 		}
-		SET_MIN_MAX(duration+frames>0?buffering:0,totalprocess);
+		SET_MIN_MAX(bytes_to_send_i2s-i2s_bytes_written,over);
 		SET_MIN_MAX(_buf_used(outputbuf),o);
 		SET_MIN_MAX(_buf_used(streambuf),s);
-		SET_MIN_MAX(used_buffer,d);
-		SET_MIN_MAX(requested_frames,req);
-		if (!(count++ & 0x1ff)) {
-			LOG_INFO( "count:%d"
-					"\n              ----------+----------+-----------+  +----------+----------+----------------+"
-					"\n                    max |      min |    current|  |      max |      min |        current |"
-					"\n                   (ms) |     (ms) |       (ms)|  | (frames) | (frames) |        (frames)|"
-					"\n              ----------+----------+-----------+  +----------+----------+----------------+"
-					"\nout           %10d|%10d|%11d|"                 "  |%10d|%10d|%16d|"
-					"\nstream        %10d|%10d|%11d|"                 "  |%10d|%10d|%16d|"
-					"\nDMA overflow  %10d|%10d|%11d|"                 "  |%10d|%10d|%16d|"
-					"\nrequested     %10d|%10d|%11d|"                 "  |%10d|%10d|%16d|"
-					"\n              ----------+----------+-----------+  +----------+----------+----------------+"
-					"\n"
-					"\n              max (us)  | min (us) | total(us) |  "
-					"\n              ----------+----------+-----------+  "
-					"\ni2s time (us):%10d|%10d|%11d|"
-					"\nbuffering(us):%10d|%10d|%11d|"
-					"\ntotal(us)    :%10d|%10d|%11d|"
-					"\n              ----------+----------+-----------+  ",
-					count,
-					BYTES_TO_MS(max_o), BYTES_TO_MS(min_o),BYTES_TO_MS(o),max_o,min_o,o,
-					BYTES_TO_MS(max_s), BYTES_TO_MS(min_s),BYTES_TO_MS(s),max_s,min_s,s,
-					BYTES_TO_MS(max_d),BYTES_TO_MS(min_d),BYTES_TO_MS(d),max_d,min_d,d,
-					FRAMES_TO_MS(max_req),FRAMES_TO_MS(min_req),FRAMES_TO_MS(req), max_req, min_req,req,
-					max_duration, min_duration, duration,
-					max_buffering, min_buffering, buffering,
-					max_totalprocess,min_totalprocess,totalprocess
-					);
-			RESET_ALL_MIN_MAX;
-		}
+
+		/*
+		 * Statistics reporting
+		 */
+#define STATS_PERIOD_MS 5000
+		count++;
+		TIMED_SECTION_START_MS(STATS_PERIOD_MS);
+
+		LOG_INFO( "count:%d, current sample rate: %d, bytes per frame: %d, avg cycle duration (ms): %d",count,output.current_sample_rate, out_bytes_per_frame,STATS_PERIOD_MS/count);
+		LOG_INFO( "              ----------+----------+-----------+  +----------+----------+----------------+");
+		LOG_INFO( "                    max |      min |    current|  |      max |      min |        current |");
+		LOG_INFO( "                   (ms) |     (ms) |       (ms)|  |  (bytes) |  (bytes) |        (bytes) |");
+		LOG_INFO( "              ----------+----------+-----------+  +----------+----------+----------------+");
+		LOG_INFO(LINE_MIN_MAX_FORMAT_STREAM, LINE_MIN_MAX_STREAM("stream",s));
+		LOG_INFO(LINE_MIN_MAX_FORMAT,LINE_MIN_MAX("output",o));
+		LOG_INFO(LINE_MIN_MAX_FORMAT,LINE_MIN_MAX("i2swrite",i2savailable));
+		LOG_INFO(LINE_MIN_MAX_FORMAT,LINE_MIN_MAX("local free",loci2sbuf));
+		LOG_INFO(LINE_MIN_MAX_FORMAT,LINE_MIN_MAX("requested",req));
+		LOG_INFO(LINE_MIN_MAX_FORMAT,LINE_MIN_MAX("received",rec));
+		LOG_INFO(LINE_MIN_MAX_FORMAT,LINE_MIN_MAX("overflow",over));
+		LOG_INFO("              ----------+----------+-----------+  +----------+----------+----------------+");
+		LOG_INFO("");
+		LOG_INFO("              max (us)  | min (us) |current(us)|  ");
+		LOG_INFO("              ----------+----------+-----------+  ");
+		LOG_INFO(LINE_MIN_MAX_DURATION_FORMAT,LINE_MIN_MAX_DURATION("Buffering(us)",buffering));
+		LOG_INFO(LINE_MIN_MAX_DURATION_FORMAT,LINE_MIN_MAX_DURATION("i2s tfr(us)",i2s_time));
+		LOG_INFO("              ----------+----------+-----------+  ");
+		RESET_ALL_MIN_MAX;
+		count=0;
+		TIMED_SECTION_END;
+		/*
+		 * End Statistics reporting
+		 */
+		wait_for_frames(BYTES_TO_FRAME(i2s_bytes_written));
 	}
 
+
 	return 0;
 }
 

main/perf_trace.c

@@ -0,0 +1,14 @@
+#include "squeezelite.h"
+#include "perf_trace.h"
+/*************************************
+ * Some performance analysis bits
+ */
+
+//perf_stats * stats[]={
+//		{ .min=LONG_MAX, .max=LONG_MIN, .current=0, .name="output", .fmt=BUFFER_TYPE },
+//		{ .min=LONG_MAX, .max=LONG_MIN, .current=0, .name="stream", .fmt=BUFFER_TYPE },
+//		{ .min=LONG_MAX, .max=LONG_MIN, .current=0, .name="i2sbuffer", .fmt=BUFFER_TYPE },
+//		{ .min=LONG_MAX, .max=LONG_MIN, .current=0, .name="i2s_write", .fmt=DURATION_TYPE },
+//		{ .min=LONG_MAX, .max=LONG_MIN, .current=0, .name="output_fill", .fmt=DURATION_TYPE }
+//};
+

main/perf_trace.h

@@ -0,0 +1,44 @@
+
+#pragma once
+#define FRAMES_TO_MS(f) output.current_sample_rate>0?1000*f/output.current_sample_rate:LONG_MIN
+#define BYTES_TO_MS(b) FRAMES_TO_MS(BYTES_TO_FRAME(b))
+#define LINE_MIN_MAX_FORMAT          "%14s%10d|%10d|%11d|"                 "  |%10d|%10d|%16d|"
+#define LINE_MIN_MAX_DURATION_FORMAT "%14s%10d|%10d|%11d|"
+#define LINE_MIN_MAX_FORMAT_STREAM   "%14s%10s|%10s|%11s|"                 "  |%10d|%10d|%16d|"
+#define SET_MIN_MAX(val,var) var=val; if(var<min_##var) min_##var=var; if(var>max_##var) max_##var=var
+#define RESET_MIN_MAX(var,mv) min_##var=mv##_MAX; max_##var=mv##_MIN
+#define DECLARE_MIN_MAX(var,t,mv) static t min_##var = mv##_MAX, max_##var = mv##_MIN; t var=0
+#define LINE_MIN_MAX(name,var) name,BYTES_TO_MS(max_##var), BYTES_TO_MS(min_##var),BYTES_TO_MS( var),max_##var,min_##var,var
+#define LINE_MIN_MAX_STREAM(name,var) name,"n/a","n/a","n/a",max_##var,min_##var,var
+#define LINE_MIN_MAX_DURATION(name,var) name,max_##var, min_##var, var
+
+#define TIME_MEASUREMENT_START(x) x=esp_timer_get_time()
+#define TIME_MEASUREMENT_GET(x) (esp_timer_get_time()-x)/1000
+
+#define TIMED_SECTION_START_MS_FORCE(x,force) if(hasTimeElapsed(x,force)) {
+#define TIMED_SECTION_START_MS(x) 		if(hasTimeElapsed(x,false)){
+#define TIMED_SECTION_START_FORCE(x,force) 			TIMED_SECTION_START_MS(x * 1000UL,force)
+#define TIMED_SECTION_START(x) 			TIMED_SECTION_START_MS(x * 1000UL)
+#define TIMED_SECTION_END				}
+static inline bool hasTimeElapsed(time_t delayMS, bool bforce)
+{
+	static time_t lastTime=0;
+	if (lastTime <= gettime_ms() ||bforce)
+	{
+		lastTime = gettime_ms() + delayMS;
+		return true;
+	}
+	else
+		return false;
+}
+//#define MAX_PERF_NAME_LEN 10
+//#define MAX_PERF_FORMAT_LEN 12
+//typedef enum  {BUFFER_TYPE,DURATION_TYPE,LAST } perf_formats;
+//typedef struct _perf_stats {
+//	uint32_t min;
+//	uint32_t max;
+//	uint32_t current;
+//	char name[MAX_PERF_NAME_LEN+1];
+//	uint32_t timer_start;
+//	perf_formats fmt;
+//} perf_stats;

main/squeezelite.h

@@ -34,7 +34,6 @@
 #define VERSION "v" MAJOR_VERSION "." MINOR_VERSION "-" MICRO_VERSION
 #endif
 
-
 #if !defined(MODEL_NAME)
 #define MODEL_NAME SqueezeLite
 #endif
@@ -43,6 +42,11 @@
 #define STR(macro)  QUOTE(macro)
 #define MODEL_NAME_STRING STR(MODEL_NAME)
 
+#if defined(EMBEDDED)
+#define POSIX 1
+#include "embedded.h"
+#endif
+
 // build detection
 #if defined(linux)
 #define LINUX     1
@@ -78,12 +82,13 @@
 #error unknown target
 #endif
 
-#if defined(DACAUDIO)
-#undef DACAUDIO
-#define DACAUDIO  1
-#elif defined(BTAUDIO)
-#undef BTAUDIO
-#define BTAUDIO 1
+
+#if defined(CONFIG_DACAUDIO)
+#undef CONFIG_DACAUDIO
+#define CONFIG_DACAUDIO  1
+#elif defined(CONFIG_BTAUDIO)
+#undef CONFIG_BTAUDIO
+#define CONFIG_BTAUDIO 1
 #elif LINUX && !defined(PORTAUDIO)
 #define ALSA      1
 #define PORTAUDIO 0
@@ -646,9 +651,13 @@ typedef enum { OUTPUT_OFF = -1, OUTPUT_STOPPED = 0, OUTPUT_BUFFER, OUTPUT_RUNNIN
 #if DSD
 typedef enum { PCM, DOP, DSD_U8, DSD_U16_LE, DSD_U32_LE, DSD_U16_BE, DSD_U32_BE, DOP_S24_LE, DOP_S24_3LE } dsd_format;
 typedef enum { S32_LE, S24_LE, S24_3LE, S16_LE, U8, U16_LE, U16_BE, U32_LE, U32_BE } output_format;
+#elif CONFIG_DACAUDIO
+typedef enum { S32_LE, S24_LE, S24_3LE, S16_LE, S24_BE, S24_3BE, S16_BE, S8_BE } output_format;
 #else
-typedef enum { S32_LE, S24_LE, S24_3LE, S16_LE,S32_BE, S24_BE, S24_3BE, S16_BE } output_format;
+typedef enum { S32_LE, S24_LE, S24_3LE, S16_LE } output_format;
 #endif
+extern uint8_t get_bytes_per_frame(output_format fmt);
+
 
 typedef enum { FADE_INACTIVE = 0, FADE_DUE, FADE_ACTIVE } fade_state;
 typedef enum { FADE_UP = 1, FADE_DOWN, FADE_CROSS } fade_dir;
@@ -741,7 +750,7 @@ void _pa_open(void);
 #endif
 
 // output_dac.c
-#if DACAUDIO
+#if CONFIG_DACAUDIO
 void set_volume(unsigned left, unsigned right);
 bool test_open(const char *device, unsigned rates[], bool userdef_rates);
 void output_init_dac(log_level level, char *device, unsigned output_buf_size, char *params, unsigned rates[], unsigned rate_delay, unsigned idle);
@@ -750,7 +759,7 @@ void hal_bluetooth_init(log_level loglevel);
 #endif
 
 //output_bt.c
-#if  BTAUDIO
+#if  CONFIG_BTAUDIO
 void set_volume(unsigned left, unsigned right);
 bool test_open(const char *device, unsigned rates[], bool userdef_rates);
 void output_init_bt(log_level level, char *device, unsigned output_buf_size, char *params, unsigned rates[], unsigned rate_delay, unsigned idle);

main/utils.c

@@ -561,3 +561,57 @@ char *strcasestr(const char *haystack, const char *needle) {
 	return NULL;
 }
 #endif
+uint8_t get_bytes_per_frame(output_format fmt)
+{
+	uint8_t bpf=0;
+
+	switch (fmt) {
+		case S32_LE:
+			bpf=4*2;
+			break;
+		case S24_LE:
+			bpf=3*2;
+			break;
+		case S24_3LE:
+			bpf=3*2;
+			break;
+		case S16_LE:
+			bpf=2*2;
+			break;
+#if CONFIG_DACAUDIO
+		case S24_BE:
+			bpf=3*2;
+			break;
+		case S24_3BE:
+			bpf=3*2;
+			break;
+		case S16_BE:
+			bpf=2*2;
+			break;
+		case S8_BE:
+			bpf=2*2;
+			break;
+#endif
+#if DSD
+		case U8:
+			bpf=1*2;
+			break;
+		case U16_LE:
+			bpf=2*2;
+			break;
+		case U16_BE:
+			bpf=2*2;
+			break;
+		case U32_LE:
+			bpf=4*2;
+			break;
+		case U32_BE:
+			bpf=4*2;
+			break;
+#endif
+		default:
+			break;
+	}
+	assert(bpf>0);
+	return bpf;
+}

sdkconfig.defaults

@@ -49,4 +49,13 @@ CONFIG_ESPTOOLPY_BAUD=2000000
 # Decreasing the delay here leads to a more responsive control of the playback.  
 # If debug logging set on output, this should be raised as it will generate a lot of noise in logs 
 CONFIG_A2DP_CONTROL_DELAY_MS=500
-CONFIG_A2DP_CONNECT_TIMEOUT_MS=1000
+CONFIG_A2DP_CONNECT_TIMEOUT_MS=1000
+CONFIG_OUTPUT_NAME=""
+CONFIG_I2S_NUM=0
+CONFIG_I2S_BCK_IO=26
+CONFIG_I2S_WS_IO=25
+CONFIG_I2S_DO_IO=22
+CONFIG_I2S_BITS_PER_CHANNEL_16=y
+CONFIG_I2S_BITS_PER_CHANNEL=16
+CONFIG_DACAUDIO=y
+CONFIG_OUTPUT_NAME="DAC"