Refactor and fix PID sensor (PID_USE_LOCAL_SENSOR) read race condition (#22162)

* Refactor and fix PID sensor (PID_USE_LOCAL_SENSOR) read race condition

Refactor PID since it was calling pid.tick willy-nilly upon demand
from MQTT and the web instead of on a periodic basis (and was being
called with time interval of 0 when those times lined up!).  Refactor
web/mqtt display because there was shared code (that code turned out
to be misguided and belonged in Every_Second loop, but now we are also
similar to 39 thermostat)

Logging revealed that the vast majority of the time the sensor JSON
was parsed to obtain current sensor data when using PID local sensor,
it was failing to parse (and it would typically only work for a second
around TELE_PERIOD, but even then, not reliably).  This bug almost
certainly affects xdrv_39_thermostat too, but using
xsns_75_prometheus.ino as a template, we are able to update PV once
per second, which allows us to be a lot more responsive.  There is no
danger of being "too responsive" because that's the point of PID, and
the PID loop already scales feedback by interval between ticks.

* Reduce logging of PID now that query side-effects removed

* Comment out all new logging, but leave present for next debugger

tasmota/tasmota_xdrv_driver/xdrv_49_pid.ino

@@ -94,10 +94,12 @@
 
    #define PID_UPDATE_SECS               0       // How often to run the pid algorithm (integer secs) or 0 to run the algorithm
                                                  // each time a new pv value is received, for most applictions specify 0.
-                                                 // Otherwise set this to a time
+                                                 // Otherwise set this to a time that is short compared to the response of 
-                                                 // that is short compared to the response of the process.  For example,
+                                                 // the process.  For example, something like 15 seconds may well be appropriate
-                                                 // something like 15 seconds may well be appropriate for a domestic room
+                                                 // for a domestic room heating application.  Keep in mind that the PID loop is
-                                                 // heating application.
+                                                 // "tick"ed once per PV update if 0 is specified, so if PV are received at
+                                                 // non-constant intervals, you may be better off specifying a value here that
+                                                 // is larger than your typical PV update times.
                                                  // May be adjusted via MQTT using cmnd PidUpdateSecs
 
    #define PID_USE_TIMPROP               1       // To use an internal relay for a time proportioned output to drive the
@@ -109,18 +111,22 @@
                                                  // not explicitly defined, then it will not be added by default.
 
    #define PID_USE_LOCAL_SENSOR                  // If defined then the local sensor will be used for pv. Leave undefined if
-                                                 // this is not required.  The rate that the sensor is read is defined by TELE_PERIOD
+                                                 // this is not required.  The sensor is read every second, and you can slow
+                                                 // down updates for slow systems by explictly setting UPDATE_SECS, or more
+                                                 // prefably, appropriately adjusting P,I,D values.
                                                  // If not using the sensor then you can supply process values via MQTT using
                                                  // cmnd PidPv
 
     #define PID_LOCAL_SENSOR_NAME         "DS18B20"           // local sensor name when PID_USE_LOCAL_SENSOR is defined above
                                                               // the JSON payload is parsed for this sensor to find the present value
-                                                              // eg "ESP32":{"Temperature":31.4},"DS18B20":{"Temperature":12.6}
+                                                              // eg "ESP32", "DS18B20" and "ANALOG" in the following data:
+                                                              // "ESP32":{"Temperature":31.4},"DS18B20":{"Temperature":12.6},"ANALOG":{"Temperature1":19.6}
 
     #define PID_LOCAL_SENSOR_TYPE         D_JSON_TEMPERATURE  // Choose one of D_JSON_TEMPERATURE D_JSON_HUMIDITY D_JSON_PRESSURE
                                                               // or any string as the sensor type. The JSON payload is parsed for the
                                                               // value in this field
-                                                              // eg "HDC1080":{"Temperature":24.8,"Humidity":79.2}
+                                                              // eg "Temperature", "Temperature1" in the following data:
+                                                              // "HDC1080":{"Temperature":24.8,"Humidity":79.2},"ANALOG":{"Temperature1":19.6}
 
    #define PID_SHUTTER                   1       // if using the PID to control a 3-way valve, create Tasmota Shutter and define the
                                                  // number of the shutter here. Otherwise leave this commented out
@@ -237,6 +243,8 @@ struct {
   bool run_pid_now = false;     // tells PID_Every_Second to run the pid algorithm
   long current_time_secs = 0;  // a counter that counts seconds since initialisation
   bool shutdown = false;        // power commands will be ignored when true
+
+  double power = 0;
 } Pid;
 
 void PIDInit()
@@ -250,23 +258,31 @@ void PIDEverySecond() {
   Pid.current_time_secs++;    // increment time
   // run the pid algorithm if Pid.run_pid_now is true or if the right number of seconds has passed or if too long has
   // elapsed since last pv update. If too long has elapsed the the algorithm will deal with that.
-  if (Pid.run_pid_now  ||  Pid.current_time_secs - Pid.last_pv_update_secs > Pid.max_interval  ||  (Pid.update_secs != 0 && sec_counter++ % Pid.update_secs  ==  0)) {
+  PIDProcessSensor();    // set actual process value, needs to have mqtt data already populated
-    if (!Pid.run_pid_now) {
+  if (Pid.run_pid_now ||
-      PIDShowSensor();    // set actual process value
+      Pid.current_time_secs - Pid.last_pv_update_secs > Pid.max_interval  ||
-    }
+      (Pid.update_secs != 0 && sec_counter++ % Pid.update_secs  ==  0)) {
     PIDRun();
     Pid.run_pid_now = false;
   }
 }
 
-void PIDShowSensor() {
+void PIDProcessSensor() {
-  // Called each time new sensor data available, data in mqtt data in same format
+  // Called periodically (every second) to feed current sensor value
-  // as published in tele/SENSOR
+  // (if enabled; data in mqtt data in same format as published in
-  // Update period is specified in TELE_PERIOD
+  // tele/SENSOR) and to log whether either sensor or input PV data is
+  // stale
 
   float sensor_reading = NAN;
 
 #if defined PID_USE_LOCAL_SENSOR
+  // Taking https://github.com/arendst/Tasmota/discussions/18328 as a
+  // template of how to reliably read sensor values and not be subject
+  // to race conditions affecting the completeness and parsability of
+  // that data:
+  ResponseClear();
+  MqttShowSensor(true); //Pull sensor data
+
   // copy the string into a new buffer that will be modified and
   // parsed to find the local sensor reading if it's there
   String buf = ResponseData();
@@ -276,12 +292,14 @@ void PIDShowSensor() {
     JsonParserToken value_token = root[PID_LOCAL_SENSOR_NAME].getObject()[PSTR(PID_LOCAL_SENSOR_TYPE)];
     if (value_token.isNum()) {
       sensor_reading = value_token.getFloat();
+      //AddLog(LOG_LEVEL_DEBUG_MORE, PSTR("PID: PIDProcessSensor: Got isNum: %s"), buf.c_str());
     }
+    //} else {
+    //AddLog(LOG_LEVEL_DEBUG, PSTR("PID: PIDProcessSensor: not valid JSON: %s"), buf.c_str());
   }
 #endif // PID_USE_LOCAL_SENSOR
 
   if (!isnan(sensor_reading)) {
-
     // pass the value to the pid alogorithm to use as current pv
     Pid.last_pv_update_secs = Pid.current_time_secs;
     Pid.pid.setPv(sensor_reading, Pid.last_pv_update_secs);
@@ -292,8 +310,9 @@ void PIDShowSensor() {
     }
   } else {
     // limit sensor not seen message to every 60 seconds to avoid flooding the logs
-    if ((Pid.current_time_secs - Pid.last_pv_update_secs) > Pid.max_interval && ((Pid.current_time_secs - Pid.last_pv_update_secs)%60)==0) {
+    if ((Pid.current_time_secs - Pid.last_pv_update_secs) > Pid.max_interval &&
-      AddLog(LOG_LEVEL_ERROR, PSTR("PID: Local temperature sensor missing for longer than PID_MAX_INTERVAL"));
+        ((Pid.current_time_secs - Pid.last_pv_update_secs)%60)==0) {
+      AddLog(LOG_LEVEL_ERROR, PSTR("PID: Local temperature sensor missing for longer than PID_MAX_INTERVAL - PID have fallen back to manual"));
     }
   }
 }
@@ -401,59 +420,6 @@ void CmndSetShutdown(void) {
   ResponseCmndNumber(Pid.shutdown);
 }
 
-void PIDShowValues(void) {
-  char str_buf[FLOATSZ];
-  char chr_buf;
-  int i_buf;
-  double d_buf;
-  ResponseAppend_P(PSTR(",\"PID\":{"));
-
-  d_buf = Pid.pid.getPv();
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidPv\":%s,"), str_buf);
-  d_buf = Pid.pid.getSp();
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidSp\":%s,"), str_buf);
-  ResponseAppend_P(PSTR("\"PidShutdown\":%d,"), Pid.shutdown);
-
-#if PID_REPORT_MORE_SETTINGS
-  d_buf = Pid.pid.getPb();
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidPb\":%s,"), str_buf);
-  d_buf = Pid.pid.getTi();
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidTi\":%s,"), str_buf);
-  d_buf = Pid.pid.getTd();
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidTd\":%s,"), str_buf);
-  d_buf = Pid.pid.getInitialInt();
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidInitialInt\":%s,"), str_buf);
-  d_buf = Pid.pid.getDSmooth();
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidDSmooth\":%s,"), str_buf);
-  chr_buf = Pid.pid.getAuto();
-  ResponseAppend_P(PSTR("\"PidAuto\":%d,"), chr_buf);
-  d_buf = Pid.pid.getManualPower();
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidManualPower\":%s,"), str_buf);
-  i_buf = Pid.pid.getMaxInterval();
-  ResponseAppend_P(PSTR("\"PidMaxInterval\":%d,"), i_buf);
-  i_buf = Pid.current_time_secs - Pid.last_pv_update_secs;
-  ResponseAppend_P(PSTR("\"PidInterval\":%d,"), i_buf);
-  ResponseAppend_P(PSTR("\"PidUpdateSecs\":%d,"), Pid.update_secs);
-#endif // PID_REPORT_MORE_SETTINGS
-
-  i_buf = (Pid.current_time_secs - Pid.last_pv_update_secs) > Pid.pid.getMaxInterval();
-  ResponseAppend_P(PSTR("\"PidSensorLost\":%d,"), i_buf);
-// The actual power value
-  d_buf = Pid.pid.tick(Pid.current_time_secs);
-  dtostrfd(d_buf, 2, str_buf);
-  ResponseAppend_P(PSTR("\"PidPower\":%s"), str_buf);
-
-  ResponseAppend_P(PSTR("}"));
-}
-
 #ifdef USE_WEBSERVER
 #define D_PID_DISPLAY_NAME     "PID Controller"
 #define D_PID_SET_POINT        "Set Point"
@@ -469,44 +435,106 @@ const char HTTP_PID_INFO[] PROGMEM = "{s}" D_PID_DISPLAY_NAME "{m}%s{e}";
 const char HTTP_PID_SP_FORMAT[] PROGMEM = "{s}%s " "{m}%*_f ";
 const char HTTP_PID_PV_FORMAT[] PROGMEM = "{s}%s " "{m}%*_f ";
 const char HTTP_PID_POWER_FORMAT[] PROGMEM = "{s}%s " "{m}%*_f " D_UNIT_PERCENT;
-
-void PIDShowValuesWeb(void) {
-  float f_buf;
-
-  WSContentSend_P(HTTP_PID_HL);
-  WSContentSend_P(HTTP_PID_INFO, (Pid.pid.getAuto()==1) ? D_PID_MODE_AUTO : Pid.pid.tick(Pid.current_time_secs)>0.0f ? D_PID_MODE_MANUAL : D_PID_MODE_OFF);
-
-  if (Pid.pid.getAuto()==1 || Pid.pid.tick(Pid.current_time_secs)>0.0f) {
-    f_buf = (float)Pid.pid.getSp();
-    WSContentSend_PD(HTTP_PID_SP_FORMAT, D_PID_SET_POINT, 1, &f_buf);
-    f_buf = (float)Pid.pid.getPv();
-    WSContentSend_PD(HTTP_PID_PV_FORMAT, D_PID_PRESENT_VALUE, 1, &f_buf);
-    f_buf = Pid.pid.tick(Pid.current_time_secs)*100.0f;
-    WSContentSend_PD(HTTP_PID_POWER_FORMAT, D_PID_POWER, 0, &f_buf);
-  }
-}
 #endif  // USE_WEBSERVER
 
+void PIDShowValues(bool json) {
+  char str_buf[FLOATSZ];
+  char chr_buf;
+  int i_buf;
+  double d_buf;
+  float f_buf;
+
+  if (json) {
+    ResponseAppend_P(PSTR(",\"PID\":{"));
+
+    d_buf = Pid.pid.getPv();
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidPv\":%s,"), str_buf);
+    d_buf = Pid.pid.getSp();
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidSp\":%s,"), str_buf);
+    ResponseAppend_P(PSTR("\"PidShutdown\":%d,"), Pid.shutdown);
+
+#if PID_REPORT_MORE_SETTINGS
+    d_buf = Pid.pid.getPb();
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidPb\":%s,"), str_buf);
+    d_buf = Pid.pid.getTi();
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidTi\":%s,"), str_buf);
+    d_buf = Pid.pid.getTd();
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidTd\":%s,"), str_buf);
+    d_buf = Pid.pid.getInitialInt();
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidInitialInt\":%s,"), str_buf);
+    d_buf = Pid.pid.getDSmooth();
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidDSmooth\":%s,"), str_buf);
+    chr_buf = Pid.pid.getAuto();
+    ResponseAppend_P(PSTR("\"PidAuto\":%d,"), chr_buf);
+    d_buf = Pid.pid.getManualPower();
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidManualPower\":%s,"), str_buf);
+    i_buf = Pid.pid.getMaxInterval();
+    ResponseAppend_P(PSTR("\"PidMaxInterval\":%d,"), i_buf);
+    i_buf = Pid.current_time_secs - Pid.last_pv_update_secs;
+    ResponseAppend_P(PSTR("\"PidInterval\":%d,"), i_buf);
+    ResponseAppend_P(PSTR("\"PidUpdateSecs\":%d,"), Pid.update_secs);
+#endif // PID_REPORT_MORE_SETTINGS
+
+    i_buf = (Pid.current_time_secs - Pid.last_pv_update_secs) > Pid.pid.getMaxInterval();
+    ResponseAppend_P(PSTR("\"PidSensorLost\":%d,"), i_buf);
+
+    d_buf = Pid.power;
+    dtostrfd(d_buf, 2, str_buf);
+    ResponseAppend_P(PSTR("\"PidPower\":%s"), str_buf);
+
+    ResponseJsonEnd();
+
+    return;
+  }
+
+#ifdef USE_WEBSERVER
+  WSContentSend_P(HTTP_PID_HL);
+  WSContentSend_P(HTTP_PID_INFO, (Pid.pid.getAuto()==1) ?
+                  D_PID_MODE_AUTO :
+                  Pid.power>0.0f ? D_PID_MODE_MANUAL : D_PID_MODE_OFF);
+
+  if (Pid.pid.getAuto()==1 || Pid.power > 0.0f) {
+    f_buf = Pid.pid.getSp();
+    WSContentSend_PD(HTTP_PID_SP_FORMAT, D_PID_SET_POINT, 1, &f_buf);
+    f_buf = Pid.pid.getPv();
+    WSContentSend_PD(HTTP_PID_PV_FORMAT, D_PID_PRESENT_VALUE, 1, &f_buf);
+    f_buf = Pid.power*100.0f;
+    WSContentSend_PD(HTTP_PID_POWER_FORMAT, D_PID_POWER, 0, &f_buf);
+  }
+#endif  // USE_WEBSERVER
+}
+
 void PIDRun(void) {
-  double power = Pid.pid.tick(Pid.current_time_secs);
+  //AddLog(LOG_LEVEL_DEBUG_MORE, PSTR("PIDRUN(): tick"));
+  Pid.power = Pid.pid.tick(Pid.current_time_secs);
 #ifdef PID_DONT_USE_PID_TOPIC
   // This part is left inside to regularly publish the PID Power via
   // `%topic%/PID {"power":"0.000"}`
   char str_buf[FLOATSZ];
-  dtostrfd(power, 3, str_buf);
+  dtostrfd(Pid.power, 3, str_buf);
   Response_P(PSTR("{\"%s\":\"%s\"}"), "power", str_buf);
   MqttPublishPrefixTopicRulesProcess_P(TELE, "PID");
 #endif // PID_DONT_USE_PID_TOPIC
 
 #if defined PID_SHUTTER
   // send output as a position from 0-100 to defined shutter
-  int pos = power * 100;
+  int pos = Pid.power * 100;
+  //AddLog(LOG_LEVEL_DEBUG, PSTR("PIDRun: Setting Shutter to %i"), pos );
   ShutterSetPosition(PID_SHUTTER, pos);
 #endif //PID_SHUTTER
 
 #if defined(PID_USE_TIMPROP) && (PID_USE_TIMPROP > 0)
   // send power to appropriate timeprop output
-  TimepropSetPower( PID_USE_TIMPROP-1, power );
+  //AddLog(LOG_LEVEL_DEBUG, PSTR("PIDRun: Setting TimeProp to %d"), Pid.power );
+  TimepropSetPower( PID_USE_TIMPROP-1, Pid.power );
 #endif // PID_USE_TIMPROP
 }
 
@@ -520,6 +548,7 @@ bool Xdrv49(uint32_t function) {
   bool result = false;
 
   switch (function) {
+    // Call sequence documented https://tasmota.github.io/docs/API
     case FUNC_INIT:
       PIDInit();
       break;
@@ -527,22 +556,18 @@ bool Xdrv49(uint32_t function) {
       PIDEverySecond();
       break;
     case FUNC_SHOW_SENSOR:
-      // only use this if the pid loop is to use the local sensor for pv
-      #if defined PID_USE_LOCAL_SENSOR
-        PIDShowSensor();
-      #endif // PID_USE_LOCAL_SENSOR
-      break;
-    case FUNC_COMMAND:
-      result = DecodeCommand(kPIDCommands, PIDCommand);
       break;
     case FUNC_JSON_APPEND:
-      PIDShowValues();
+      PIDShowValues(true);
       break;
 #ifdef USE_WEBSERVER
     case FUNC_WEB_SENSOR:
-      PIDShowValuesWeb();
+      PIDShowValues(false);
       break;
 #endif  // USE_WEBSERVER
+    case FUNC_COMMAND:
+      result = DecodeCommand(kPIDCommands, PIDCommand);
+      break;
     case FUNC_ACTIVE:
       result = true;
       break;