Reduced I2C master speed from 400 to 100 Khz. Hope to get power-on init for BMP280 more reliable. Added warnings for I2C devices that are missing. Some logmessages reduced to debug log messages. Added extra 10 mSec delays before read shunt voltage in the INA219 task. Removed and reduced log levels in the MQTT task. Show received data events. Remove WiFi total time debug logging, it's ok now.

Wed, 12 Apr 2023 16:23:02 +0200

author
Michiel Broek <mbroek@mbse.eu>
date
Wed, 12 Apr 2023 16:23:02 +0200
changeset 24
74609f70411e
parent 23
2cc30d828d6e
child 25
c5a9bde0268f

Reduced I2C master speed from 400 to 100 Khz. Hope to get power-on init for BMP280 more reliable. Added warnings for I2C devices that are missing. Some logmessages reduced to debug log messages. Added extra 10 mSec delays before read shunt voltage in the INA219 task. Removed and reduced log levels in the MQTT task. Show received data events. Remove WiFi total time debug logging, it's ok now.

main/iotbalkon.c file | annotate | diff | comparison | revisions
main/task_ina219.c file | annotate | diff | comparison | revisions
main/task_mqtt.c file | annotate | diff | comparison | revisions
main/task_wifi.c file | annotate | diff | comparison | revisions
--- a/main/iotbalkon.c	Tue Apr 11 19:41:53 2023 +0200
+++ b/main/iotbalkon.c	Wed Apr 12 16:23:02 2023 +0200
@@ -340,25 +340,31 @@
     i2c_dev_t dev = { 0 };
     dev.cfg.sda_io_num = CONFIG_I2C_MASTER_SDA;
     dev.cfg.scl_io_num = CONFIG_I2C_MASTER_SCL;
-    dev.cfg.master.clk_speed = 400000;
+    dev.cfg.master.clk_speed = 100000;
 
     dev.addr = 0x39;
     if (i2c_dev_probe(&dev, I2C_DEV_WRITE) == 0) {
 	ESP_ERROR_CHECK(apds9930_init_desc(&apds9930_dev, 0x39, 0, CONFIG_I2C_MASTER_SDA, CONFIG_I2C_MASTER_SCL));
 	ESP_ERROR_CHECK(apds9930_init(&apds9930_dev));
 	ESP_LOGI(TAG, "Found APDS-9930 id: 0x%02x", apds9930_dev.id);
+    } else {
+	ESP_LOGW(TAG, "No APDS-9930 found");
     }
     dev.addr = 0x40;
     if (i2c_dev_probe(&dev, I2C_DEV_WRITE) == 0) {
 	ESP_ERROR_CHECK(ina219_init_desc(&ina219_b_dev, 0x40, 0, CONFIG_I2C_MASTER_SDA, CONFIG_I2C_MASTER_SCL));
 	ESP_ERROR_CHECK(ina219_init(&ina219_b_dev));
 	ESP_LOGI(TAG, "Found INA219 @0x40 Battery");
+    } else {
+	ESP_LOGW(TAG, "No INA219 @0x40 found");
     }
     dev.addr = 0x41;
     if (i2c_dev_probe(&dev, I2C_DEV_WRITE) == 0) {
 	ESP_ERROR_CHECK(ina219_init_desc(&ina219_s_dev, 0x41, 0, CONFIG_I2C_MASTER_SDA, CONFIG_I2C_MASTER_SCL));
 	ESP_ERROR_CHECK(ina219_init(&ina219_s_dev));
         ESP_LOGI(TAG, "Found INA219 @0x41 Solar");
+    } else {
+	ESP_LOGW(TAG, "No INA219 @0x41 found");
     }
     dev.addr = 0x76;
     if (i2c_dev_probe(&dev, I2C_DEV_WRITE) == 0) {
@@ -371,7 +377,9 @@
 	    ESP_ERROR_CHECK(bmp280_init_desc(&bmp280_dev, BMP280_I2C_ADDRESS_1, 0, CONFIG_I2C_MASTER_SDA, CONFIG_I2C_MASTER_SCL));
 	    ESP_ERROR_CHECK(bmp280_init(&bmp280_dev, &bmp280_params));
             ESP_LOGI(TAG, "Found BMP280 @ 0x77 id: 0x%02x", bmp280_dev.id);
-    	}
+    	} else {
+	    ESP_LOGW(TAG, "No BMP280 found");
+	}
     }
 
     /*
@@ -408,7 +416,7 @@
 
     while (1) {
 	if (OldState != State) {
-	    ESP_LOGI(TAG, "Switch to state %d", State);
+	    ESP_LOGD(TAG, "Switch to state %d", State);
 	    OldState = State;
 	}
 
@@ -431,7 +439,7 @@
 					    vTaskDelay(250 / portTICK_PERIOD_MS);
 					    request_mqtt(true);
 					    Alarm &= ~AL_NOWIFI;
-					    ESP_LOGI(TAG, "Connected counter WiFi %d", DisCounter);
+					    ESP_LOGD(TAG, "Connected counter WiFi %d", DisCounter);
 					    DisCounter = 0;
 					} else {
 					    /*
@@ -570,7 +578,7 @@
         				    // Active mode, 60 seconds loop
 					    ST_LOOPS = 6;
 					    gTimeNext = millis() + ST_INTERVAL;
-					    ESP_LOGI(TAG, "Start sleeploops");
+					    ESP_LOGD(TAG, "Start sleeploops");
 					    State = State_Wait;
       					} else {
 					    ds_time = DS_TIME;
@@ -595,7 +603,7 @@
 	    case State_Measure:		gTimeNext = millis() + ST_INTERVAL;
 					getVoltsCurrent();
 					if (loopno >= ST_LOOPS) {
-					    ESP_LOGI(TAG, "Enough loops, do connect");
+					    ESP_LOGD(TAG, "Enough loops, do connect");
         				    getLightValues();
 					    State = State_Connect_Wifi;
 					    DisCounter = 0;
--- a/main/task_ina219.c	Tue Apr 11 19:41:53 2023 +0200
+++ b/main/task_ina219.c	Wed Apr 12 16:23:02 2023 +0200
@@ -105,10 +105,11 @@
 		 * rest for a while. The INA219 runs in continuous mode so we get the
 		 * results during the vTaskDelay().
 		 */
-//		vTaskDelay(20 / portTICK_PERIOD_MS);
+		vTaskDelay(20 / portTICK_PERIOD_MS);
 		ESP_ERROR_CHECK(ina219_get_bus_voltage(&ina219_b_dev, &bus_voltage));
+		vTaskDelay(10 / portTICK_PERIOD_MS);
 		ESP_ERROR_CHECK(ina219_get_shunt_voltage(&ina219_b_dev, &shunt_voltage));
-		vTaskDelay(20 / portTICK_PERIOD_MS);
+		vTaskDelay(10 / portTICK_PERIOD_MS);
 		ESP_ERROR_CHECK(ina219_get_current(&ina219_b_dev, &current));
 		ESP_LOGI(TAG, "Battery VBUS: %.04f V, VSHUNT: %.04f mV, IBUS: %.04f mA", bus_voltage, shunt_voltage * 1000, current * 1000);
 	    }
@@ -134,8 +135,9 @@
 	    if (! ina219_state->Solar.fake) {
 		vTaskDelay(20 / portTICK_PERIOD_MS);
                 ESP_ERROR_CHECK(ina219_get_bus_voltage(&ina219_s_dev, &bus_voltage));
+		vTaskDelay(10 / portTICK_PERIOD_MS);
                 ESP_ERROR_CHECK(ina219_get_shunt_voltage(&ina219_s_dev, &shunt_voltage));
-		vTaskDelay(20 / portTICK_PERIOD_MS);
+		vTaskDelay(10 / portTICK_PERIOD_MS);
                 ESP_ERROR_CHECK(ina219_get_current(&ina219_s_dev, &current));
                 ESP_LOGI(TAG, "  Solar VBUS: %.04f V, VSHUNT: %.04f mV, IBUS: %.04f mA", bus_voltage, shunt_voltage * 1000, current * 1000);
 	    }
--- a/main/task_mqtt.c	Tue Apr 11 19:41:53 2023 +0200
+++ b/main/task_mqtt.c	Wed Apr 12 16:23:02 2023 +0200
@@ -79,14 +79,13 @@
 
 void wait_mqtt(int time)
 {
-    EventBits_t uxBits;
+//    EventBits_t uxBits;
 
-    ESP_LOGI(TAG, "wait_mqtt(%d) 1", time);
     if (xEventGroupGetBits(xEventGroupMQTT) & TASK_MQTT_CONNECTED) {
-	uxBits = xEventGroupWaitBits(xEventGroupMQTT, TASK_MQTT_DISCONNECTED, pdTRUE, pdFALSE, time / portTICK_PERIOD_MS);
-	ESP_LOGI(TAG, "wait_mqtt(%d) 2 %lu", time, uxBits & TASK_MQTT_DISCONNECTED);
-    } else {
-	ESP_LOGI(TAG, "wait_mqtt(%d) 3 not connected", time);
+	/*uxBits =*/ xEventGroupWaitBits(xEventGroupMQTT, TASK_MQTT_DISCONNECTED, pdTRUE, pdFALSE, time / portTICK_PERIOD_MS);
+//	ESP_LOGI(TAG, "wait_mqtt(%d) 2 %lu", time, uxBits & TASK_MQTT_DISCONNECTED);
+//    } else {
+//	ESP_LOGI(TAG, "wait_mqtt(%d) 3 not connected", time);
     }
 }
 
@@ -242,17 +241,18 @@
 
 static esp_err_t mqtt_event_handler_cb(esp_mqtt_event_handle_t event)
 {
-    char		*topic = NULL;
+    char	*subscr = NULL, *check = NULL;
 
     switch (event->event_id) {
 
         case MQTT_EVENT_CONNECTED:
             ESP_LOGI(TAG, "MQTT_EVENT_CONNECTED");
-	    topic = topic_base();
-            topic = xstrcat(topic, (char *)"output/set/#");
-            ESP_LOGI(TAG, "Subscribe `%s' id %d", topic, esp_mqtt_client_subscribe(client, topic, 0));
-            free(topic);
-	    topic = NULL;
+	    subscr = topic_base();
+            subscr = xstrcat(subscr, (char *)"output/set/#");
+	    int msgid = esp_mqtt_client_subscribe(client, subscr, 0);
+            ESP_LOGI(TAG, "Subscribe `%s' id %d", subscr, msgid);
+            free(subscr);
+	    subscr = NULL;
 	    xEventGroupSetBits(xEventGroupMQTT, TASK_MQTT_CONNECTED);
 	    xEventGroupClearBits(xEventGroupMQTT, TASK_MQTT_DISCONNECTED);
             break;
@@ -264,7 +264,7 @@
             break;
 
         case MQTT_EVENT_SUBSCRIBED:
-            ESP_LOGI(TAG, "MQTT_EVENT_SUBSCRIBED, msg_id=%d", event->msg_id);
+            ESP_LOGD(TAG, "MQTT_EVENT_SUBSCRIBED, msg_id=%d", event->msg_id);
             break;
 
         case MQTT_EVENT_UNSUBSCRIBED:
@@ -272,7 +272,6 @@
             break;
 
         case MQTT_EVENT_PUBLISHED:
-            ESP_LOGI(TAG, "MQTT_EVENT_PUBLISHED, msg_id=%d", event->msg_id);
 	    if (xSemaphoreTake(xSemaphorePcounter, 10) == pdTRUE) {
 	    	if (count_pub) {
 		    count_pub--;
@@ -281,60 +280,65 @@
 	    } else {
         	ESP_LOGE(TAG, "mqtt_event_handler_cb(() lock error event");
 	    }
+	    ESP_LOGI(TAG, "MQTT_EVENT_PUBLISHED, msg_id=%d, %d msgs in queue", event->msg_id, count_pub);
             break;
 
         case MQTT_EVENT_DATA:
-            ESP_LOGI(TAG, "MQTT_EVENT_DATA len=%d", event->data_len);
 	    bool gotit = false;
-	    char data[65];
+	    char data[65], topic[128];
 	    if (event->data_len < 65)
 		snprintf(data, 64, "%.*s", event->data_len, event->data);
 	    else
 		data[0] = '\0';
+	    if (event->topic_len < 128)
+		snprintf(topic, 127, "%.*s", event->topic_len, event->topic);
+	    else
+		topic[0] = '\0';
+	    ESP_LOGI(TAG, "MQTT_EVENT_DATA %s %s", topic, data);
 
-	    topic = topic_base();
-            topic = xstrcat(topic, (char *)"output/set/1");
-	    if (strncmp(topic, event->topic, event->topic_len) == 0) {
-		ESP_LOGI(TAG, "Got %s `%s' %d", topic, data, atoi(data));
+	    check = topic_base();
+            check = xstrcat(check, (char *)"output/set/1");
+	    if (strncmp(check, event->topic, event->topic_len) == 0) {
+		ESP_LOGD(TAG, "Got %s `%s' %d", check, data, atoi(data));
 		gotit = true;
 		Relay1 = (uint8_t)atoi(data);
 		nvsio_write_u8((char *)"out1", Relay1);
 	    }
-	    free(topic);
-	    topic = NULL;
+	    free(check);
+	    check = NULL;
 
-	    topic = topic_base();
-            topic = xstrcat(topic, (char *)"output/set/2");
-	    if (strncmp(topic, event->topic, event->topic_len) == 0) {
-                ESP_LOGI(TAG, "Got %s `%s' %d", topic, data, atoi(data));
+	    check = topic_base();
+            check = xstrcat(check, (char *)"output/set/2");
+	    if (strncmp(check, event->topic, event->topic_len) == 0) {
+                ESP_LOGD(TAG, "Got %s `%s' %d", check, data, atoi(data));
                 gotit = true;
                 Relay2 = (uint8_t)atoi(data);
 		nvsio_write_u8((char *)"out2", Relay2);
             }
-            free(topic);
-            topic = NULL;
+            free(check);
+            check = NULL;
 
-	    topic = topic_base();
-            topic = xstrcat(topic, (char *)"output/set/3");
-            if (strncmp(topic, event->topic, event->topic_len) == 0) {
-                ESP_LOGI(TAG, "Got %s `%s' %d", topic, data, atoi(data));
+	    check = topic_base();
+            check = xstrcat(check, (char *)"output/set/3");
+            if (strncmp(check, event->topic, event->topic_len) == 0) {
+                ESP_LOGI(TAG, "Got %s `%s' %d", check, data, atoi(data));
                 gotit = true;
                 Dimmer3 = (uint8_t)atoi(data);
 		nvsio_write_u8((char *)"out3", Dimmer3);
             }
-            free(topic);
-            topic = NULL;
+            free(check);
+            check = NULL;
 
-	    topic = topic_base();
-            topic = xstrcat(topic, (char *)"output/set/4");
-            if (strncmp(topic, event->topic, event->topic_len) == 0) {
-                ESP_LOGI(TAG, "Got %s `%s' %d", topic, data, atoi(data));
+	    check = topic_base();
+            check = xstrcat(check, (char *)"output/set/4");
+            if (strncmp(check, event->topic, event->topic_len) == 0) {
+                ESP_LOGD(TAG, "Got %s `%s' %d", check, data, atoi(data));
                 gotit = true;
                 Dimmer4 = (uint8_t)atoi(data);
 		nvsio_write_u8((char *)"out4", Dimmer4);
             }
-            free(topic);
-            topic = NULL;
+            free(check);
+            check = NULL;
 
 	    if (! gotit) {
             	printf("TOPIC=%.*s ", event->topic_len, event->topic);
@@ -427,7 +431,7 @@
 	    xEventGroupClearBits(xEventGroupMQTT, TASK_MQTT_CONNECT);
 
 	} else if (uxBits & TASK_MQTT_DISCONNECT) {
-	    ESP_LOGI(TAG, "Request MQTT disconnect start");
+	    ESP_LOGI(TAG, "Request MQTT disconnect");
 	    /*
 	     * Unsubscribe if connected
 	     */
@@ -446,7 +450,6 @@
                 ESP_LOGE(TAG, "Result %s", esp_err_to_name(err));
 	    }
 	    xEventGroupWaitBits(xEventGroupMQTT, TASK_MQTT_DISCONNECTED, pdTRUE, pdFALSE, 500 / portTICK_PERIOD_MS);
-	    ESP_LOGI(TAG, "disconnect confirmed");
 
 	    /*
 	     * Finally stop the client because new connections start
@@ -455,9 +458,7 @@
 	     */
 	    err = esp_mqtt_client_stop(client);
             if (err != ESP_OK) {
-                ESP_LOGE(TAG, "Result %s", esp_err_to_name(err));
-            } else {
-                ESP_LOGI(TAG, "stopped");
+                ESP_LOGE(TAG, "esp_mqtt_client_stop() result %s", esp_err_to_name(err));
             }
 
 	    xEventGroupClearBits(xEventGroupMQTT, TASK_MQTT_CONNECTED);
--- a/main/task_wifi.c	Tue Apr 11 19:41:53 2023 +0200
+++ b/main/task_wifi.c	Wed Apr 12 16:23:02 2023 +0200
@@ -222,7 +222,7 @@
 
 void task_wifi( void * pvParameters )
 {
-    uint64_t starttime = 0;
+//    uint64_t starttime = 0;
 
     ESP_LOGI(TAG, "Starting WiFi task");
     esp_log_level_set("wifi", ESP_LOG_ERROR);
@@ -267,12 +267,12 @@
 	     * Finally: release the request bit
 	     */
 	    xEventGroupClearBits(xEventGroupWifi, TASK_WIFI_REQUEST_STA_DISCONNECT);
-	    ESP_LOGI(TAG, "Connection time %llu", (esp_timer_get_time() / 1000) - starttime);
+//	    ESP_LOGI(TAG, "Connection time %llu", (esp_timer_get_time() / 1000) - starttime);
 
 	} else if (uxBits & TASK_WIFI_REQUEST_STA_CONNECT) {
 
 	    ESP_LOGI(TAG, "Request STA connect `%s' `%s'", ESP_WIFI_SSID, ESP_WIFI_PASS);
-	    starttime = esp_timer_get_time() / 1000;
+//	    starttime = esp_timer_get_time() / 1000;
 	    wifi_connect();
 
 	    /*

mercurial