More DAC WIP

Stable DAC out.  Needs refactoring!

main/esp32.c

@@ -25,7 +25,8 @@
 #include "esp_gap_bt_api.h"
 #include "esp_a2dp_api.h"
 #include "esp_avrc_api.h"
-
+#include "esp_pthread.h"
+#include "pthread.h"
 #define BT_AV_TAG               "BT_AV"
 u8_t *bt_optr;
 extern log_level loglevel;
@@ -50,6 +51,17 @@ int64_t connecting_timeout = 0;
 #define A2DP_TIMER_INIT connecting_timeout = esp_timer_get_time() +(CONFIG_A2DP_CONNECT_TIMEOUT_MS * 1000)
 #define IS_A2DP_TIMER_OVER esp_timer_get_time() >= connecting_timeout
 
+#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);
+#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);
+
 
 void get_mac(u8_t mac[]) {
     esp_read_mac(mac, ESP_MAC_WIFI_STA);
@@ -494,9 +506,8 @@ static int32_t bt_app_a2d_data_cb(uint8_t *data, int32_t len)
 {
 	frames_t frames;
 	static int count = 0;
-	static unsigned min_o = -1, max_o = 0, min_s = -1, max_s = 0;
-	unsigned o, s;
 
+	DECLARE_ALL_MIN_MAX;
 
 	if (len < 0 || data == NULL ) {
         return 0;
@@ -545,18 +556,27 @@ static int32_t bt_app_a2d_data_cb(uint8_t *data, int32_t len)
 
 	UNLOCK;
 
-	o = _buf_used(outputbuf);
-	if (o < min_o) min_o = o;
-	if (o > max_o) max_o = o;
-
-	s = _buf_used(streambuf);
-	if (s < min_s) min_s = s;
-	if (s > max_s) max_s = s;
+	SET_MIN_MAX(_buf_used(outputbuf),o);
+	SET_MIN_MAX(_buf_used(streambuf),s);
+	SET_MIN_MAX(frames,req);
 
 	if (!(count++ & 0x1ff)) {
-		LOG_INFO("frames %d (count:%d) (out:%d/%d/%d, stream:%d/%d/%d)", frames, count, max_o, min_o, o, max_s, min_s, s);
-		min_o = min_s = -1;
-		max_o = max_s = -0;
+		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|"
+							"\nN/A           %10d|%10d|%11d|"                 "  |%10d|%10d|%16d|"
+							"\nrequested     %10d|%10d|%11d|"                 "  |%10d|%10d|%16d|"
+							"\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(req),FRAMES_TO_MS(req),FRAMES_TO_MS(req), req, req,req);
+		RESET_ALL_MIN_MAX;
 	}
 
 	return frames * BYTES_PER_FRAME;

main/esp_app_main.c

@@ -132,6 +132,10 @@ 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
-#ifndef DACAUDIO
+#if !DACAUDIO && !BTAUDIO
 		case 'l':
 			list_devices();
 			exit(0);
@@ -803,6 +803,8 @@ int main(int argc, char **argv) {
 
 #if DACAUDIO
 	output_close_dac();	
+#elif BTAUDIO
+	output_close_bt();
 #else
 	if (!strcmp(output_device, "-")) {
 		output_close_stdout();

main/output_bt.c

@@ -41,7 +41,7 @@ void output_init_bt(log_level level, char *device, unsigned output_buf_size, cha
 
 	memset(&output, 0, sizeof(output));
 
-	output.start_frames = 0; //CONFIG_ //FRAME_BLOCK * 2;
+	output.start_frames = FRAME_BLOCK; //CONFIG_ //FRAME_BLOCK * 2;
 	output.write_cb = &_write_frames;
 	output.rate_delay = rate_delay;
 

main/output_dac.c

@@ -1,22 +1,29 @@
 
 #include "squeezelite.h"
 #include "driver/i2s.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)
 
-// buffer length is expressed in number of samples
-#define I2S_BUF_LEN		60
+#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				}}
+
 static log_level loglevel;
 
 static bool running = true;
-
+static bool isI2SStarted=false;
 extern struct outputstate output;
+extern struct buffer *streambuf;
 extern struct buffer *outputbuf;
-
+static i2s_config_t i2s_config;
 #if REPACK && BYTES_PER_FRAMES == 4
 #error "REPACK is not compatible with BYTES_PER_FRAME=4"
 #endif
@@ -25,7 +32,19 @@ extern struct buffer *outputbuf;
 #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;
@@ -35,7 +54,16 @@ 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;
+}
 void set_volume(unsigned left, unsigned right) {
 	LOG_DEBUG("setting internal gain left: %u right: %u", left, right);
 	LOCK;
@@ -44,9 +72,10 @@ void set_volume(unsigned left, unsigned right) {
 	UNLOCK;
 }
 
+
 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_BLOCK * BYTES_PER_FRAME);
+	optr = malloc(FRAME_TO_BYTES(DAC_OUTPUT_BUFFER_FRAMES));
 	if (!optr) {
 		LOG_ERROR("unable to malloc buf");
 		return;
@@ -60,7 +89,7 @@ void output_init_dac(log_level level, char *device, unsigned output_buf_size, ch
 #else 
 	output.format = S32_LE;
 #endif	
-	output.start_frames = FRAME_BLOCK * 2;
+	output.start_frames = DAC_OUTPUT_BUFFER_FRAMES*2;
 	output.write_cb = &_dac_write_frames;
 	output.rate_delay = rate_delay;
 
@@ -77,24 +106,28 @@ void output_init_dac(log_level level, char *device, unsigned output_buf_size, ch
 
 	output_init_common(level, device, output_buf_size, rates, idle);
 	
-	i2s_config_t i2s_config = {
-			.mode = I2S_MODE_MASTER | I2S_MODE_TX,                    // Only TX
-			.sample_rate = output.current_sample_rate,
-			.bits_per_sample = BYTES_PER_FRAME * 8,
-			.channel_format = I2S_CHANNEL_FMT_RIGHT_LEFT,           //2-channels
-			.communication_format = I2S_COMM_FORMAT_I2S
-					| I2S_COMM_FORMAT_I2S_MSB,
-			.dma_buf_count = 6, //todo: tune this parameter. Expressed in numbrer of buffers
-			.dma_buf_len = I2S_BUF_LEN, // todo: tune this parameter. Expressed in number of samples. Byte size depends on bit depth
-			.use_apll = false,
-			.intr_alloc_flags = ESP_INTR_FLAG_LEVEL1 //Interrupt level 1
-			};
+
+	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.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.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
 			};
+	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);
+	isI2SStarted=false;
+	i2s_stop(I2S_NUM);
 
 #if LINUX || OSX || FREEBSD || POSIX
 	pthread_attr_t attr;
@@ -166,24 +199,40 @@ static int _dac_write_frames(frames_t out_frames, bool silence, s32_t gainL, s32
 #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;
 }
 
+void wait_for_frames(size_t frames)
+{
+	usleep((1000* frames/output.current_sample_rate) );
+}
+
 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);
-	int frames = 0;
-	size_t i2s_bytes_write = 0;
+//	// 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;
@@ -195,37 +244,90 @@ static void *output_thread() {
 	bytes_per_frame = BYTES_PER_FRAME;
 #endif
 
-	while (running) {
 
+	while (running) {
+		start_writing=esp_timer_get_time();
 		LOCK;
 		
 		if (output.state == OUTPUT_OFF) {
 			UNLOCK;
+			LOG_INFO("Output state is off.");
+			isI2SStarted=false;
+			i2s_stop(I2S_NUM);
 			usleep(500000);
 			continue;
 		}		
-		// todo: call i2s_set_clock here if rate is changed
+		requested_frames = 0;
+		frames=0;
+		if(used_buffer==0)
+		{
+			// replenish buffer when it's empty
+			opos=optr;
+			requested_frames =DAC_OUTPUT_BUFFER_FRAMES;
 
-		output.device_frames = 0;
-		output.updated = gettime_ms();
-		output.frames_played_dmp = output.frames_played;
+			frames = _output_frames( requested_frames ); // Keep the dma buffer full
+			used_buffer+=FRAME_TO_BYTES(frames);
 
-		optr = obuf + frames * bytes_per_frame;
-		frames += _output_frames(FRAME_BLOCK);
-		
+		}
 		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
+
 
-		if (frames) {
-			 i2s_write(I2S_NUM, optr,frames*BYTES_PER_FRAME, &i2s_bytes_write, 100);
-			if(i2s_bytes_write!=frames*BYTES_PER_FRAME){
-				LOG_WARN("Bytes available: %d, I2S wrote %d", frames*BYTES_PER_FRAME,i2s_bytes_write);
+		if (used_buffer  )
+		{
+			start_i2s=esp_timer_get_time();
+			if(!isI2SStarted)
+			{
+				isI2SStarted=true;
+				i2s_start(I2S_NUM);
 			}
-			 usleep((frames * 1000 * 1000) / output.current_sample_rate);
-			frames = 0;
-		} else {
-			usleep((FRAME_BLOCK * 1000 * 1000) / output.current_sample_rate);
-		}	
-		
+			i2s_write(I2S_NUM, opos,used_buffer, &i2s_bytes_write, portMAX_DELAY);
+			if(i2s_bytes_write!=used_buffer)
+			{
+				LOG_WARN("I2S DMA Overflow! available bytes: %d, I2S wrote %d bytes", used_buffer,i2s_bytes_write);
+			}
+			used_buffer -= i2s_bytes_write;
+			opos+=i2s_bytes_write;
+			output.device_frames =BYTES_TO_FRAME(used_buffer);
+			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);
+		}
+		SET_MIN_MAX(duration+frames>0?buffering:0,totalprocess);
+		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;
+		}
 	}
 
 	return 0;

main/squeezelite.h

@@ -647,7 +647,7 @@ typedef enum { OUTPUT_OFF = -1, OUTPUT_STOPPED = 0, OUTPUT_BUFFER, OUTPUT_RUNNIN
 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;
 #else
-typedef enum { S32_LE, S24_LE, S24_3LE, S16_LE } output_format;
+typedef enum { S32_LE, S24_LE, S24_3LE, S16_LE,S32_BE, S24_BE, S24_3BE, S16_BE } output_format;
 #endif
 
 typedef enum { FADE_INACTIVE = 0, FADE_DUE, FADE_ACTIVE } fade_state;