Stabilize HTTP server, change logging

components/wifi-manager/http_server.c

@@ -89,9 +89,9 @@ const static char http_redirect_hdr_end[] = "/\n\n";
 
 
 
-void http_server_start(){
+void http_server_start() {
 
-	if(task_http_server == NULL){
+	if(task_http_server == NULL) {
 		xTaskCreate(&http_server, "http_server", 1024*5, NULL, WIFI_MANAGER_TASK_PRIORITY, &task_http_server);
 	}
 }
@@ -105,7 +105,7 @@ void http_server(void *pvParameters) {
 	ESP_LOGI(TAG, "HTTP Server listening on 80/tcp");
 	do {
 		err = netconn_accept(conn, &newconn);
-		if (err == ERR_OK) {
+		if(err == ERR_OK) {
 			http_server_netconn_serve(newconn);
 			netconn_delete(newconn);
 		}
@@ -130,7 +130,7 @@ char* http_server_get_header(char *request, char *header_name, int *len) {
 	char *ptr = NULL;
 
 	ptr = strstr(request, header_name);
-	if (ptr) {
+	if(ptr) {
 		ret = ptr + strlen(header_name);
 		ptr = ret;
 		while (*ptr != '\0' && *ptr != '\n' && *ptr != '\r') {
@@ -147,31 +147,31 @@ char* http_server_search_header(char *request, char *header_name, int *len, char
 	char *ptr = NULL;
 	int currentLength=0;
 
-	ESP_LOGD(TAG, "header name: [%s]\nRequest: %s", header_name, request);
+	ESP_LOGV(TAG, "searching for header name: [%s]", header_name);
 	ptr = strstr(request, header_name);
 
 
-	if (ptr!=NULL && ptr<bufEnd) {
+	if(ptr!=NULL && ptr<bufEnd) {
 		ret = ptr + strlen(header_name);
 		ptr = ret;
 		currentLength=(int)(ptr-request);
-		ESP_LOGD(TAG, "found string at %d", currentLength);
+		ESP_LOGV(TAG, "found string at %d", currentLength);
 
 		while (*ptr != '\0' && *ptr != '\n' && *ptr != '\r' && *ptr != ':' && ptr<bufEnd) {
 			ptr++;
 		}
-		if(*ptr==':'){
+		if(*ptr==':') {
 			currentLength=(int)(ptr-ret);
-			ESP_LOGD(TAG, "Found parameter name end, length : %d", currentLength);
+			ESP_LOGV(TAG, "Found parameter name end, length : %d", currentLength);
 			// save the parameter name: the string between header name and ":"
 			*parm_name=malloc(currentLength+1);
-			if(*parm_name==NULL){
+			if(*parm_name==NULL) {
 				ESP_LOGE(TAG, "Unable to allocate memory for new header name");
 				return NULL;
 			}
 			memset(*parm_name, 0x00,currentLength+1);
 			strncpy(*parm_name,ret,currentLength);
-			ESP_LOGD(TAG, "Found parameter name : %s ", *parm_name);
+			ESP_LOGV(TAG, "Found parameter name : %s ", *parm_name);
 			ptr++;
 			while (*ptr == ' ' && ptr<bufEnd) {
 				ptr++;
@@ -186,7 +186,7 @@ char* http_server_search_header(char *request, char *header_name, int *len, char
 		// Terminate value inside its actual buffer so we can treat it as individual string
 		*ptr='\0';
 		currentLength=(int)(ptr-ret);
-		ESP_LOGD(TAG, "Found parameter value end, length : %d, 	value: %s", currentLength,ret );
+		ESP_LOGV(TAG, "Found parameter value end, length : %d, 	value: %s", currentLength,ret );
 
 		*next_position=++ptr;
 		return ret;
@@ -194,11 +194,11 @@ char* http_server_search_header(char *request, char *header_name, int *len, char
 	ESP_LOGD(TAG, "No more match for : %s", header_name);
 	return NULL;
 }
-void http_server_send_resource_file(struct netconn *conn,const uint8_t * start, const uint8_t * end, char * content_type,char * encoding){
+void http_server_send_resource_file(struct netconn *conn,const uint8_t * start, const uint8_t * end, char * content_type,char * encoding) {
 	uint16_t len=end - start;
 	size_t  buff_length= sizeof(http_hdr_template)+strlen(content_type)+strlen(encoding);
 	char * http_hdr=malloc(buff_length);
-	if( http_hdr == NULL){
+	if( http_hdr == NULL) {
 		ESP_LOGE(TAG,"Cound not allocate %d bytes for headers.",buff_length);
 		netconn_write(conn, http_503_hdr, sizeof(http_503_hdr) - 1, NETCONN_NOCOPY);
 	}
@@ -213,19 +213,19 @@ void http_server_send_resource_file(struct netconn *conn,const uint8_t * start,
 	}
 }
 
-err_t http_server_nvs_dump(struct netconn *conn, nvs_type_t nvs_type){
+err_t http_server_nvs_dump(struct netconn *conn, nvs_type_t nvs_type) {
 	nvs_entry_info_t info;
 	char * num_buffer = NULL;
 	cJSON * nvs_json = cJSON_CreateObject();
 	num_buffer = malloc(NUM_BUFFER_LEN);
 	nvs_iterator_t it = nvs_entry_find(settings_partition, NULL, nvs_type);
-	if (it == NULL) {
+	if(it == NULL) {
 		ESP_LOGW(TAG, "No nvs entry found in %s",NVS_PARTITION_NAME );
 	}
-	while (it != NULL){
+	while (it != NULL) {
 		nvs_entry_info(it, &info);
 		memset(num_buffer,0x00,NUM_BUFFER_LEN);
-		if(strstr(info.namespace_name, current_namespace)){
+		if(strstr(info.namespace_name, current_namespace)) {
 			void * value = get_nvs_value_alloc(nvs_type,info.key);
 			if(value==NULL)
 			{
@@ -277,13 +277,13 @@ err_t http_server_nvs_dump(struct netconn *conn, nvs_type_t nvs_type){
 	return ESP_OK;
 }
 
-void http_server_process_config(struct netconn *conn, 	char *inbuf){
+void http_server_process_config(struct netconn *conn, 	char *inbuf) {
 
 	// Here, we are passed a buffer which contains the http request
 
 //		netbuf_data(inbuf, (void**)&buf, &buflen);
 //		err = netconn_recv(conn, &inbuf);
-//		if (err == ERR_OK) {
+//		if(err == ERR_OK) {
 //
 //		/* extract the first line of the request */
 //		char *save_ptr = buf;
@@ -294,9 +294,9 @@ void http_server_process_config(struct netconn *conn, 	char *inbuf){
 	char *ptr = NULL;
 	last = ptr = inbuf;
 	bool bHeaders= true;
-	while(ptr!=NULL && *ptr != '\0'){
+	while(ptr!=NULL && *ptr != '\0') {
 		// Move to the end of the line, or to the end of the buffer
-		if(bHeaders){
+		if(bHeaders) {
 			while (*ptr != '\0' && *ptr != '\n' && *ptr != '\r') {
 				ptr++;
 			}
@@ -314,7 +314,7 @@ void http_server_process_config(struct netconn *conn, 	char *inbuf){
 				ESP_LOGD(TAG,"Processing body. ");
 				break;
 			}
-			if(strlen(last)>0){
+			if(strlen(last)>0) {
 				ESP_LOGD(TAG,"Found Header Line %s ", last);
 				//Content-Type: application/json
 			}
@@ -337,7 +337,17 @@ void http_server_process_config(struct netconn *conn, 	char *inbuf){
 
 }
 
-
+void dump_net_buffer(void * buf, u16_t buflen) {
+	char * curbuf = malloc(buflen+1);
+	ESP_LOGD(TAG,"netconn buffer, length=%u",buflen);
+	if(curbuf==NULL) {
+		ESP_LOGE(TAG,"Unable to show netconn buffer.  Malloc failed");
+	}
+	memset(curbuf,0x0, buflen+1);
+	memcpy(curbuf,buf,buflen);
+	ESP_LOGV(TAG,"netconn buffer content:\n%s",curbuf);
+	free(curbuf);
+}
 
 void http_server_netconn_serve(struct netconn *conn) {
 
@@ -348,14 +358,15 @@ void http_server_netconn_serve(struct netconn *conn) {
 	const char new_line[2] = "\n";
 
 	err = netconn_recv(conn, &inbuf);
-	if (err == ERR_OK) {
+	if(err == ERR_OK) {
 
 		netbuf_data(inbuf, (void**)&buf, &buflen);
+		dump_net_buffer(buf, buflen);
 
 		/* extract the first line of the request */
 		char *save_ptr = buf;
 		char *line = strtok_r(save_ptr, new_line, &save_ptr);
-		ESP_LOGD(TAG,"http_server_netconn_serve Processing line %s, socket: %u",line, conn->socket);
+		ESP_LOGD(TAG,"http_server_netconn_serve Processing line %s",line);
 
 		if(line) {
 
@@ -363,7 +374,7 @@ void http_server_netconn_serve(struct netconn *conn) {
 			int lenH = 0;
 			char *host = http_server_get_header(save_ptr, "Host: ", &lenH);
 			const char * host_name=NULL;
-			if((err=tcpip_adapter_get_hostname(TCPIP_ADAPTER_IF_STA, &host_name )) !=ESP_OK){
+			if((err=tcpip_adapter_get_hostname(TCPIP_ADAPTER_IF_STA, &host_name )) !=ESP_OK) {
 				ESP_LOGE(TAG,"Unable to get host name. Error: %s",esp_err_to_name(err));
 			}
 
@@ -373,14 +384,13 @@ void http_server_netconn_serve(struct netconn *conn) {
 			wifi_manager_unlock_sta_ip_string();
 			bool access_from_host_name = (host_name!=NULL) && strstr(host, host_name);
 
-			if (lenH > 0 && !strstr(host, DEFAULT_AP_IP) && !(access_from_sta_ip || access_from_host_name)) {
+			if(lenH > 0 && !strstr(host, DEFAULT_AP_IP) && !(access_from_sta_ip || access_from_host_name)) {
 				ESP_LOGI(TAG,"Redirecting to default AP IP Address : %s", DEFAULT_AP_IP);
 				netconn_write(conn, http_redirect_hdr_start, sizeof(http_redirect_hdr_start) - 1, NETCONN_NOCOPY);
 				netconn_write(conn, DEFAULT_AP_IP, sizeof(DEFAULT_AP_IP) - 1, NETCONN_NOCOPY);
 				netconn_write(conn, http_redirect_hdr_end, sizeof(http_redirect_hdr_end) - 1, NETCONN_NOCOPY);
-
 			}
-			else{
+			else {
                 //static stuff
 				/* default page */
 				if(strstr(line, "GET / ")) {
@@ -411,31 +421,30 @@ void http_server_netconn_serve(struct netconn *conn) {
                 //dynamic stuff
 				else if(strstr(line, "GET /ap.json ")) {
 					/* if we can get the mutex, write the last version of the AP list */
-					ESP_LOGI(TAG,"Processing ap.json request for socket %u",conn->socket);
-					if(wifi_manager_lock_json_buffer(( TickType_t ) 10)){
+					ESP_LOGI(TAG,"Processing ap.json request");
+					if(wifi_manager_lock_json_buffer(( TickType_t ) 10)) {
 						netconn_write(conn, http_ok_json_no_cache_hdr, sizeof(http_ok_json_no_cache_hdr) - 1, NETCONN_NOCOPY);
 						char *buff = wifi_manager_get_ap_list_json();
 						netconn_write(conn, buff, strlen(buff), NETCONN_NOCOPY);
 						wifi_manager_unlock_json_buffer();
 					}
-					else{
+					else {
 						netconn_write(conn, http_503_hdr, sizeof(http_503_hdr) - 1, NETCONN_NOCOPY);
 						ESP_LOGE(TAG, "http_server_netconn_serve: GET /ap.json failed to obtain mutex");
 					}
 					/* request a wifi scan */
 					ESP_LOGI(TAG,"Starting wifi scan");
 					wifi_manager_scan_async();
-					ESP_LOGI(TAG,"Done serving ap.json for socket %u",conn->socket);
+					ESP_LOGI(TAG,"Done serving ap.json");
 				}
-				else if(strstr(line, "GET /config.json ")){
-					ESP_LOGI(TAG,"Serving config.json for socket %u",conn->socket);
+				else if(strstr(line, "GET /config.json ")) {
+					ESP_LOGI(TAG,"Serving config.json");
 					ESP_LOGI(TAG, "About to get config from flash");
 					http_server_nvs_dump(conn,NVS_TYPE_STR);
-					ESP_LOGD(TAG,"Done serving config.json for socket %u",conn->socket);
+					ESP_LOGD(TAG,"Done serving config.json");
 				}
-				else if(strstr(line, "POST /config.json ")){
-					ESP_LOGI(TAG,"Serving POST config.json for socket %u",conn->socket);
-
+				else if(strstr(line, "POST /config.json ")) {
+					ESP_LOGI(TAG,"Serving POST config.json");
 					int lenA=0;
 					char * last_parm=save_ptr;
 					char * next_parm=save_ptr;
@@ -443,26 +452,23 @@ void http_server_netconn_serve(struct netconn *conn) {
 					bool bErrorFound=false;
 					bool bOTA=false;
 					char * otaURL=NULL;
-					// make sure we terminate the netconn string
-					save_ptr[buflen-1]='\0';
-
 					// todo:  implement json body parsing
 					//http_server_process_config(conn,save_ptr);
 
-					while(last_parm!=NULL){
+					while(last_parm!=NULL) {
 						// Search will return
-						ESP_LOGI(TAG, "Getting parameters from X-Custom headers");
+						ESP_LOGD(TAG, "Getting parameters from X-Custom headers");
 						last_parm = http_server_search_header(next_parm, "X-Custom-", &lenA, &last_parm_name,&next_parm,buf+buflen);
-						if(last_parm!=NULL && last_parm_name!=NULL){
-							ESP_LOGI(TAG, "http_server_netconn_serve: config.json/ call, found parameter %s=%s, length %i", last_parm_name, last_parm, lenA);
-							if(strcmp(last_parm_name, "fwurl")==0){
+						if(last_parm!=NULL && last_parm_name!=NULL) {
+							ESP_LOGI(TAG, "http_server_netconn_serve: POST config.json, config %s=%s", last_parm_name, last_parm);
+							if(strcmp(last_parm_name, "fwurl")==0) {
 								// we're getting a request to do an OTA from that URL
-								ESP_LOGI(TAG, "OTA parameter found!");
+								ESP_LOGW(TAG, "Found OTA request!");
 								otaURL=strdup(last_parm);
 								bOTA=true;
 							}
 							else {
-									ESP_LOGD(TAG, "http_server_netconn_serve: config.json/ Storing parameter");
+									ESP_LOGV(TAG, "http_server_netconn_serve: POST config.json Storing parameter");
 									err= store_nvs_value(NVS_TYPE_STR, last_parm_name , last_parm);
 									if(err!=ESP_OK) ESP_LOGE(TAG,"Unable to save nvs value. Error: %s",esp_err_to_name(err));
 							}
@@ -472,29 +478,35 @@ void http_server_netconn_serve(struct netconn *conn) {
 							last_parm_name=NULL;
 						}
 					}
-					if(bErrorFound){
+					if(bErrorFound) {
 						netconn_write(conn, http_400_hdr, sizeof(http_400_hdr) - 1, NETCONN_NOCOPY); //400 invalid request
 					}
-					else{
-						if(bOTA){
-							ESP_LOGI(TAG, "Restarting to process OTA for url %s",otaURL);
-							netconn_write(conn, http_ok_json_no_cache_hdr, sizeof(http_ok_json_no_cache_hdr) - 1, NETCONN_NOCOPY); //200ok
+					else {
+						netconn_write(conn, http_ok_json_no_cache_hdr, sizeof(http_ok_json_no_cache_hdr) - 1, NETCONN_NOCOPY); //200ok
+						if(bOTA) {
+#if RECOVERY_APPLICATION
+							ESP_LOGW(TAG, "Starting process OTA for url %s",otaURL);
+#else
+							ESP_LOGW(TAG, "Restarting system to process OTA for url %s",otaURL);
+							// close the connection cleanly
+							netconn_close(conn);
+							netconn_delete(conn);
+#endif
 							start_ota(otaURL,false);
 							free(otaURL);
 						}
 					}
-					ESP_LOGI(TAG,"Done Serving POST config.json for socket %u",conn->socket);
-
+					ESP_LOGI(TAG,"Done Serving POST config.json");
 				} 
 				else if(strstr(line, "POST /connect.json ")) {
-					ESP_LOGI(TAG, "http_server_netconn_serve: POST /connect.json for socket %u",conn->socket);
+					ESP_LOGI(TAG, "http_server_netconn_serve: POST /connect.json");
 					bool found = false;
 					int lenS = 0, lenP = 0;
 					char *ssid = NULL, *password = NULL;
 					ssid = http_server_get_header(save_ptr, "X-Custom-ssid: ", &lenS);
 					password = http_server_get_header(save_ptr, "X-Custom-pwd: ", &lenP);
 
-					if(ssid && lenS <= MAX_SSID_SIZE && password && lenP <= MAX_PASSWORD_SIZE){
+					if(ssid && lenS <= MAX_SSID_SIZE && password && lenP <= MAX_PASSWORD_SIZE) {
 						wifi_config_t* config = wifi_manager_get_wifi_sta_config();
 						memset(config, 0x00, sizeof(wifi_config_t));
 						memcpy(config->sta.ssid, ssid, lenS);
@@ -505,85 +517,99 @@ void http_server_netconn_serve(struct netconn *conn) {
 						found = true;
 					}
 
-					if(!found){
+					if(!found) {
 						/* bad request the authentification header is not complete/not the correct format */
 						netconn_write(conn, http_400_hdr, sizeof(http_400_hdr) - 1, NETCONN_NOCOPY);
 						ESP_LOGE(TAG, "bad request the authentification header is not complete/not the correct format");
 					}
 
-					ESP_LOGI(TAG, "http_server_netconn_serve: done serving connect.json for socket %u",conn->socket);
+					ESP_LOGI(TAG, "http_server_netconn_serve: done serving connect.json");
 				}
 				else if(strstr(line, "DELETE /connect.json ")) {
-					ESP_LOGI(TAG, "http_server_netconn_serve: DELETE /connect.json for socket %u",conn->socket);
+					ESP_LOGI(TAG, "http_server_netconn_serve: DELETE /connect.json");
 					/* request a disconnection from wifi and forget about it */
 					wifi_manager_disconnect_async();
 					netconn_write(conn, http_ok_json_no_cache_hdr, sizeof(http_ok_json_no_cache_hdr) - 1, NETCONN_NOCOPY); /* 200 ok */
-					ESP_LOGI(TAG, "http_server_netconn_serve: done serving DELETE /connect.json for socket %u",conn->socket);
+					ESP_LOGI(TAG, "http_server_netconn_serve: done serving DELETE /connect.json");
 				}
-				else if(strstr(line, "POST /reboot.json ")){
-					ESP_LOGI(TAG, "http_server_netconn_serve: POST reboot.json for socket %u",conn->socket);
+				else if(strstr(line, "POST /reboot.json ")) {
+					ESP_LOGI(TAG, "http_server_netconn_serve: POST reboot.json");
+					netconn_close(conn);
+					netconn_delete(conn);
 					guided_restart_ota();
-					ESP_LOGI(TAG, "http_server_netconn_serve: done serving POST reboot.json for socket %u",conn->socket);
+					ESP_LOGI(TAG, "http_server_netconn_serve: done serving POST reboot.json");
 				}
-				else if(strstr(line, "POST /recovery.json ")){
-					ESP_LOGI(TAG, "http_server_netconn_serve: POST recovery.json for socket %u",conn->socket);
+				else if(strstr(line, "POST /recovery.json ")) {
+					ESP_LOGI(TAG, "http_server_netconn_serve: POST recovery.json");
+					netconn_close(conn);
+					netconn_delete(conn);
 					guided_factory();
-					ESP_LOGI(TAG, "http_server_netconn_serve: done serving POST recovery.json for socket %u",conn->socket);
+					ESP_LOGI(TAG, "http_server_netconn_serve: done serving POST recovery.json");
 				}
-				else if(strstr(line, "GET /status.json ")){
-					ESP_LOGI(TAG,"Serving status.json for socket %u",conn->socket);
-					if(wifi_manager_lock_json_buffer(( TickType_t ) 10)){
+				else if(strstr(line, "GET /status.json ")) {
+					ESP_LOGI(TAG,"Serving status.json");
+					if(wifi_manager_lock_json_buffer(( TickType_t ) 10)) {
 						char *buff = wifi_manager_get_ip_info_json();
-						if(buff){
+						if(buff) {
 							netconn_write(conn, http_ok_json_no_cache_hdr, sizeof(http_ok_json_no_cache_hdr) - 1, NETCONN_NOCOPY);
 							netconn_write(conn, buff, strlen(buff), NETCONN_NOCOPY);
 						}
-						else{
+						else {
 							netconn_write(conn, http_503_hdr, sizeof(http_503_hdr) - 1, NETCONN_NOCOPY);
 						}
 						wifi_manager_unlock_json_buffer();
 					}
-					else{
+					else {
 						netconn_write(conn, http_503_hdr, sizeof(http_503_hdr) - 1, NETCONN_NOCOPY);
 						ESP_LOGE(TAG, "http_server_netconn_serve: GET /status failed to obtain mutex");
 					}
-					ESP_LOGI(TAG,"Done Serving status.json for socket %u",conn->socket);
+					ESP_LOGI(TAG,"Done Serving status.json");
 				}
-				else{
+				else {
 					netconn_write(conn, http_400_hdr, sizeof(http_400_hdr) - 1, NETCONN_NOCOPY);
-					ESP_LOGE(TAG, "bad request for socket %u",conn->socket);
+					ESP_LOGE(TAG, "bad request");
 				}
 			}
 		}
-		else{
-			ESP_LOGE(TAG, "URL Not found. Sending 404. for socket %u",conn->socket);
+		else {
+			ESP_LOGE(TAG, "URL Not found. Sending 404.");
 			netconn_write(conn, http_404_hdr, sizeof(http_404_hdr) - 1, NETCONN_NOCOPY);
 		}
 	}
-	/* free the buffer */
+	//-1 if there is no next part
+	// 1 if moved to the next part but now there is no next part
+	// 0 if moved to the next part and there are still more parts
+	while(netbuf_next(inbuf) != -1) {
+		ESP_LOGD(TAG,"More data found from the connection!");
+		netbuf_data(inbuf, (void**)&buf, &buflen);
+		dump_net_buffer(buf, buflen);
+	}
+	netconn_close(conn);
 	netbuf_delete(inbuf);
+	/* free the buffer */
+
 }
 
-bool http_server_lock_json_object(TickType_t xTicksToWait){
+bool http_server_lock_json_object(TickType_t xTicksToWait) {
 	ESP_LOGD(TAG,"Locking config json object");
-	if(http_server_config_mutex){
+	if(http_server_config_mutex) {
 		if( xSemaphoreTake( http_server_config_mutex, xTicksToWait ) == pdTRUE ) {
-			ESP_LOGD(TAG,"config Json object locked!");
+			ESP_LOGV(TAG,"config Json object locked!");
 			return true;
 		}
-		else{
-			ESP_LOGD(TAG,"Semaphore take failed. Unable to lock config Json object mutex");
+		else {
+			ESP_LOGW(TAG,"Semaphore take failed. Unable to lock config Json object mutex");
 			return false;
 		}
 	}
-	else{
-		ESP_LOGD(TAG,"Unable to lock config Json object mutex");
+	else {
+		ESP_LOGW(TAG,"Unable to lock config Json object mutex");
 		return false;
 	}
 
 }
 
-void http_server_unlock_json_object(){
+void http_server_unlock_json_object() {
 	ESP_LOGD(TAG,"Unlocking json buffer!");
 	xSemaphoreGive( http_server_config_mutex );
 }
@@ -591,12 +617,12 @@ void http_server_unlock_json_object(){
 void strreplace(char *src, char *str, char *rep)
 {
     char *p = strstr(src, str);
-    if (p)
+    if(p)
     {
         int len = strlen(src)+strlen(rep)-strlen(str);
         char r[len];
         memset(r, 0, len);
-        if ( p >= src ){
+        if( p >= src ) {
             strncpy(r, src, p-src);
             r[p-src]='\0';
             strncat(r, rep, strlen(rep));