BT update + enable gain

.gitignore

@@ -57,3 +57,4 @@ $RECYCLE.BIN/
 # Windows shortcuts
 *.lnk
 sdkconfig
+*.save

main/Kconfig.projbuild

@@ -152,7 +152,13 @@ menu "Squeezelite-ESP32"
 	        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.	            
+	            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.	    		            
 	            
 	endmenu
 

main/bt_app_core.c

@@ -26,12 +26,14 @@ static log_level loglevel;
 
 static xQueueHandle s_bt_app_task_queue = NULL;
 static xTaskHandle s_bt_app_task_handle = NULL;
+
+
 void bt_set_log_level(log_level level){
 	loglevel = level;
 }
 bool bt_app_work_dispatch(bt_app_cb_t p_cback, uint16_t event, void *p_params, int param_len, bt_app_copy_cb_t p_copy_cback)
 {
-	LOG_DEBUG("%s event 0x%x, param len %d", __func__, event, param_len);
+	LOG_SDEBUG("%s event 0x%x, param len %d", __func__, event, param_len);
 
     bt_app_msg_t msg;
     memset(&msg, 0, sizeof(bt_app_msg_t));
@@ -81,7 +83,7 @@ static void bt_app_task_handler(void *arg)
     bt_app_msg_t msg;
     for (;;) {
         if (pdTRUE == xQueueReceive(s_bt_app_task_queue, &msg, (portTickType)portMAX_DELAY)) {
-            LOG_DEBUG("%s, sig 0x%x, 0x%x", __func__, msg.sig, msg.event);
+        	LOG_SDEBUG("%s, sig 0x%x, 0x%x", __func__, msg.sig, msg.event);
             switch (msg.sig) {
             case BT_APP_SIG_WORK_DISPATCH:
                 bt_app_work_dispatched(&msg);

main/output_bt.c

@@ -31,6 +31,7 @@ extern struct outputstate output;
 extern struct buffer *outputbuf;
 extern struct buffer *streambuf;
 
+
 #define LOCK   mutex_lock(outputbuf->mutex)
 #define UNLOCK mutex_unlock(outputbuf->mutex)
 
@@ -38,6 +39,9 @@ extern struct buffer *streambuf;
 
 extern u8_t *silencebuf;
 static u8_t *optr;
+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
 
 static int _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);
@@ -47,11 +51,10 @@ void set_volume(unsigned left, unsigned right) {
 	LOCK;
 	output.gainL = left;
 	output.gainR = right;
-	// TODO
-	output.gainL = FIXED_ONE;
-	output.gainR = FIXED_ONE;
 	UNLOCK;
 }
+#define LOG_DEBUG_EVENT(e) LOG_DEBUG("evt: " STR(e))
+#define LOG_SDEBUG_EVENT(e) LOG_SDEBUG("evt: " STR(e))
 
 /* event for handler "bt_av_hdl_stack_up */
 enum {
@@ -69,12 +72,26 @@ enum {
     APP_AV_STATE_DISCONNECTING,
 };
 
+char * APP_AV_STATE_DESC[] = {
+	    "APP_AV_STATE_IDLE",
+	    "APP_AV_STATE_DISCOVERING",
+	    "APP_AV_STATE_DISCOVERED",
+	    "APP_AV_STATE_UNCONNECTED",
+	    "APP_AV_STATE_CONNECTING",
+	    "APP_AV_STATE_CONNECTED",
+	    "APP_AV_STATE_DISCONNECTING"
+};
+
+
+
 /* sub states of APP_AV_STATE_CONNECTED */
+
 enum {
     APP_AV_MEDIA_STATE_IDLE,
     APP_AV_MEDIA_STATE_STARTING,
     APP_AV_MEDIA_STATE_STARTED,
     APP_AV_MEDIA_STATE_STOPPING,
+	APP_AV_MEDIA_STATE_WAIT_DISCONNECT
 };
 
 #define BT_APP_HEART_BEAT_EVT                (0xff00)
@@ -104,7 +121,6 @@ static uint8_t s_peer_bdname[ESP_BT_GAP_MAX_BDNAME_LEN + 1];
 static int s_a2d_state = APP_AV_STATE_IDLE;
 static int s_media_state = APP_AV_MEDIA_STATE_IDLE;
 static int s_intv_cnt = 0;
-static int s_connecting_intv = 0;
 static uint32_t s_pkt_cnt = 0;
 
 static TimerHandle_t s_tmr;
@@ -129,7 +145,7 @@ void output_init_dac(log_level level, char *device, unsigned output_buf_size, ch
 
 	memset(&output, 0, sizeof(output));
 
-	output.start_frames = FRAME_BLOCK * 2;
+	output.start_frames = 0; //CONFIG_ //FRAME_BLOCK * 2;
 	output.write_cb = &_write_frames;
 	output.rate_delay = rate_delay;
 
@@ -220,7 +236,6 @@ static int _write_frames(frames_t out_frames, bool silence, s32_t gainL, s32_t g
 	
 	if (!silence) {
 		
-		/* 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);
 		}
@@ -228,8 +243,7 @@ static int _write_frames(frames_t out_frames, bool silence, s32_t gainL, s32_t g
 		if (gainL != FIXED_ONE || gainR!= FIXED_ONE) {
 			_apply_gain(outputbuf, out_frames, gainL, gainR);
 		}
-		*/
-
+		
 #if BYTES_PER_FRAME == 4		
 		memcpy(optr, outputbuf->readp, out_frames * BYTES_PER_FRAME);
 #else
@@ -320,87 +334,133 @@ static bool get_name_from_eir(uint8_t *eir, uint8_t *bdname, uint8_t *bdname_len
 
     return false;
 }
-
+#define LOG_INFO_NO_LF(fmt, ...)   if (loglevel >= lINFO)  logprint(fmt, ##__VA_ARGS__)
 static void filter_inquiry_scan_result(esp_bt_gap_cb_param_t *param)
 {
     char bda_str[18];
     uint32_t cod = 0;
     int32_t rssi = -129; /* invalid value */
     uint8_t *eir = NULL;
+    uint8_t nameLen = 0;
     esp_bt_gap_dev_prop_t *p;
+    memset(s_peer_bdname, 0x00,sizeof(s_peer_bdname));
 
-    LOG_INFO("Scanned device: %s", bda2str(param->disc_res.bda, bda_str, 18));
+    LOG_INFO("\n=======================\nScanned device: %s", bda2str(param->disc_res.bda, bda_str, 18));
     for (int i = 0; i < param->disc_res.num_prop; i++) {
         p = param->disc_res.prop + i;
         switch (p->type) {
         case ESP_BT_GAP_DEV_PROP_COD:
             cod = *(uint32_t *)(p->val);
-            LOG_INFO("--Class of Device: 0x%x", cod);
+            LOG_INFO_NO_LF("\n-- Class of Device: 0x%x", cod);
             break;
         case ESP_BT_GAP_DEV_PROP_RSSI:
             rssi = *(int8_t *)(p->val);
-            LOG_INFO("--RSSI: %d", rssi);
+            LOG_INFO_NO_LF("\n-- RSSI: %d", rssi);
             break;
         case ESP_BT_GAP_DEV_PROP_EIR:
             eir = (uint8_t *)(p->val);
+            LOG_INFO_NO_LF("\n-- EIR: %d", eir);
             break;
         case ESP_BT_GAP_DEV_PROP_BDNAME:
+            nameLen = (p->len > ESP_BT_GAP_MAX_BDNAME_LEN) ? ESP_BT_GAP_MAX_BDNAME_LEN : (uint8_t)p->len;
+            memcpy(s_peer_bdname, (uint8_t *)(p->val), nameLen);
+            s_peer_bdname[nameLen] = '\0';
+            LOG_INFO_NO_LF("\n-- Name: %s", s_peer_bdname);
+            break;
         default:
             break;
         }
     }
-
+    if (!esp_bt_gap_is_valid_cod(cod)){
     /* search for device with MAJOR service class as "rendering" in COD */
-    if (!esp_bt_gap_is_valid_cod(cod) ||
-            !(esp_bt_gap_get_cod_srvc(cod) & ESP_BT_COD_SRVC_RENDERING)) {
-        return;
+    	LOG_INFO_NO_LF("\n--Invalid class of device. Skipping.\n");
+    	return;
+    }
+    else if (!(esp_bt_gap_get_cod_srvc(cod) & ESP_BT_COD_SRVC_RENDERING))
+    {
+    	LOG_INFO_NO_LF("\n--Not a rendering device. Skipping.\n");
+    	return;
     }
 
+
     /* search for device named "ESP_SPEAKER" in its extended inqury response */
     if (eir) {
+    	LOG_INFO_NO_LF("\n--Getting details from eir.\n");
         get_name_from_eir(eir, s_peer_bdname, NULL);
-        if (strcmp((char *)s_peer_bdname, CONFIG_A2DP_SINK_NAME) != 0) {
-            return;
-        }
+        LOG_INFO("--\nDevice name is %s",s_peer_bdname);
+    }
+
+    if (strcmp((char *)s_peer_bdname, CONFIG_A2DP_SINK_NAME) == 0) {
+    	LOG_INFO("Found a target device, address %s, name %s", bda_str, s_peer_bdname);
 
-        LOG_INFO("Found a target device, address %s, name %s", bda_str, s_peer_bdname);
-        s_a2d_state = APP_AV_STATE_DISCOVERED;
-        memcpy(s_peer_bda, param->disc_res.bda, ESP_BD_ADDR_LEN);
-        LOG_INFO("Cancel device discovery ...");
-        esp_bt_gap_cancel_discovery();
+        if(esp_bt_gap_cancel_discovery()!=ESP_ERR_INVALID_STATE)
+        {
+        	LOG_INFO("Cancel device discovery ...");
+			memcpy(s_peer_bda, param->disc_res.bda, ESP_BD_ADDR_LEN);
+        	s_a2d_state = APP_AV_STATE_DISCOVERED;
+        }
+        else
+        {
+        	LOG_ERROR("Cancel device discovery failed...");
+        }
+    }
+    else
+    {
+    	LOG_INFO("Not the device we are looking for. Continuing scan.");
     }
 }
 
 
 void bt_app_gap_cb(esp_bt_gap_cb_event_t event, esp_bt_gap_cb_param_t *param)
 {
+
     switch (event) {
     case ESP_BT_GAP_DISC_RES_EVT: {
         filter_inquiry_scan_result(param);
         break;
     }
     case ESP_BT_GAP_DISC_STATE_CHANGED_EVT: {
-        if (param->disc_st_chg.state == ESP_BT_GAP_DISCOVERY_STOPPED) {
-            if (s_a2d_state == APP_AV_STATE_DISCOVERED) {
-                s_a2d_state = APP_AV_STATE_CONNECTING;
-                LOG_INFO("Device discovery stopped.");
-                LOG_INFO("a2dp connecting to peer: %s", s_peer_bdname);
-                esp_a2d_source_connect(s_peer_bda);
-            } else {
+        if (param->disc_st_chg.state == ESP_BT_GAP_DISCOVERY_STOPPED)
+        {
+            if (s_a2d_state == APP_AV_STATE_DISCOVERED)
+            {
+                if(esp_a2d_source_connect(s_peer_bda)!=ESP_ERR_INVALID_STATE)
+                {
+                	s_a2d_state = APP_AV_STATE_CONNECTING;
+					LOG_INFO("Device discovery stopped. a2dp connecting to peer: %s", s_peer_bdname);
+					A2DP_TIMER_INIT;
+                }
+                else
+                {
+                	// not discovered, continue to discover
+					LOG_INFO("Attempt at connecting failed, resuming discover...");
+					esp_bt_gap_start_discovery(ESP_BT_INQ_MODE_GENERAL_INQUIRY, 10, 0);
+                }
+            }
+            else
+            {
                 // not discovered, continue to discover
                 LOG_INFO("Device discovery failed, continue to discover...");
                 esp_bt_gap_start_discovery(ESP_BT_INQ_MODE_GENERAL_INQUIRY, 10, 0);
             }
-        } else if (param->disc_st_chg.state == ESP_BT_GAP_DISCOVERY_STARTED) {
+        }
+        else if (param->disc_st_chg.state == ESP_BT_GAP_DISCOVERY_STARTED) {
             LOG_INFO("Discovery started.");
         }
+        else
+        {
+        	LOG_DEBUG("This shouldn't happen.  Discovery has only 2 states (for now).");
+        }
         break;
     }
     case ESP_BT_GAP_RMT_SRVCS_EVT:
+    	LOG_DEBUG_EVENT(ESP_BT_GAP_RMT_SRVCS_EVT);
+    	break;
     case ESP_BT_GAP_RMT_SRVC_REC_EVT:
+    	LOG_DEBUG_EVENT(ESP_BT_GAP_RMT_SRVC_REC_EVT);
         break;
     case ESP_BT_GAP_AUTH_CMPL_EVT: {
-        if (param->auth_cmpl.stat == ESP_BT_STATUS_SUCCESS) {
+    	if (param->auth_cmpl.stat == ESP_BT_STATUS_SUCCESS) {
             LOG_INFO("authentication success: %s", param->auth_cmpl.device_name);
             //esp_log_buffer_hex(param->auth_cmpl.bda, ESP_BD_ADDR_LEN);
         } else {
@@ -409,7 +469,7 @@ void bt_app_gap_cb(esp_bt_gap_cb_event_t event, esp_bt_gap_cb_param_t *param)
         break;
     }
     case ESP_BT_GAP_PIN_REQ_EVT: {
-        LOG_INFO("ESP_BT_GAP_PIN_REQ_EVT min_16_digit:%d", param->pin_req.min_16_digit);
+    	LOG_INFO("ESP_BT_GAP_PIN_REQ_EVT min_16_digit:%d", param->pin_req.min_16_digit);
         if (param->pin_req.min_16_digit) {
             LOG_INFO("Input pin code: 0000 0000 0000 0000");
             esp_bt_pin_code_t pin_code = {0};
@@ -434,7 +494,6 @@ void bt_app_gap_cb(esp_bt_gap_cb_event_t event, esp_bt_gap_cb_param_t *param)
     case ESP_BT_GAP_KEY_NOTIF_EVT:
         LOG_INFO("ESP_BT_GAP_KEY_NOTIF_EVT passkey:%d", param->key_notif.passkey);
         break;
-    case ESP_BT_GAP_KEY_REQ_EVT:
         LOG_INFO("ESP_BT_GAP_KEY_REQ_EVT Please enter passkey!");
         break;
 #endif
@@ -449,12 +508,14 @@ void bt_app_gap_cb(esp_bt_gap_cb_event_t event, esp_bt_gap_cb_param_t *param)
 
 static void bt_av_hdl_stack_evt(uint16_t event, void *p_param)
 {
-	LOG_DEBUG("%s evt %d", __func__, event);
+
     switch (event) {
     case BT_APP_EVT_STACK_UP: {
+    	LOG_INFO("BT Stack going up.");
         /* set up device name */
         char *dev_name = CONFIG_A2DP_DEV_NAME;
         esp_bt_dev_set_device_name(dev_name);
+        LOG_INFO("Preparing to connect to device: %s",CONFIG_A2DP_SINK_NAME);
 
         /* register GAP callback function */
         esp_bt_gap_register_callback(bt_app_gap_cb);
@@ -475,7 +536,7 @@ static void bt_av_hdl_stack_evt(uint16_t event, void *p_param)
         /* create and start heart beat timer */
         do {
             int tmr_id = 0;
-            s_tmr = xTimerCreate("connTmr", (10000 / portTICK_RATE_MS),
+            s_tmr = xTimerCreate("connTmr", (CONFIG_A2DP_CONTROL_DELAY_MS / portTICK_RATE_MS),
                                pdTRUE, (void *)tmr_id, a2d_app_heart_beat);
             xTimerStart(s_tmr, portMAX_DELAY);
         } while (0);
@@ -499,21 +560,28 @@ static int32_t bt_app_a2d_data_cb(uint8_t *data, int32_t len)
 	static unsigned min_o = -1, max_o = 0, min_s = -1, max_s = 0;
 	unsigned o, s;
 	
-	if (len < 0 || data == NULL) {
+
+	if (len < 0 || data == NULL ) {
         return 0;
     }
-    
-   	LOCK;
+	// bail out if A2DP isn't connected
+	LOCK;
+	if(s_media_state != APP_AV_MEDIA_STATE_STARTED)
+    {
+		UNLOCK;
+    	return 0;
+    }
+
 	
-/* TODO
-	Normally, we would want BT to not call us back unless we are not in BUFFERING state. 
+// todo: fix me!!
+/*	Normally, we would want BT to not call us back unless we are not in BUFFERING state.
 	That requires BT to not start until we are > OUTPUT_BUFFER
-	// come back later, we are buffering (or stopped, need to handle that case ...) but we don't want silence 
-	if (output.state <= OUTPUT_BUFFER) {
-		UNLOCK;
-		return 0;
-	}		
-*/	
+	// come back later, we are buffering (or stopped, need to handle that case ...) but we don't want silence */
+//	if (output.state <= OUTPUT_BUFFER) {
+//		UNLOCK;
+//		return 0;
+//	}
+
 
    	frames = len / 4;
    	output.device_frames = 0;
@@ -534,7 +602,7 @@ static int32_t bt_app_a2d_data_cb(uint8_t *data, int32_t len)
 	if (s < min_s) min_s = s;
 	if (s > max_s) max_s = s;
 	
-	if (!(count++ & 0x1ff)) {
+	if (!(count++ & 0x7ff)) {
 		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;
@@ -546,7 +614,8 @@ static int32_t bt_app_a2d_data_cb(uint8_t *data, int32_t len)
 bool test_open(const char *device, unsigned rates[], bool userdef_rates) {
 	memset(rates, 0, MAX_SUPPORTED_SAMPLERATES * sizeof(unsigned));
 	if (!strcmp(device, "BT")) {
-		rates[0] = 44100;
+		unsigned _rates[] = { 48000, 44100, 0 };	
+		memcpy(rates, _rates, sizeof(_rates));
 	} else {
 		unsigned _rates[] = { 96000, 88200, 48000, 44100, 32000, 0 };	
 		memcpy(rates, _rates, sizeof(_rates));
@@ -561,10 +630,13 @@ static void a2d_app_heart_beat(void *arg)
 
 static void bt_app_av_sm_hdlr(uint16_t event, void *param)
 {
-    LOG_INFO("%s state %d, evt 0x%x", __func__, s_a2d_state, event);
+    //LOG_DEBUG("%s state %s, evt 0x%x, output state: %d", __func__, APP_AV_STATE_DESC[s_a2d_state], event, output.state);
     switch (s_a2d_state) {
     case APP_AV_STATE_DISCOVERING:
+    	LOG_DEBUG("state %s, evt 0x%x, output state: %d", APP_AV_STATE_DESC[s_a2d_state], event, output.state);
+    	break;
     case APP_AV_STATE_DISCOVERED:
+    	LOG_DEBUG("state %s, evt 0x%x, output state: %d", APP_AV_STATE_DESC[s_a2d_state], event, output.state);
         break;
     case APP_AV_STATE_UNCONNECTED:
         bt_app_av_state_unconnected(event, param);
@@ -586,19 +658,47 @@ static void bt_app_av_sm_hdlr(uint16_t event, void *param)
 
 static void bt_app_av_state_unconnected(uint16_t event, void *param)
 {
-    switch (event) {
+	switch (event) {
     case ESP_A2D_CONNECTION_STATE_EVT:
+    	LOG_DEBUG_EVENT(ESP_A2D_CONNECTION_STATE_EVT);
+    	break;
     case ESP_A2D_AUDIO_STATE_EVT:
+    	LOG_DEBUG_EVENT(ESP_A2D_AUDIO_STATE_EVT);
+    	break;
     case ESP_A2D_AUDIO_CFG_EVT:
+    	LOG_DEBUG_EVENT(ESP_A2D_AUDIO_CFG_EVT);
+    	break;
     case ESP_A2D_MEDIA_CTRL_ACK_EVT:
-        break;
+    	LOG_DEBUG_EVENT(ESP_A2D_MEDIA_CTRL_ACK_EVT);
+    	break;
     case BT_APP_HEART_BEAT_EVT: {
         uint8_t *p = s_peer_bda;
-        LOG_INFO("a2dp connecting to peer: %02x:%02x:%02x:%02x:%02x:%02x",
-                 p[0], p[1], p[2], p[3], p[4], p[5]);
-        esp_a2d_source_connect(s_peer_bda);
-        s_a2d_state = APP_AV_STATE_CONNECTING;
-        s_connecting_intv = 0;
+        LOG_INFO("BT_APP_HEART_BEAT_EVT a2dp connecting to peer: %02x:%02x:%02x:%02x:%02x:%02x",p[0], p[1], p[2], p[3], p[4], p[5]);
+        switch (esp_bluedroid_get_status()) {
+		case ESP_BLUEDROID_STATUS_UNINITIALIZED:
+			LOG_INFO("BlueDroid Status is ESP_BLUEDROID_STATUS_UNINITIALIZED.");
+			break;
+		case ESP_BLUEDROID_STATUS_INITIALIZED:
+			LOG_INFO("BlueDroid Status is ESP_BLUEDROID_STATUS_INITIALIZED.");
+			break;
+		case ESP_BLUEDROID_STATUS_ENABLED:
+			LOG_INFO("BlueDroid Status is ESP_BLUEDROID_STATUS_ENABLED.");
+			break;
+			default:
+				break;
+		}
+        if(esp_a2d_source_connect(s_peer_bda)!=ESP_ERR_INVALID_STATE)
+		{
+			s_a2d_state = APP_AV_STATE_CONNECTING;
+			LOG_INFO("a2dp connecting to peer: %s", s_peer_bdname);
+			A2DP_TIMER_INIT;
+		}
+		else
+		{
+			// not discovered, continue to discover
+			LOG_INFO("Attempt at connecting failed, resuming discover...");
+			esp_bt_gap_start_discovery(ESP_BT_INQ_MODE_GENERAL_INQUIRY, 10, 0);
+		}
         break;
     }
     default:
@@ -610,11 +710,12 @@ static void bt_app_av_state_unconnected(uint16_t event, void *param)
 static void bt_app_av_state_connecting(uint16_t event, void *param)
 {
     esp_a2d_cb_param_t *a2d = NULL;
+
     switch (event) {
     case ESP_A2D_CONNECTION_STATE_EVT: {
         a2d = (esp_a2d_cb_param_t *)(param);
         if (a2d->conn_stat.state == ESP_A2D_CONNECTION_STATE_CONNECTED) {
-            LOG_INFO("a2dp connected");
+            LOG_INFO("a2dp connected! Stopping scan. ");
             s_a2d_state =  APP_AV_STATE_CONNECTED;
             s_media_state = APP_AV_MEDIA_STATE_IDLE;
             esp_bt_gap_set_scan_mode(ESP_BT_NON_CONNECTABLE, ESP_BT_NON_DISCOVERABLE);
@@ -624,14 +725,21 @@ static void bt_app_av_state_connecting(uint16_t event, void *param)
         break;
     }
     case ESP_A2D_AUDIO_STATE_EVT:
+    	LOG_DEBUG_EVENT(ESP_A2D_AUDIO_STATE_EVT);
+    	break;
     case ESP_A2D_AUDIO_CFG_EVT:
+    	LOG_DEBUG_EVENT(ESP_A2D_AUDIO_CFG_EVT);
+    	break;
     case ESP_A2D_MEDIA_CTRL_ACK_EVT:
-        break;
+    	LOG_DEBUG_EVENT(ESP_A2D_MEDIA_CTRL_ACK_EVT);
+    	break;
     case BT_APP_HEART_BEAT_EVT:
-        if (++s_connecting_intv >= 2) {
+    	if (IS_A2DP_TIMER_OVER)
+    	{
             s_a2d_state = APP_AV_STATE_UNCONNECTED;
-            s_connecting_intv = 0;
+            LOG_DEBUG("Connect timed out.  Setting state to Unconnected. ");
         }
+    	LOG_SDEBUG("BT_APP_HEART_BEAT_EVT");
         break;
     default:
         LOG_ERROR("%s unhandled evt %d", __func__, event);
@@ -639,31 +747,43 @@ static void bt_app_av_state_connecting(uint16_t event, void *param)
     }
 }
 
+
 static void bt_app_av_media_proc(uint16_t event, void *param)
 {
     esp_a2d_cb_param_t *a2d = NULL;
     switch (s_media_state) {
     case APP_AV_MEDIA_STATE_IDLE: {
-        if (event == BT_APP_HEART_BEAT_EVT) {
-            LOG_INFO("a2dp media ready checking ...");
-            esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_CHECK_SRC_RDY);
-        } else if (event == ESP_A2D_MEDIA_CTRL_ACK_EVT) {
-            a2d = (esp_a2d_cb_param_t *)(param);
-            if (a2d->media_ctrl_stat.cmd == ESP_A2D_MEDIA_CTRL_CHECK_SRC_RDY &&
-                    a2d->media_ctrl_stat.status == ESP_A2D_MEDIA_CTRL_ACK_SUCCESS) {
-                LOG_INFO("a2dp media ready, starting ...");
-                esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_START);
-                s_media_state = APP_AV_MEDIA_STATE_STARTING;
+    	if (event == BT_APP_HEART_BEAT_EVT) {
+            if(output.state <= OUTPUT_STOPPED )
+        	{
+        		// TODO: anything to do while we are waiting? Should we check if we're still connected?
+        	}
+            else if(output.state <= OUTPUT_BUFFER )
+            {
+            	LOG_INFO("buffering output, a2dp media ready and connected. Starting checking if ready...");
+            	esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_CHECK_SRC_RDY);
             }
+
+
+        } else if (event == ESP_A2D_MEDIA_CTRL_ACK_EVT) {
+        	a2d = (esp_a2d_cb_param_t *)(param);
+			if (a2d->media_ctrl_stat.cmd == ESP_A2D_MEDIA_CTRL_CHECK_SRC_RDY &&
+					a2d->media_ctrl_stat.status == ESP_A2D_MEDIA_CTRL_ACK_SUCCESS
+					) {
+				LOG_INFO("a2dp media ready, starting media playback ...");
+				s_media_state = APP_AV_MEDIA_STATE_STARTING;
+				esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_START);
+
+			}
         }
         break;
     }
     case APP_AV_MEDIA_STATE_STARTING: {
-        if (event == ESP_A2D_MEDIA_CTRL_ACK_EVT) {
+    	if (event == ESP_A2D_MEDIA_CTRL_ACK_EVT) {
             a2d = (esp_a2d_cb_param_t *)(param);
             if (a2d->media_ctrl_stat.cmd == ESP_A2D_MEDIA_CTRL_START &&
                     a2d->media_ctrl_stat.status == ESP_A2D_MEDIA_CTRL_ACK_SUCCESS) {
-                LOG_INFO("a2dp media start successfully.");
+                LOG_INFO("a2dp media started successfully.");
                 s_intv_cnt = 0;
                 s_media_state = APP_AV_MEDIA_STATE_STARTED;
             } else {
@@ -676,24 +796,29 @@ static void bt_app_av_media_proc(uint16_t event, void *param)
     }
     case APP_AV_MEDIA_STATE_STARTED: {
         if (event == BT_APP_HEART_BEAT_EVT) {
-            if (++s_intv_cnt >= 10) {
-                LOG_INFO("a2dp media stopping...");
-                esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_STOP);
+        	if(output.state <= OUTPUT_STOPPED) {
+                LOG_INFO("Output state is stopped. Stopping a2dp media ...");
                 s_media_state = APP_AV_MEDIA_STATE_STOPPING;
+                esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_STOP);
+
                 s_intv_cnt = 0;
             }
         }
         break;
     }
     case APP_AV_MEDIA_STATE_STOPPING: {
+    	LOG_DEBUG_EVENT(APP_AV_MEDIA_STATE_STOPPING);
         if (event == ESP_A2D_MEDIA_CTRL_ACK_EVT) {
             a2d = (esp_a2d_cb_param_t *)(param);
             if (a2d->media_ctrl_stat.cmd == ESP_A2D_MEDIA_CTRL_STOP &&
                     a2d->media_ctrl_stat.status == ESP_A2D_MEDIA_CTRL_ACK_SUCCESS) {
-                LOG_INFO("a2dp media stopped successfully, disconnecting...");
+                LOG_INFO("a2dp media stopped successfully...");
+                //s_media_state = APP_AV_MEDIA_STATE_WAIT_DISCONNECT;
+
                 s_media_state = APP_AV_MEDIA_STATE_IDLE;
-                esp_a2d_source_disconnect(s_peer_bda);
-                s_a2d_state = APP_AV_STATE_DISCONNECTING;
+                // todo:  should we disconnect?
+//                esp_a2d_source_disconnect(s_peer_bda);
+//                s_a2d_state = APP_AV_STATE_DISCONNECTING;
             } else {
                 LOG_INFO("a2dp media stopping...");
                 esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_STOP);
@@ -709,7 +834,7 @@ static void bt_app_av_state_connected(uint16_t event, void *param)
     esp_a2d_cb_param_t *a2d = NULL;
     switch (event) {
     case ESP_A2D_CONNECTION_STATE_EVT: {
-        a2d = (esp_a2d_cb_param_t *)(param);
+    	a2d = (esp_a2d_cb_param_t *)(param);
         if (a2d->conn_stat.state == ESP_A2D_CONNECTION_STATE_DISCONNECTED) {
             LOG_INFO("a2dp disconnected");
             s_a2d_state = APP_AV_STATE_UNCONNECTED;
@@ -718,6 +843,7 @@ static void bt_app_av_state_connected(uint16_t event, void *param)
         break;
     }
     case ESP_A2D_AUDIO_STATE_EVT: {
+    	LOG_DEBUG_EVENT(ESP_A2D_AUDIO_STATE_EVT);
         a2d = (esp_a2d_cb_param_t *)(param);
         if (ESP_A2D_AUDIO_STATE_STARTED == a2d->audio_stat.state) {
             s_pkt_cnt = 0;
@@ -726,9 +852,15 @@ static void bt_app_av_state_connected(uint16_t event, void *param)
     }
     case ESP_A2D_AUDIO_CFG_EVT:
         // not suppposed to occur for A2DP source
+    	LOG_DEBUG_EVENT(ESP_A2D_AUDIO_CFG_EVT);
         break;
-    case ESP_A2D_MEDIA_CTRL_ACK_EVT:
+    case ESP_A2D_MEDIA_CTRL_ACK_EVT:{
+        	LOG_DEBUG_EVENT(ESP_A2D_MEDIA_CTRL_ACK_EVT);
+            bt_app_av_media_proc(event, param);
+            break;
+        }
     case BT_APP_HEART_BEAT_EVT: {
+    	LOG_SDEBUG_EVENT(BT_APP_HEART_BEAT_EVT);
         bt_app_av_media_proc(event, param);
         break;
     }
@@ -743,6 +875,7 @@ static void bt_app_av_state_disconnecting(uint16_t event, void *param)
     esp_a2d_cb_param_t *a2d = NULL;
     switch (event) {
     case ESP_A2D_CONNECTION_STATE_EVT: {
+    	LOG_DEBUG_EVENT(ESP_A2D_CONNECTION_STATE_EVT);
         a2d = (esp_a2d_cb_param_t *)(param);
         if (a2d->conn_stat.state == ESP_A2D_CONNECTION_STATE_DISCONNECTED) {
             LOG_INFO("a2dp disconnected");
@@ -752,10 +885,17 @@ static void bt_app_av_state_disconnecting(uint16_t event, void *param)
         break;
     }
     case ESP_A2D_AUDIO_STATE_EVT:
+    	LOG_DEBUG_EVENT(ESP_A2D_AUDIO_STATE_EVT);
+    	break;
     case ESP_A2D_AUDIO_CFG_EVT:
+    	LOG_DEBUG_EVENT(ESP_A2D_AUDIO_CFG_EVT);
+    	break;
     case ESP_A2D_MEDIA_CTRL_ACK_EVT:
+    	LOG_DEBUG_EVENT(ESP_A2D_MEDIA_CTRL_ACK_EVT);
+    	break;
     case BT_APP_HEART_BEAT_EVT:
-        break;
+    	LOG_DEBUG_EVENT(BT_APP_HEART_BEAT_EVT);
+    	break;
     default:
         LOG_ERROR("%s unhandled evt %d", __func__, event);
         break;

sdkconfig.defaults

@@ -48,4 +48,5 @@ CONFIG_ESPTOOLPY_BAUD_2MB=y
 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_CONTROL_DELAY_MS=500
+CONFIG_A2DP_CONNECT_TIMEOUT_MS=1000