search

arjenhiemstra / ithowifi

Itho wifi add-on module (ESP32 wifi to itho I2C protocol)
GNU General Public License v3.0
181 stars 32 forks source link

Maximum speed after a reboot #86

Closed reneklootwijk closed 2 years ago

reneklootwijk commented 2 years ago

Since I installed the module I experienced a number of times the fan spontaneous going to maximum speed and I had to turn it down again. Looking at the debug logs it seems to appear just after a reboot has been initiated by the watchdog:

System boot, last reset reason: OWDT_RESET

Is it only me experiencing this?

Device information

Debug logging See above

arjenhiemstra commented 2 years ago

The wdt reset should not happen in the first place so that is something to investigate further. But a wdt reset should not lead to a high speed setting of the fan unless this was configured intentionally by the startup speed setting. If a (wdt) startup leads to a high speed setting most of the times some value is still present on for example a MQTT topic. Depending on your domotica system it might be quite easy to log all commands to the API (ie. a node-red MQTT capture / log all commands flow) to debug this.

reneklootwijk commented 2 years ago

A few minutes ago the cve again spontaneously went to full speed.

This is what is in the debug log:

2022-04-06 06:57:32 N: System boot, last reset reason: DEEPSLEEP_RESET
2022-04-06 06:57:32 N: HW rev: 2, FW ver.: 2.3.5
2022-04-06 06:57:32 N: Static IP config OK
2022-04-06 06:57:36 N: WiFi: connection successful
2022-04-06 06:57:36 N: WiFi info:
2022-04-06 06:57:36 N: Mode:STA
2022-04-06 07:19:33 N: Status:3
2022-04-06 07:19:33 N: IP:192.168.5.129
2022-04-06 07:19:33 N: Setup: Virtual remote ID: 139,195,80
2022-04-06 07:19:33 N: Setup: init of CC1101 RF module successful
2022-04-06 07:19:34 N: MQTT: connected, System config: 1
2022-04-06 07:19:34 N: Webserver: started
2022-04-06 07:19:34 N: mDNS: started
2022-04-06 07:19:34 N: Hostname: Itho
2022-04-06 07:19:34 N: Setup: done
2022-04-06 07:19:42 N: I2C init: QueryDevicetype - fw:11 hw:27
2022-04-06 07:19:42 N: I2C init: QueryStatusFormat - items:15
2022-04-06 07:19:42 N: I2C init: QueryStatus
2022-04-06 07:19:42 N: HA DISCOVERY: Start publishing MQTT Home Assistant

I am sure there has not been given any command and there was no MQTT command queued (I use QOS 0). The home automation software I am using I created myself and is in use for many many years, so I know how it is working.

reneklootwijk commented 2 years ago

And again:

2022-04-07 20:45:18 N: System boot, last reset reason: DEEPSLEEP_RESET
2022-04-07 20:45:18 N: HW rev: 2, FW ver.: 2.3.5
2022-04-07 20:45:19 N: Static IP config OK
2022-04-07 20:45:22 N: WiFi: connection successful
2022-04-07 20:45:22 N: WiFi info:
2022-04-07 20:45:22 N: Mode:STA
2022-04-07 20:45:23 N: Status:3
2022-04-07 20:45:23 N: IP:192.168.5.129
2022-04-07 20:45:23 N: Setup: Virtual remote ID: 139,195,80
2022-04-07 20:45:23 N: Setup: init of CC1101 RF module successful
2022-04-07 20:47:25 N: MQTT: connected, System config: 1
2022-04-07 20:47:25 N: Webserver: started
2022-04-07 20:47:25 N: mDNS: started
2022-04-07 20:47:25 N: Hostname: Itho
2022-04-07 20:47:25 N: Setup: done
2022-04-07 20:47:32 N: I2C init: QueryDevicetype - fw:11 hw:27
2022-04-07 20:47:32 N: I2C init: QueryStatusFormat - items:15
2022-04-07 20:47:32 N: I2C init: QueryStatus
2022-04-07 20:47:32 N: HA DISCOVERY: Start publishing MQTT Home Assistant Discovery...
Label Value
Speed status 99
Internal fault 0
Frost cycle 0
Filter dirty 0
Ventilation setpoint (%) 99
Fan setpoint (rpm) 2680
Fan speed (rpm) 2684
Error 0
Selection 3
Startup counter 779
Total operation (hours) 69570
Absence (min) 0
Deferred absence (min) 0
Highest CO2 concentration (ppm) 0
Co2 velocity 0
Valve 2
Presence timer (sec) 0
Current period 0
Period timer 0
arjenhiemstra commented 2 years ago

Not sure why the module would DEEPSLEEP_RESET, that is new to me. Still a commando must be given at some time (either originating from firmware or externally). Just to be sure; you haven't set the 'Start/fallback speed' speed setting to a high value?

Would it be possible to track the status of the lastcmd MQTT topic? That should give an indication where the command originates from and help pointing to the right direction hopefully.

The home automation software I am using I created myself and is in use for many many years, so I know how it is working.

Nice work! 👍 🥇

reneklootwijk commented 2 years ago

These are the settings: image

These are the logs of commands send to the CVE on the day the last time the issue occured:

2022-04-07T05:57:55.513Z debug: iConnectActionHandler: Entering for 62f633ef-c0b1-4337-9e1f-e42bacd271eb with {"speed":254}
2022-04-07T06:23:10.331Z debug: iConnectActionHandler: Entering for 62f633ef-c0b1-4337-9e1f-e42bacd271eb with {"speed":38}

These are the topics configured for your controller: image

These are the logs of the MQTT messages send by your module around the last time the issue occurred (I was already capturing everything but did not have a look at it):

2022-04-07T20:45:02.951Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:02.976Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:03.034Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:07.969Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:08.006Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:08.051Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:12.965Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":910,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:12.987Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:13.027Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:17.947Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:17.972Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:18.013Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:23.020Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:23.039Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:23.093Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:27.986Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:28.010Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:28.048Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:32.974Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:32.999Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:33.042Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:38.016Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:38.043Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:38.091Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:43.020Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":910,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:43.044Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:43.084Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:48.025Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:48.060Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:48.101Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:53.073Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:53.090Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:53.140Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:45:58.087Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":910,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:45:58.123Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:45:58.176Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:03.033Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":912,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:03.052Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:03.105Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:08.074Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":910,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:08.104Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:08.144Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:13.130Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:13.140Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:13.189Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:18.146Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:18.166Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:18.214Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:23.104Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:23.146Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:23.164Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:28.075Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":910,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:28.108Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:28.149Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:33.109Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:33.139Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:33.189Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:38.158Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":910,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:38.186Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:38.235Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:43.150Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:43.172Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:43.216Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:48.154Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:48.178Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:48.220Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:53.179Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:53.220Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:53.269Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:46:58.170Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:46:58.170Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:46:58.196Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:47:03.126Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:03.148Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:03.189Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:47:08.204Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:08.232Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:08.288Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:47:13.247Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:13.276Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:13.322Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:47:18.216Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":10.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":10,"Fan setpoint (rpm)":909,"Fan speed (rpm)":911,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:18.233Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:18.274Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649312586}}
2022-04-07T20:47:28.836Z debug: ithoEventHandler: Entering with {"topic":"itho/1/lw","message":"online"}
2022-04-07T20:47:29.376Z debug: ithoEventHandler: Entering with {"topic":"itho/1/lw","message":"online"}
2022-04-07T20:47:29.376Z debug: ithoEventHandler: Entering with {"topic":"itho/1/state","message":254}
2022-04-07T20:47:37.475Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":24.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":99,"Fan setpoint (rpm)":2680,"Fan speed (rpm)":1196,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:37.507Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:37.547Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":null,"command":"","timestamp":0}}
2022-04-07T20:47:42.169Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":91.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":99,"Fan setpoint (rpm)":2680,"Fan speed (rpm)":2539,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:42.198Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:42.239Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":null,"command":"","timestamp":0}}
2022-04-07T20:47:47.086Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":99,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":99,"Fan setpoint (rpm)":2680,"Fan speed (rpm)":2684,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:47.104Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:47.144Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":null,"command":"","timestamp":0}}
2022-04-07T20:47:52.148Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":99,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":99,"Fan setpoint (rpm)":2680,"Fan speed (rpm)":2684,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:52.161Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:52.199Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":null,"command":"","timestamp":0}}
2022-04-07T20:47:57.157Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":99,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":99,"Fan setpoint (rpm)":2680,"Fan speed (rpm)":2685,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:57.185Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:57.227Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":null,"command":"","timestamp":0}}

This is where it goes wrong, the MQTT server detects the disconnect and published the last will and the next message is the initialisation message from your controller and it clearly states there was no last command:

2022-04-07T20:47:29.376Z debug: ithoEventHandler: Entering with {"topic":"itho/1/lw","message":"online"}
2022-04-07T20:47:29.376Z debug: ithoEventHandler: Entering with {"topic":"itho/1/state","message":254}
2022-04-07T20:47:37.475Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":24.5,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":99,"Fan setpoint (rpm)":2680,"Fan speed (rpm)":1196,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69570,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-07T20:47:37.507Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{"Badkamer boven":{"lastcmd":0}}}
2022-04-07T20:47:37.547Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":null,"command":"","timestamp":0}}

BTW You publish online as the last will, this should be offline i.m.o.

arjenhiemstra commented 2 years ago

Thanks for the info! Cannot explain it right away but I'll dive into it! Given the ""source":null" status I expect an overflow issue somewhere

About the last will implementation; The client connects to the broker with retained message "offline" here: https://github.com/arjenhiemstra/ithowifi/blob/ac3b3daad45f3099366600e7b106637a9ed71eab/software/NRG_itho_wifi/TaskMQTT.ino#L505

and publishes "online" after succesful connect here: https://github.com/arjenhiemstra/ithowifi/blob/ac3b3daad45f3099366600e7b106637a9ed71eab/software/NRG_itho_wifi/TaskMQTT.ino#L514

I tested it and on an ungraceful disconnect the broker correctly reports "offline" after some time. A graceful disconnect is handled here: https://github.com/arjenhiemstra/ithowifi/blob/ac3b3daad45f3099366600e7b106637a9ed71eab/software/NRG_itho_wifi/TaskMQTT.ino#L522

following the described best practice here I believe: https://www.hivemq.com/blog/mqtt-essentials-part-9-last-will-and-testament/#:~:text=In%20MQTT%2C%20you%20use%20the,flag%2C%20QoS%2C%20and%20payload.

Happy to change the implementation if I understood it incorrectly

arjenhiemstra commented 2 years ago

Please try https://github.com/arjenhiemstra/ithowifi/releases/tag/Version-2.4.0-alpha6

The only thing that could trigger a command right after reboot is the queue, when values are uninitialised before the queue sends a command this could result in a garbage speed command being fed, translating probably to a >254 number in unsigned int16 which will be capped to 254. That is probably what happens here but I cannot explain really why but c++ class variable init is certainly not my specialty so I easily might overlooked something here.

The version linked will log the first command to the MQTT topic after boot (when send from the queue and when no other command has been send which seems to be the case) and will also log an error when the value from the queue is >254. A speed command >254 will be ignored, so if my theory is right you will only see a message on MQTT and the fan won't spin up to max speed.

reneklootwijk commented 2 years ago

I updated the firmware and immediately after the reboot the speed went again to 254.

Debug log (I do not what happens to the timestamp, but all these events where directly after each other):

2022-04-15 18:50:35 N: Firmware update: nrgitho-hw2-v2.4.0-alpha6.bin
2022-04-15 18:50:57 N: Reboot requested
2022-04-15 18:10:49 I: System boot, last reset reason: SDIO_RESET
2022-04-15 18:10:49 I: HW rev: 2, FW ver.: 2.4.0-alpha6
2022-04-15 18:10:50 I: Static IP config OK
2022-04-15 18:10:53 I: WiFi: connection successful
2022-04-15 18:10:53 I: WiFi info:
2022-04-15 18:10:53 I: Mode:STA
2022-04-15 18:10:53 I: Status:3
2022-04-15 18:10:54 I: IP:192.168.5.129
2022-04-15 18:10:54 I: Setup: Virtual remote ID: 139,195,80
2022-04-15 18:10:54 I: Setup: writing initial remotes config
2022-04-15 18:10:54 I: Setup: remotes configfile loaded
2022-04-15 18:10:54 I: Setup: init of CC1101 RF module successful
2022-04-15 18:10:54 I: Remotes config version mismatch, resetting config...
2022-04-15 18:10:58 I: System boot, last reset reason: SW_RESET
2022-04-15 18:10:58 I: HW rev: 2, FW ver.: 2.4.0-alpha6
2022-04-15 18:10:59 I: Static IP config OK
2022-04-15 18:11:02 I: WiFi: connection successful
2022-04-15 18:11:03 I: WiFi info:
2022-04-15 18:11:03 I: Mode:STA
2022-04-15 18:11:03 I: Status:3
2022-04-15 18:11:03 I: IP:192.168.5.129
2022-04-15 18:11:03 I: Setup: Virtual remote ID: 139,195,80
2022-04-15 18:11:03 I: Setup: remotes configfile loaded
2022-04-15 18:11:04 I: Setup: init of CC1101 RF module successful
2022-04-15 18:11:04 I: MQTT: connected, System config: 1
2022-04-15 18:11:04 I: Setup: remotes configfile loaded
2022-04-15 18:11:04 I: Webserver: started
2022-04-15 18:11:04 I: mDNS: started
2022-04-15 18:11:05 I: Hostname: Itho
2022-04-15 18:11:05 I: Setup: done
2022-04-15 18:51:24 I: I2C init: QueryDevicetype - fw:11 hw:27
2022-04-15 18:51:24 I: I2C init: QueryStatusFormat - items:15
2022-04-15 18:51:24 I: I2C init: QueryStatus
2022-04-15 18:51:25 I: HA DISCOVERY: Start publishing MQTT Home Assistant Discovery...

MQTT log:

2022-04-15T18:50:38.688Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649965164}}
2022-04-15T18:51:23.124Z debug: ithoEventHandler: Entering with {"topic":"itho/1/lw","message":"online"}
2022-04-15T18:51:23.392Z debug: ithoEventHandler: Entering with {"topic":"itho/1/lw","message":"online"}
2022-04-15T18:51:24.216Z debug: ithoEventHandler: Entering with {"topic":"itho/1/state","message":254}
2022-04-15T18:51:24.216Z debug: iconnect.protocol.publishEvent: Entering with {"uuid":"62f633ef-c0b1-4337-9e1f-e42bacd271eb","type":"ventilation_controller","property":"speed","value":254}
2022-04-15T18:51:32.200Z debug: ithoEventHandler: Entering with {"topic":"itho/1/status","message":{"Speed status":99,"Internal fault":0,"Frost cycle":0,"Filter dirty":0,"Ventilation setpoint (%)":99,"Fan setpoint (rpm)":2680,"Fan speed (rpm)":2686,"Error":0,"Selection":3,"Startup counter":779,"Total operation (hours)":69760,"Absence (min)":0,"Deferred absence (min)":0,"Highest CO2 concentration (ppm)":0,"Co2 velocity":0,"Valve":2,"Presence timer (sec)":0,"Current period":0,"Period timer":0}}
2022-04-15T18:51:32.203Z debug: iConnectActionHandler: Entering for 62f633ef-c0b1-4337-9e1f-e42bacd271eb with {"speed":38}
2022-04-15T18:51:32.204Z debug: iconnect.protocol.publishRaw: Entering with {"topic":"itho/1/command","payload":"{\"speed\":38}"}
2022-04-15T18:51:32.205Z debug: ithoEventHandler: Entering with {"topic":"itho/1/remotes","message":{}}
2022-04-15T18:51:32.245Z debug: ithoEventHandler: Entering with {"topic":"itho/1/command","message":{"speed":38}}

I created a rule that as soon as the ventilation goes to speed 254 and there was no trigger from my home automation system a command will be send to set it back to 38 (should I put a delay on it??). That is what you see at 18:51:32. To get back to the last will, I do not receive as last will with message offline, instead I receive twice a last will with message online.

reneklootwijk commented 2 years ago

With regards to the last will: After a firmware update do you gracefully disconnect and send a offline message explicitly from MQTT before a reboot is initiated?

Logs from my MQTT server:

Apr 15 20:50:35 iconnect mosquitto: 1650048635: Client Itho disconnected.
Apr 15 20:51:16 iconnect mosquitto: 1650048676: New connection from xxx.xxx.xxx.xxx on port 1883.
Apr 15 20:51:16 iconnect mosquitto: 1650048676: New client connected from xxx.xxx.xxx.xxx as Itho (c1, k15).

I did a reset via the web ui and also then I only receive 2 online message on the lw topic.

arjenhiemstra commented 2 years ago

Nothing on the lastcmd topic in your MQTT log around or somewhere after 2022-04-15T18:51:24.216Z debug: ithoEventHandler: Entering with {"topic":"itho/1/state","message":254} ??

should I put a delay on it??

I would say for testing at least a delay > your "Itho status update frequency" setting, that way at least 1 MQTT log entry should by there before your correction command triggers

reneklootwijk commented 2 years ago

I put a 10s delay on the rule, the update frequency of the itho state is 5s.

These are the different messages on the last_command topic (indeed I see a message with source ithoQueue):

2022-04-15T18:50:38.688Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1649965164}}
2022-04-15T18:51:32.247Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"ithoQueue","command":"speed:254","timestamp":1650046265}}
2022-04-15T18:51:36.864Z debug: ithoEventHandler: Entering with {"topic":"itho/1/last_command","message":{"source":"MQTT API","command":"speed:38","timestamp":1650048686}}
arjenhiemstra commented 2 years ago

Ok, still no explanation unfortunately, lets dig a little bit deeper.

The linked version logs every command being executed to a log file. The log file can be downloaded through the file editor (which can be found on the debug page). De file is called cmdlog0.current.log or something.

Little warning, this firmware logs info at least every second. Best not to let it running for too long. Update firmware, test, download logfiles and put back the normal version would be the best course of action. If you could provide the logfile here that would be great!

2.4.0-cmdlogtest1.bin.zip

reneklootwijk commented 2 years ago

I installed this version. The cve did go to maximum speed this time.

cmdlog0.current.log

And reverted back to the alpha6 version, also now the cve did not go maximum speed.

arjenhiemstra commented 2 years ago

I was wondering why so little showed up but I now realise I made an error implementing some logging commands, pushing the output just to the serial port instead of flash log.

This version contains a lot more logging: 2.4.0-cmdlogtest2.bin.zip

reneklootwijk commented 2 years ago

cmdlog0.current (1).log

arjenhiemstra commented 2 years ago

thx! Did in this case the fan spin up to max speed? Cause from the log it seems not to be the case...

reneklootwijk commented 2 years ago

No it did not, only the first update to the alpha6 firmware, this afternoon, made the fan go to max speed.

arjenhiemstra commented 2 years ago

Apparently we have entered the realm of quantum mechanics here.... I'm kinda puzzled for a moment

reneklootwijk commented 2 years ago

I will be abroad whole week, so cannot do much. Next week I will try to dive into your sources.

arjenhiemstra commented 2 years ago

FYI. the changes for this test firmware are committed to a separate branch; https://github.com/arjenhiemstra/ithowifi/tree/2.4.0-cmdlogtest

besides the logging stuff I made two 'functional' changes, one mem allocation is moved from stack to heap and the update frequency of the queue has been lowered to once a second instead of 100ms to prevent too much writes to flash. Cannot rule these out so I will compile a version without the logging but with the two other changes just to be sure.

Thx for looking into it as well, the source code might be a bit challenging here and there, sorry. Almost all stages of me learning to code are in here.... rework needed so to say

reneklootwijk commented 2 years ago

Don't worry I am not a master myself also (especially not with C++). I'll appreciate the work you have done so far.

BTW your name really sounds familiar, have you been working at ING?

arjenhiemstra commented 2 years ago

BTW your name really sounds familiar, have you been working at ING?

Yep! Thought your name sounded familiar as well! :) I was lead for the MS CDaaS team a while ago

reneklootwijk commented 2 years ago

Ah yes and before that you were in the team of Bart right?

BTW the module did not reboot since last week so I did not experience the issue anymore. Waiting for the next reboot ;-)

reneklootwijk commented 2 years ago

Tonight another spontaneous reboot, but the speed did not go to the max. So the change in the firmware seems to work.

2022-05-02 02:55:51 I: System boot, last reset reason: SW_RESET
2022-05-02 02:55:51 I: HW rev: 2, FW ver.: 2.4.0-alpha6
stale[bot] commented 2 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.