Stabilizations

.cproject

@@ -64,4 +64,33 @@
 			<autodiscovery enabled="true" problemReportingEnabled="true" selectedProfileId=""/>
 		</scannerConfigBuildInfo>
 	</storageModule>
+	<storageModule moduleId="refreshScope"/>
+	<storageModule moduleId="org.eclipse.cdt.make.core.buildtargets">
+		<buildTargets>
+			<target name="all" path="" targetID="org.eclipse.cdt.build.MakeTargetBuilder">
+				<buildCommand>make</buildCommand>
+				<buildArguments/>
+				<buildTarget>all</buildTarget>
+				<stopOnError>true</stopOnError>
+				<useDefaultCommand>true</useDefaultCommand>
+				<runAllBuilders>true</runAllBuilders>
+			</target>
+			<target name="size-components" path="" targetID="org.eclipse.cdt.build.MakeTargetBuilder">
+				<buildCommand>make</buildCommand>
+				<buildArguments/>
+				<buildTarget>size-components</buildTarget>
+				<stopOnError>true</stopOnError>
+				<useDefaultCommand>true</useDefaultCommand>
+				<runAllBuilders>true</runAllBuilders>
+			</target>
+			<target name="flash" path="" targetID="org.eclipse.cdt.build.MakeTargetBuilder">
+				<buildCommand>make</buildCommand>
+				<buildArguments/>
+				<buildTarget>flash</buildTarget>
+				<stopOnError>true</stopOnError>
+				<useDefaultCommand>true</useDefaultCommand>
+				<runAllBuilders>true</runAllBuilders>
+			</target>
+		</buildTargets>
+	</storageModule>
 </cproject>

components/platform_esp32/cmd_squeezelite.c

@@ -16,7 +16,7 @@
 #include "nvs_flash.h"
 //extern char current_namespace[];
 static const char * TAG = "squeezelite_cmd";
-#define SQUEEZELITE_THREAD_STACK_SIZE 20480
+#define SQUEEZELITE_THREAD_STACK_SIZE 32000
 extern int main(int argc, char **argv);
 static int launchsqueezelite(int argc, char **argv);
 pthread_t thread_squeezelite;
@@ -45,11 +45,11 @@ static void * squeezelite_thread(){
 	}
 	isRunning=true;
 	ESP_LOGI(TAG,"Waiting for WiFi.");
-	while(!wait_for_wifi()){};
+	while(!wait_for_wifi()){usleep(100000);};
 	ESP_LOGD(TAG ,"Number of args received: %u",thread_parms.argc );
-	ESP_LOGV(TAG ,"Values:");
+	ESP_LOGD(TAG ,"Values:");
     for(int i = 0;i<thread_parms.argc; i++){
-    	ESP_LOGV(TAG ,"     %s",thread_parms.argv[i]);
+    	ESP_LOGD(TAG ,"     %s",thread_parms.argv[i]);
     }
 
     ESP_LOGD(TAG,"Starting Squeezelite runner Thread");
@@ -75,57 +75,14 @@ static void * squeezelite_thread(){
 	isRunning=false;
 	return NULL;
 }
-//static int launchsqueezelite_dft(int _argc, char **_argv){
-//	nvs_handle nvs;
-//	esp_err_t err;
-//	optListStruct * curOpt=&optList[0];
-//	ESP_LOGV(TAG ,"preparing to allocate memory ");
-//	int argc =_argc+50; // todo: max number of parms?
-//	char ** argv = malloc(sizeof(char**)*argc);
-//	memset(argv,'\0',sizeof(char**)*argc);
-//	int curOptNum=0;
-//	argv[curOptNum++]=strdup(_argv[0]);
-//	ESP_LOGV(TAG ,"nvs_open\n");
-//	err = nvs_open(current_namespace, NVS_READONLY, &nvs);
-//	if (err != ESP_OK) {
-//		return err;
-//	}
-//
-//	while(curOpt->optName!=NULL){
-//		ESP_LOGV(TAG ,"Checking option %s with default value %s",curOpt->optName, curOpt->defaultValue);
-//		if(!strcmp(curOpt->relatedcommand,"squeezelite"))
-//		{
-//			ESP_LOGV(TAG ,"option is for Squeezelite command, processing it");
-//			// this is a squeezelite option
-//			if(curOpt->cmdLinePrefix!=NULL){
-//				ESP_LOGV(TAG ,"adding prefix %s",curOpt->cmdLinePrefix);
-//				argv[curOptNum++]=strdup(curOpt->cmdLinePrefix);
-//			}
-//			size_t len;
-//			if ( (nvs_get_str(nvs, curOpt->optName, NULL, &len)) == ESP_OK) {
-//				char *str = (char *)malloc(len);
-//				nvs_get_str(nvs, curOpt->optName, str, &len);
-//				ESP_LOGV(TAG ,"assigning retrieved value %s",str);
-//				argv[curOptNum++]=str;
-//
-//			}
-//		}
-//		curOpt++;
-//	}
-//	nvs_close(nvs);
-//	ESP_LOGV(TAG ,"calling launchsqueezelite with parameters");
-//	launchsqueezelite(argc, argv);
-//	ESP_LOGV(TAG ,"back from calling launchsqueezelite");
-//	return 0;
-//}
 
 static int launchsqueezelite(int argc, char **argv)
 {
 	ESP_LOGV(TAG ,"Begin");
 
-    ESP_LOGV(TAG, "Parameters:");
+    ESP_LOGD(TAG, "Parameters:");
     for(int i = 0;i<argc; i++){
-    	ESP_LOGV(TAG, "     %s",argv[i]);
+    	ESP_LOGD(TAG, "     %s",argv[i]);
     }
     ESP_LOGV(TAG,"Saving args in thread structure");
 

components/platform_esp32/console.c

@@ -202,7 +202,7 @@ void initialize_console() {
 	esp_vfs_dev_uart_use_driver(CONFIG_CONSOLE_UART_NUM);
 
 	/* Initialize the console */
-	esp_console_config_t console_config = { .max_cmdline_args = 8,
+	esp_console_config_t console_config = { .max_cmdline_args = 22,
 			.max_cmdline_length = 256,
 #if CONFIG_LOG_COLORS
 			.hint_color = atoi(LOG_COLOR_CYAN)

components/platform_esp32/perf_trace.h

@@ -16,9 +16,9 @@
 #define SET_MIN_MAX_SIZED(val,var,siz) var=val; if(var<min_##var) min_##var=var; if(var>max_##var) max_##var=var; count_##var++; avgtot_##var+= var;size_##var=siz
 #define RESET_MIN_MAX(var) min_##var=PERF_MAX; max_##var=0; avgtot_##var=0;count_##var=0;var=0;size_##var=0
 #define RESET_MIN_MAX_DURATION(var) min_##var=PERF_MAX; max_##var=0; avgtot_##var=0;count_##var=0;var=0
-#define DECLARE_MIN_MAX(var) static uint32_t min_##var = PERF_MAX, max_##var = 0, size_##var = 0,avgtot_##var = 0, count_##var=0; uint32_t var=0
-#define DECLARE_MIN_MAX_DURATION(var) static uint32_t min_##var = PERF_MAX, max_##var = 0, avgtot_##var = 0, count_##var=0; uint32_t var=0
-#define LINE_MIN_MAX_AVG(var) (count_##var>0?avgtot_##var/count_##var:0)
+#define DECLARE_MIN_MAX(var) static uint32_t min_##var = PERF_MAX, max_##var = 0, size_##var = 0, count_##var=0;uint64_t avgtot_##var = 0; uint32_t var=0
+#define DECLARE_MIN_MAX_DURATION(var) static uint32_t min_##var = PERF_MAX, max_##var = 0, count_##var=0; uint64_t avgtot_##var = 0; uint32_t var=0
+#define LINE_MIN_MAX_AVG(var) (uint32_t)(count_##var>0?avgtot_##var/count_##var:0)
 
 #define LINE_MIN_MAX_FORMAT_HEAD1  "              +----------+----------+----------------+-----+----------------+"
 #define LINE_MIN_MAX_FORMAT_HEAD2  "              |      max |      min |        average |     |        count   |"

components/platform_esp32/platform_esp32.c

@@ -36,7 +36,7 @@
 #include "argtable3/argtable3.h"
 
 #define STATS_REPORT_DELAY_MS 15000
-static const char * TAG = "platform_esp32";
+static const char * TAG = "platform";
 extern char * get_output_state_desc(output_state state);
 
 extern struct outputstate output;
@@ -50,6 +50,7 @@ time_t disconnect_time=0;
 #define LOCK   pthread_mutex_lock(&(outputbuf->mutex))
 #define UNLOCK pthread_mutex_unlock(&(outputbuf->mutex))
 int64_t connecting_timeout = 0;
+
 static const char *  art_a2dp_connected[]={"\n",
 		"           ___  _____  _____     _____                            _           _ _ ",
 		"     /\\   |__ \\|  __ \\|  __ \\   / ____|                          | |         | | |",
@@ -136,7 +137,7 @@ char * APP_AV_STATE_DESC[] = {
 enum {
     APP_AV_MEDIA_STATE_IDLE,
     APP_AV_MEDIA_STATE_STARTING,
-	APP_AV_MEDIA_STATE_BUFFERING,
+//	APP_AV_MEDIA_STATE_BUFFERING,
     APP_AV_MEDIA_STATE_STARTED,
     APP_AV_MEDIA_STATE_STOPPING,
 	APP_AV_MEDIA_STATE_WAIT_DISCONNECT
@@ -411,7 +412,6 @@ static void a2d_app_heart_beat(void *arg)
 
 static void bt_app_av_sm_hdlr(uint16_t event, void *param)
 {
-    //ESP_LOGD(TAG,"%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:
     	ESP_LOGV(TAG,"state %s, evt 0x%x, output state: %s", APP_AV_STATE_DESC[s_a2d_state], event, get_output_state_desc(output.state));
@@ -488,6 +488,12 @@ static void filter_inquiry_scan_result(esp_bt_gap_cb_param_t *param)
     uint8_t *eir = NULL;
     uint8_t nameLen = 0;
     esp_bt_gap_dev_prop_t *p;
+    if(s_a2d_state != APP_AV_STATE_DISCOVERING)
+    {
+    	// Ignore messages that might have been queued already
+    	// when we've discovered the target device.
+    	return;
+    }
     memset(s_peer_bdname, 0x00,sizeof(s_peer_bdname));
 
     ESP_LOGI(TAG,"\n=======================\nScanned device: %s", bda2str(param->disc_res.bda, bda_str, 18));
@@ -630,7 +636,7 @@ static void bt_app_av_media_proc(uint16_t event, void *param)
     	if (event == BT_APP_HEART_BEAT_EVT) {
             if(out_state > OUTPUT_STOPPED)
             {
-            	ESP_LOGI(TAG,"Output state is %s, a2dp media ready and connected. Checking if A2DP is ready.", get_output_state_desc(out_state));
+            	ESP_LOGI(TAG,"Output state is %s, Checking if A2DP is ready.", get_output_state_desc(out_state));
             	esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_CHECK_SRC_RDY);
             }
 
@@ -639,43 +645,13 @@ static void bt_app_av_media_proc(uint16_t event, void *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
 					) {
-				ESP_LOGI(TAG,"a2dp media ready, waiting for media buffering ...");
-				s_media_state = APP_AV_MEDIA_STATE_BUFFERING;
+				ESP_LOGI(TAG,"a2dp media ready, starting playback!");
+				s_media_state = APP_AV_MEDIA_STATE_STARTING;
+				esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_START);
 			}
         }
         break;
     }
-    case APP_AV_MEDIA_STATE_BUFFERING: {
-      	if (event == BT_APP_HEART_BEAT_EVT) {
-      		switch (out_state) {
-				case OUTPUT_RUNNING :
-				case OUTPUT_PAUSE_FRAMES :
-				case OUTPUT_SKIP_FRAMES:
-				case OUTPUT_START_AT:
-				case OUTPUT_BUFFER:
-	            	 // Buffer is ready, local buffer has some data, start playback!
-					ESP_LOGI(TAG,"Out state is %s, a2dp media ready and connected. Starting playback! ", get_output_state_desc(out_state));
-					s_media_state = APP_AV_MEDIA_STATE_STARTING;
-					esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_START);
-					break;
-				case OUTPUT_STOPPED:
-				case OUTPUT_OFF:
-					ESP_LOGD(TAG,"Output state is %s. Changing app status to ",get_output_state_desc(out_state));
-	                s_media_state = APP_AV_MEDIA_STATE_STOPPING;
-	                esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_STOP);
-	                break;
-				default:
-					ESP_LOGE(TAG,"Unknown output status while waiting for buffering to complete %d",out_state);
-					break;
-			}
-          }
-      	else{
-      		ESP_LOGW(TAG,"Received unknown event while in state APP_AV_MEDIA_STATE_BUFFERING");
-      	}
-
-          break;
-      }
-
 
     case APP_AV_MEDIA_STATE_STARTING: {
     	if (event == ESP_A2D_MEDIA_CTRL_ACK_EVT) {
@@ -695,7 +671,7 @@ 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(out_state <= OUTPUT_STOPPED) {
-        		ESP_LOGI(TAG,"Output state is stopped. Stopping a2dp media ...");
+        		ESP_LOGI(TAG,"Output state is %s. Stopping a2dp media ...", get_output_state_desc(out_state));
                 s_media_state = APP_AV_MEDIA_STATE_STOPPING;
                 esp_a2d_media_ctrl(ESP_A2D_MEDIA_CTRL_STOP);
             }
@@ -812,13 +788,13 @@ static void bt_app_av_state_unconnected(uint16_t event, void *param)
 		}
 //        if(out_state > OUTPUT_STOPPED){
         	// only attempt a connect when playback isn't stopped
+			for(uint8_t l=0;art_a2dp_connecting[l][0]!='\0';l++){
+				ESP_LOGI(TAG,"%s",art_a2dp_connecting[l]);
+			}
+			ESP_LOGI(TAG,"Device: %s", s_peer_bdname);
 			if(esp_a2d_source_connect(s_peer_bda)==ESP_OK) {
-				s_a2d_state = APP_AV_STATE_CONNECTING;
-				for(uint8_t l=0;art_a2dp_connecting[l][0]!='\0';l++){
-					ESP_LOGI(TAG,"%s",art_a2dp_connecting[l]);
-				}
-				ESP_LOGI(TAG,"********** A2DP CONNECTING TO %s", s_peer_bdname);
 				A2DP_TIMER_INIT;
+				s_a2d_state = APP_AV_STATE_CONNECTING;
 			}
 			else {
 				// there was an issue connecting... continue to discover
@@ -844,12 +820,13 @@ static void bt_app_av_state_connecting(uint16_t event, void *param)
         if (a2d->conn_stat.state == ESP_A2D_CONNECTION_STATE_CONNECTED) {
             s_a2d_state =  APP_AV_STATE_CONNECTED;
             s_media_state = APP_AV_MEDIA_STATE_IDLE;
-			for(uint8_t l=0;art_a2dp_connected[l][0]!='\0';l++){
-				ESP_LOGI(TAG,"%s",art_a2dp_connected[l]);
-			}
+
 			ESP_LOGD(TAG,"Setting scan mode to ESP_BT_NON_CONNECTABLE, ESP_BT_NON_DISCOVERABLE");
             esp_bt_gap_set_scan_mode(ESP_BT_NON_CONNECTABLE, ESP_BT_NON_DISCOVERABLE);
             ESP_LOGD(TAG,"Done setting scan mode. App state is now CONNECTED and media state IDLE.");
+			for(uint8_t l=0;art_a2dp_connected[l][0]!='\0';l++){
+				ESP_LOGI(TAG,"%s",art_a2dp_connected[l]);
+			}
         } else if (a2d->conn_stat.state == ESP_A2D_CONNECTION_STATE_DISCONNECTED) {
             s_a2d_state =  APP_AV_STATE_UNCONNECTED;
         }
@@ -868,8 +845,7 @@ static void bt_app_av_state_connecting(uint16_t event, void *param)
     	if (IS_A2DP_TIMER_OVER)
     	{
             s_a2d_state = APP_AV_STATE_UNCONNECTED;
-            ESP_LOGE(TAG,"A2DP Connect time out!  Setting state to Unconnected. ");
-            A2DP_TIMER_INIT;
+            ESP_LOGW(TAG,"A2DP Connect time out!  Setting state to Unconnected. ");
         }
     	ESP_LOGV(TAG,"BT_APP_HEART_BEAT_EVT");
         break;
@@ -911,7 +887,7 @@ static void bt_app_av_state_connected(uint16_t event, void *param)
             break;
         }
     case BT_APP_HEART_BEAT_EVT: {
-    	ESP_LOG_DEBUG_EVENT(TAG,QUOTE(BT_APP_HEART_BEAT_EVT));
+    	ESP_LOGV(TAG,QUOTE(BT_APP_HEART_BEAT_EVT));
         bt_app_av_media_proc(event, param);
         break;
     }
@@ -952,3 +928,17 @@ static void bt_app_av_state_disconnecting(uint16_t event, void *param)
         break;
     }
 }
+const char *loc_logtime(void) {
+	static char buf[100];
+#if WIN
+	SYSTEMTIME lt;
+	GetLocalTime(&lt);
+	sprintf(buf, "[%02d:%02d:%02d.%03d]", lt.wHour, lt.wMinute, lt.wSecond, lt.wMilliseconds);
+#else
+	struct timeval tv;
+	gettimeofday(&tv, NULL);
+	strftime(buf, sizeof(buf), "[%T.", localtime(&tv.tv_sec));
+	sprintf(buf+strlen(buf), "%06ld]", (long)tv.tv_usec);
+#endif
+	return buf;
+}

components/platform_esp32/platform_esp32.h

@@ -64,102 +64,30 @@ extern pthread_t wifi_connect_suspend_mutex;
 //		""
 //};
 #define ESP_LOG_DEBUG_EVENT(tag,e) ESP_LOGD(tag,"evt: " e)
-typedef struct {
-	char * optName;
-	char * cmdLinePrefix;
-	char * description;
-	char * defaultValue;
-	char * relatedcommand;
-} optListStruct;
-optListStruct * getOptionByName(char * option);
-//static optListStruct optList[] = {
-//	{
-//		.optName= "log_slimproto",
-//		.cmdLinePrefix="-d slimproto=",
-//		.description="Slimproto Logging Level info|debug|sdebug",
-//		.defaultValue=(CONFIG_LOGGING_SLIMPROTO),
-//		.relatedcommand="squeezelite"
-//	},
-//	{
-//		.optName="log_stream",
-//		.cmdLinePrefix="-d stream=",
-//		.description="Stream Logging Level info|debug|sdebug",
-//		.defaultValue=(CONFIG_LOGGING_STREAM),
-//		.relatedcommand="squeezelite"
-//	},
-//	{
-//		.optName="log_decode",
-//		.cmdLinePrefix="-d decode=",
-//		.description="Decode Logging Level info|debug|sdebug",
-//		.defaultValue=(CONFIG_LOGGING_DECODE),
-//		.relatedcommand="squeezelite"
-//	},
-//	{
-//		.optName="log_output",
-//		.cmdLinePrefix="-d output=",
-//		.description="Output Logging Level info|debug|sdebug",
-//		.defaultValue=(CONFIG_LOGGING_OUTPUT),
-//		.relatedcommand="squeezelite"
-//	},
-//	{
-//		.optName="output_rates",
-//		.cmdLinePrefix="-r ",
-//		.description="Supported rates",
-//		.defaultValue=(CONFIG_OUTPUT_RATES),
-//		.relatedcommand="squeezelite"
-//	},
-//	{
-//		.optName="output_dev",
-//		.cmdLinePrefix="-O",
-//		.description="Output device to use. BT for Bluetooth, DAC for i2s DAC.",
-//		.defaultValue=(CONFIG_A2DP_SINK_NAME),
-//		.relatedcommand=""
-//	},
-//	{
-//		.optName="a2dp_sink_name",
-//		.cmdLinePrefix="",
-//		.description="Bluetooth sink name to connect to.",
-//		.defaultValue=(CONFIG_A2DP_SINK_NAME),
-//		.relatedcommand=""
-//	},
-//	{
-//		.optName="a2dp_dev_name",
-//		.cmdLinePrefix="",
-//		.description="A2DP Device name to use when connecting to audio sink.",
-//		.defaultValue=(CONFIG_A2DP_DEV_NAME),
-//		.relatedcommand=""
-//	},
-//	{
-//		.optName="a2dp_cntrldelay",
-//		.cmdLinePrefix="",
-//		.description="Delay (ms) for each pass of the A2DP control loop.",
-//		.defaultValue=STR(CONFIG_A2DP_CONTROL_DELAY_MS),
-//		.relatedcommand=""
-//	},
-//	{
-//		.optName="a2dp_timeout",
-//		.cmdLinePrefix="",
-//		.description="Delay (ms) for A2DP timeout on connect.",
-//		.defaultValue=STR(CONFIG_A2DP_CONNECT_TIMEOUT_MS),
-//		.relatedcommand=""
-//	},
-//	{
-//		.optName="wifi_ssid",
-//		.cmdLinePrefix="",
-//		.description="WiFi access point name to connect to.",
-//		.defaultValue=	(CONFIG_WIFI_SSID),
-//		.relatedcommand=""
-//	},
-//	{
-//		.optName="wifi_password",
-//		.cmdLinePrefix= "",
-//		.description="WiFi access point password.",
-//		.defaultValue=(CONFIG_WIFI_PASSWORD),
-//		.relatedcommand=""
-//	},
-//	{}
-//};
-
+const char *loc_logtime(void);
+//#define MY_ESP_LOG
+#ifdef MY_ESP_LOG
+#ifdef ESP_LOGI
+#undef ESP_LOGI
+#define ESP_LOGI(tag, format, ... ) ESP_LOG_LEVEL_LOCAL(ESP_LOG_INFO,    tag, "%s %d " format,loc_logtime(),  __LINE__, ##__VA_ARGS__)
+#endif
+#ifdef ESP_LOGE
+#undef ESP_LOGE
+#define ESP_LOGE(tag, format, ... ) ESP_LOG_LEVEL_LOCAL(ESP_LOG_ERROR,    tag, "%s %d " format,loc_logtime(),  __LINE__, ##__VA_ARGS__)
+#endif
+#ifdef ESP_LOGW
+#undef ESP_LOGW
+#define ESP_LOGW(tag, format, ... ) ESP_LOG_LEVEL_LOCAL(ESP_LOG_WARN,    tag, "%s %d " format,loc_logtime(),  __LINE__, ##__VA_ARGS__)
+#endif
+#ifdef ESP_LOGD
+#undef ESP_LOGD
+#define ESP_LOGD(tag, format, ... ) ESP_LOG_LEVEL_LOCAL(ESP_LOG_DEBUG,    tag, "%s %d " format,loc_logtime(),  __LINE__, ##__VA_ARGS__)
+#endif
+#ifdef ESP_LOGV
+#undef ESP_LOGV
+#define ESP_LOGV(tag, format, ... ) ESP_LOG_LEVEL_LOCAL(ESP_LOG_VERBOSE, tag, "%s %d " format,loc_logtime(),  __LINE__, ##__VA_ARGS__)
+#endif
+#endif
 #ifdef __cplusplus
 }
 #endif

sdkconfig

@@ -77,6 +77,8 @@ CONFIG_LOGGING_SLIMPROTO="debug"
 CONFIG_LOGGING_STREAM="debug"
 CONFIG_LOGGING_DECODE="debug"
 CONFIG_LOGGING_OUTPUT="debug"
+CONFIG_WIFI_SSID="myssid"
+CONFIG_WIFI_PASSWORD="mypassword"
 CONFIG_WIFI_FAST_SCAN=y
 # CONFIG_WIFI_ALL_CHANNEL_SCAN is not set
 CONFIG_WIFI_CONNECT_AP_BY_SIGNAL=y