MQTT with TLS not working #3211

schlamar · 2024-08-31T14:47:45Z

The Problem

I have configured MQTT with TLS however the connections fails without a useful error:

<INF>	[MQTT IF] using caCert: /config/cacert.pem
<DBG>	[MQTT IF] URI: mqtts://mosquitto.local.schlamar.de:8883, clientname: watermeter
...
<ERR>	[MQTT IF] Other event id:
<WRN>	[MQTT IF] Disconnected, trying to reconnect

My server is configured correctly. TLS Connection with a simple Python script works:

context = ssl.create_default_context(
        purpose=ssl.Purpose.SERVER_AUTH, cafile="cacert.pem"
    )
s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
ssl_sock = context.wrap_socket(s, server_hostname="mosquitto.local.schlamar.de")
ssl_sock.connect(("mosquitto.local.schlamar.de", 8883))

Version

15.7.0

Logfile

[0d00h00m00s] 2024-08-31T14:26:43	<INF>	[MAIN] =================================================
[0d00h00m00s] 2024-08-31T14:26:43	<INF>	[MAIN] ==================== Start ======================
[0d00h00m00s] 2024-08-31T14:26:43	<INF>	[MAIN] =================================================
[0d00h00m00s] 2024-08-31T14:26:43	<INF>	[MAIN] PSRAM size: 8388608 byte (8MB / 64MBit)
[0d00h00m00s] 2024-08-31T14:26:43	<INF>	[MAIN] Total heap: 4380199 byte
[0d00h00m04s] 2024-08-31T14:26:47	<INF>	[MAIN] Camera info: PID: 0x26, VER: 0x42, MIDL: 0x7f, MIDH: 0xa2
[0d00h00m04s] 2024-08-31T14:26:47	<INF>	[SDCARD] Basic R/W check started...
[0d00h00m04s] 2024-08-31T14:26:47	<INF>	[SDCARD] Basic R/W check successful
[0d00h00m04s] 2024-08-31T14:26:47	<INF>	[SNTP] TimeServer not defined, using default: pool.ntp.org
[0d00h00m04s] 2024-08-31T14:26:47	<INF>	[SNTP] Configuring NTP Client...
[0d00h00m04s] 2024-08-31T16:26:47	<INF>	[SNTP] Time zone set to CET-1CEST,M3.5.0,M10.5.0/3
[0d00h00m04s] 2024-08-31T16:26:47	<INF>	[SNTP] time zone: +0200 Delta to UTC: 7200 seconds
[0d00h00m04s] 2024-08-31T16:26:47	<INF>	[SNTP] Time is already set: 2024-08-31 16:26:47
[0d00h00m04s] 2024-08-31T16:26:47	<INF>	[MAIN] CPU frequency: 160 MHz
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[SDCARD] Folder/file presence check started...
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[SDCARD] Folder/file presence check successful
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[MAIN] Tag: 'v15.7.0', Release: v15.7.0 (Commit: 0d0b018+), Date/Time: 2024-02-17 00:15, Web UI: Release: v15.7.0 (Commit: 0d0b018+)
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[MAIN] Reset reason: Via esp_restart
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[WLANINI] SSID: easybell DSL-FD9E95
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[WLANINI] Password: XXXXXXXX
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[WLANINI] RSSIThreshold: -75
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[MAIN] WLAN config loaded, init WIFI...
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[WIFI] Automatic interface config --> Use DHCP service
[0d00h00m05s] 2024-08-31T16:26:48	<INF>	[WIFI] Set hostname to: watermeter
[0d00h00m06s] 2024-08-31T16:26:48	<INF>	[WIFI] Init successful
[0d00h00m10s] 2024-08-31T16:26:53	<INF>	[WIFI] Connected to: easybell DSL-FD9E95, RSSI: -64
[0d00h00m11s] 2024-08-31T16:26:54	<INF>	[WIFI] Assigned IP: 192.168.181.60
[0d00h00m11s] 2024-08-31T16:26:54	<INF>	[SNTP] Time is synced with NTP Server pool.ntp.org: 2024-08-31 16:26:54
[0d00h00m12s] 2024-08-31T16:26:55	<INF>	[MAIN] Device info: CPU cores: 2, Chip revision: 101
[0d00h00m12s] 2024-08-31T16:26:55	<INF>	[MAIN] SD card info: Name: NCard, Capacity: 14910MB, Free: 14890MB
[0d00h00m14s] 2024-08-31T16:26:57	<INF>	[MAIN] Initialization completed successfully
[0d00h00m17s] 2024-08-31T16:27:00	<INF>	[LOGFILE] Set log level to DEBUG
[0d00h00m17s] 2024-08-31T16:27:00	<DBG>	[MQTT] Digitizer interval is 5.0 minutes => setting MQTT LWT timeout to 12.5 minutes.
[0d00h00m17s] 2024-08-31T16:27:00	<INF>	[MQTT IF] using caCert: /config/cacert.pem
[0d00h00m17s] 2024-08-31T16:27:00	<DBG>	[MQTT IF] URI: mqtts://mosquitto.local.schlamar.de:8883, clientname: watermeter, user: watermeter, password: XXXXXXXX, maintopic: watermeter, last-will-topic: watermeter/connection, keepAlive: 750, RetainFlag: 0
[0d00h00m17s] 2024-08-31T16:27:00	<INF>	[MQTT IF] Init
[0d00h00m17s] 2024-08-31T16:27:00	<INF>	[MQTT IF] Client started, waiting for established connection...
[0d00h00m17s] 2024-08-31T16:27:00	<INF>	[MAINCTRL] Starting Flow...
[0d00h00m17s] 2024-08-31T16:27:00	<DBG>	[MAINCTRL] ----------------------------------------------------------------
[0d00h00m17s] 2024-08-31T16:27:00	<INF>	[MAINCTRL] Round #1 started
[0d00h00m17s] 2024-08-31T16:27:00	<DBG>	[FLOWCTRL] Status: Take Image (16:27:00)
[0d00h00m17s] 2024-08-31T16:27:00	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h00m17s] 2024-08-31T16:27:00	<DBG>	[PSRAM] Init shared memory for step 'Take Image' (STBI buffers)
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocating memory (307215 bytes) for STBI (use shared memory in PSRAM)...
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocating memory (153615 bytes) for STBI (use shared memory in PSRAM)...
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocating memory (153615 bytes) for STBI (use shared memory in PSRAM)...
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocated 643 bytes in PSRAM for 'STBI'
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocated 643 bytes in PSRAM for 'STBI'
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocated 643 bytes in PSRAM for 'STBI'
[0d00h00m24s] 2024-08-31T16:27:07	<DBG>	[PSRAM] Allocating memory (921601 bytes) for STBI (use shared memory in PSRAM)...
[0d00h00m25s] 2024-08-31T16:27:08	<DBG>	[PSRAM] Part of shared memory used for STBI (PSRAM, part of shared memory) is free again
[0d00h00m25s] 2024-08-31T16:27:08	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m25s] 2024-08-31T16:27:08	<DBG>	[PSRAM] Part of shared memory used for STBI (PSRAM, part of shared memory) is free again
[0d00h00m25s] 2024-08-31T16:27:08	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m25s] 2024-08-31T16:27:08	<DBG>	[PSRAM] Part of shared memory used for STBI (PSRAM, part of shared memory) is free again
[0d00h00m25s] 2024-08-31T16:27:08	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m25s] 2024-08-31T16:27:08	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m27s] 2024-08-31T16:27:10	<DBG>	[C IMG BASIS] Not freeing (zwImage as there was never PSRAM allocated for it)
[0d00h00m27s] 2024-08-31T16:27:10	<DBG>	[PSRAM] Deinit shared memory for step 'Take Image' (STBI buffers)
[0d00h00m27s] 2024-08-31T16:27:10	<DBG>	[FLOWCTRL] Status: Aligning (16:27:10)
[0d00h00m27s] 2024-08-31T16:27:10	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h00m28s] 2024-08-31T16:27:11	<DBG>	[PSRAM] Allocating tmpImage (921600 bytes, use shared memory in PSRAM)...
[0d00h00m30s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h00m30s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m30s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h00m30s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 1551 bytes in PSRAM for 'STBI'
[0d00h00m30s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 399 bytes in PSRAM for 'STBI'
[0d00h00m30s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 399 bytes in PSRAM for 'STBI'
[0d00h00m30s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 39 bytes in PSRAM for 'STBI'
[0d00h00m30s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 39 bytes in PSRAM for 'STBI'
[0d00h00m31s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 39 bytes in PSRAM for 'STBI'
[0d00h00m31s] 2024-08-31T16:27:13	<DBG>	[PSRAM] Allocated 2485 bytes in PSRAM for 'STBI'
[0d00h00m31s] 2024-08-31T16:27:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m31s] 2024-08-31T16:27:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m31s] 2024-08-31T16:27:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m31s] 2024-08-31T16:27:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m31s] 2024-08-31T16:27:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m31s] 2024-08-31T16:27:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m31s] 2024-08-31T16:27:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m32s] 2024-08-31T16:27:15	<ERR>	[MQTT IF] Other event id:
[0d00h00m32s] 2024-08-31T16:27:15	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 2319 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 591 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 591 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 44 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 44 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 44 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Allocated 4306 bytes in PSRAM for 'STBI'
[0d00h00m33s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m34s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m34s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m34s] 2024-08-31T16:27:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m34s] 2024-08-31T16:27:17	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m34s] 2024-08-31T16:27:17	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m34s] 2024-08-31T16:27:17	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m38s] 2024-08-31T16:27:21	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h00m41s] 2024-08-31T16:27:24	<DBG>	[OTA FILE] log_get_last_part_handler
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[PSRAM] Shared memory used for tmpImage (PSRAM, part of shared memory) is free again
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[FLOWCTRL] Status: Digitalization of ROIs (16:27:27)
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[CNN] doFlow after alignment
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[PSRAM] Allocating Tensor Arena (819200 bytes, use shared memory in PSRAM)...
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[TFLITE] CTfLiteClass::LoadModel
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[TFLITE] CTfLiteClass::ReadFileToModel: /sdcard/config/dig-cont_0620_s3_q.tflite
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[TFLITE] Loading Model /sdcard/config/dig-cont_0620_s3_q.tflite /size: 315504 bytes...
[0d00h00m44s] 2024-08-31T16:27:27	<DBG>	[PSRAM] Allocating Model memory (1363148 bytes, use shared memory in PSRAM)...
[0d00h00m45s] 2024-08-31T16:27:28	<DBG>	[TFLITE] CTfLiteClass::MakeAllocate
[0d00h00m45s] 2024-08-31T16:27:28	<DBG>	[CNN] Processing Number 'main'
[0d00h00m45s] 2024-08-31T16:27:28	<DBG>	[CNN] ROI #0 - TfLite
[0d00h00m45s] 2024-08-31T16:27:28	<DBG>	[CNN] CNN Type: DoubleHyprid10
[0d00h00m47s] 2024-08-31T16:27:30	<ERR>	[MQTT IF] Other event id:
[0d00h00m47s] 2024-08-31T16:27:30	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h00m48s] 2024-08-31T16:27:31	<DBG>	[CNN] After Invoke
[0d00h00m48s] 2024-08-31T16:27:31	<DBG>	[CNN] _num (p, m): 2 3 1 _val (p, m): 0.992188 0.007812 0.000000 result: 2.007812 _fit: 1.000000
[0d00h00m48s] 2024-08-31T16:27:31	<DBG>	[CNN] ROI #1 - TfLite
[0d00h00m48s] 2024-08-31T16:27:31	<DBG>	[CNN] CNN Type: DoubleHyprid10
[0d00h00m51s] 2024-08-31T16:27:34	<DBG>	[CNN] After Invoke
[0d00h00m51s] 2024-08-31T16:27:34	<DBG>	[CNN] _num (p, m): 4 5 3 _val (p, m): 0.996094 0.000000 0.000000 result: 4.000000 _fit: 0.996094
[0d00h00m51s] 2024-08-31T16:27:34	<DBG>	[CNN] ROI #2 - TfLite
[0d00h00m51s] 2024-08-31T16:27:34	<DBG>	[CNN] CNN Type: DoubleHyprid10
[0d00h00m53s] 2024-08-31T16:27:36	<DBG>	[CNN] After Invoke
[0d00h00m53s] 2024-08-31T16:27:36	<DBG>	[CNN] _num (p, m): 7 8 6 _val (p, m): 0.996094 0.000000 0.000000 result: 7.000000 _fit: 0.996094
[0d00h00m53s] 2024-08-31T16:27:36	<DBG>	[PSRAM] Shared memory used for Tensor Arena and model (PSRAM, part of shared memory) is free again
[0d00h00m54s] 2024-08-31T16:27:36	<DBG>	[FLOWCTRL] Status: Digitalization of ROIs (16:27:36)
[0d00h00m54s] 2024-08-31T16:27:36	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[CNN] doFlow after alignment
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[PSRAM] Allocating Tensor Arena (819200 bytes, use shared memory in PSRAM)...
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[TFLITE] CTfLiteClass::LoadModel
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[TFLITE] CTfLiteClass::ReadFileToModel: /sdcard/config/ana-cont_1208_s2_q.tflite
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[TFLITE] Loading Model /sdcard/config/ana-cont_1208_s2_q.tflite /size: 47232 bytes...
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[PSRAM] Allocating Model memory (1363148 bytes, use shared memory in PSRAM)...
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[TFLITE] CTfLiteClass::MakeAllocate
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[CNN] Processing Number 'main'
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[CNN] ROI #0 - TfLite
[0d00h00m54s] 2024-08-31T16:27:37	<DBG>	[CNN] CNN Type: Analogue
[0d00h00m55s] 2024-08-31T16:27:38	<DBG>	[CNN] After Invoke
[0d00h00m55s] 2024-08-31T16:27:38	<DBG>	[CNN] ROI #1 - TfLite
[0d00h00m55s] 2024-08-31T16:27:38	<DBG>	[CNN] CNN Type: Analogue
[0d00h00m55s] 2024-08-31T16:27:38	<DBG>	[CNN] After Invoke
[0d00h00m55s] 2024-08-31T16:27:38	<DBG>	[CNN] ROI #2 - TfLite
[0d00h00m56s] 2024-08-31T16:27:38	<DBG>	[CNN] CNN Type: Analogue
[0d00h00m56s] 2024-08-31T16:27:39	<DBG>	[CNN] After Invoke
[0d00h00m56s] 2024-08-31T16:27:39	<DBG>	[CNN] ROI #3 - TfLite
[0d00h00m56s] 2024-08-31T16:27:39	<DBG>	[CNN] CNN Type: Analogue
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] After Invoke
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[PSRAM] Shared memory used for Tensor Arena and model (PSRAM, part of shared memory) is free again
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[FLOWCTRL] Status: Post-Processing (16:27:40)
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] getReadout _analog=0, _extendedResolution=0, prev=-1
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] PointerEvalAnalogNew - No predecessor - Result = 6 number: 6.430299 numeral_preceder = -1 Analog_error = 3
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] PointerEvalAnalogNew - number unambiguous, no correction necessary - result = 0 number: 0.720300 numeral_preceder = 6 Analog_error = 3
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] PointerEvalAnalogNew - number ambiguous, correction upwards - result = 6 number: 5.880595 numeral_preceder = 0 Analog_error = 3
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] PointerEvalAnalogNew - number unambiguous, no correction necessary - result = 1 number: 1.449090 numeral_preceder = 6 Analog_error = 3
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] getReadout _analog=0, _extendedResolution=0, prev=1
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] PointerEvalAnalogToDigitNew - NO digital Uncertainty - Result = 7 number: 7.000000 numeral_preceder = 1.449090
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] PointerEvalHybridNew - Analog predecessor, evaluation over PointerEvalAnalogNew = 7 number: 7.000000 number_of_predecessors = 1.449090 eval_predecessors = 1 Digital_Uncertainty = 0.200000
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] getReadout(dig100)  prev=7
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] PointerEvalHybridNew - NO analogue predecessor, no change of digits, as pre-decimal point far enough away = 4 number: 4.000000 number_of_predecessors = 7.000000 eval_predecessors = 7 Digital_Uncertainty = 0.200000
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] getReadout#PointerEvalHybridNew()= 4
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] getReadout#result= 47
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] PointerEvalHybridNew - NO analogue predecessor, no change of digits, as pre-decimal point far enough away = 2 number: 2.007812 number_of_predecessors = 4.000000 eval_predecessors = 4 Digital_Uncertainty = 0.200000
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] getReadout#PointerEvalHybridNew()= 2
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[CNN] getReadout#result= 247
[0d00h00m57s] 2024-08-31T16:27:40	<DBG>	[POSTPROC] handleAllowNegativeRate for device: main
[0d00h00m57s] 2024-08-31T16:27:40	<INF>	[POSTPROC] main: Raw: 247.1606, Value: 247.1606, Status: no error
[0d00h00m58s] 2024-08-31T16:27:40	<DBG>	[FLOWCTRL] Status: Sending MQTT (16:27:40)
[0d00h00m58s] 2024-08-31T16:27:41	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h00m58s] 2024-08-31T16:27:41	<WRN>	[MQTT SERVER] Unable to send Homeassistant Discovery Topics, we are not connected to the MQTT broker!
[0d00h00m58s] 2024-08-31T16:27:41	<WRN>	[MQTT SERVER] Unable to send Static Topics, we are not connected to the MQTT broker!
[0d00h00m58s] 2024-08-31T16:27:41	<WRN>	[MQTT SERVER] One or more MQTT topics failed to be published, will try sending them in the next round!
[0d00h00m58s] 2024-08-31T16:27:41	<WRN>	[MQTT SERVER] Unable to send System Topics, we are not connected to the MQTT broker!
[0d00h00m58s] 2024-08-31T16:27:41	<WRN>	[MQTT] One or more MQTT topics failed to be published!
[0d00h00m58s] 2024-08-31T16:27:41	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h00m58s] 2024-08-31T16:27:41	<INF>	[MAINCTRL] Round #1 completed (41 seconds)
[0d00h00m58s] 2024-08-31T16:27:41	<DBG>	[MAINCTRL] CPU Temperature: 53Â°C
[0d00h00m58s] 2024-08-31T16:27:41	<DBG>	[MAINCTRL] WIFI Signal (RSSI): -70dBm
[0d00h01m02s] 2024-08-31T16:27:45	<ERR>	[MQTT IF] Other event id:
[0d00h01m02s] 2024-08-31T16:27:45	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h01m17s] 2024-08-31T16:28:00	<ERR>	[MQTT IF] Other event id:
[0d00h01m17s] 2024-08-31T16:28:00	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h01m17s] 2024-08-31T16:28:00	<ERR>	[MQTT IF] Disconnected, multiple reconnect attempts failed, still retrying...
[0d00h01m32s] 2024-08-31T16:28:15	<ERR>	[MQTT IF] Other event id:
[0d00h01m32s] 2024-08-31T16:28:15	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h01m47s] 2024-08-31T16:28:30	<ERR>	[MQTT IF] Other event id:
[0d00h01m48s] 2024-08-31T16:28:30	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h02m03s] 2024-08-31T16:28:45	<ERR>	[MQTT IF] Other event id:
[0d00h02m03s] 2024-08-31T16:28:46	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h02m18s] 2024-08-31T16:29:01	<ERR>	[MQTT IF] Other event id:
[0d00h02m18s] 2024-08-31T16:29:01	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h02m33s] 2024-08-31T16:29:16	<ERR>	[MQTT IF] Other event id:
[0d00h02m33s] 2024-08-31T16:29:16	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h02m33s] 2024-08-31T16:29:16	<ERR>	[MQTT IF] Disconnected, multiple reconnect attempts failed, still retrying...
[0d00h02m48s] 2024-08-31T16:29:31	<ERR>	[MQTT IF] Other event id:
[0d00h02m48s] 2024-08-31T16:29:31	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h03m03s] 2024-08-31T16:29:46	<ERR>	[MQTT IF] Other event id:
[0d00h03m03s] 2024-08-31T16:29:46	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h03m18s] 2024-08-31T16:30:01	<ERR>	[MQTT IF] Other event id:
[0d00h03m18s] 2024-08-31T16:30:01	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h03m33s] 2024-08-31T16:30:16	<ERR>	[MQTT IF] Other event id:
[0d00h03m33s] 2024-08-31T16:30:16	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h03m48s] 2024-08-31T16:30:31	<ERR>	[MQTT IF] Other event id:
[0d00h03m48s] 2024-08-31T16:30:31	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h03m48s] 2024-08-31T16:30:31	<ERR>	[MQTT IF] Disconnected, multiple reconnect attempts failed, still retrying...
[0d00h04m03s] 2024-08-31T16:30:46	<ERR>	[MQTT IF] Other event id:
[0d00h04m03s] 2024-08-31T16:30:46	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h04m18s] 2024-08-31T16:31:01	<ERR>	[MQTT IF] Other event id:
[0d00h04m18s] 2024-08-31T16:31:01	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h04m34s] 2024-08-31T16:31:16	<ERR>	[MQTT IF] Other event id:
[0d00h04m34s] 2024-08-31T16:31:16	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h04m49s] 2024-08-31T16:31:32	<ERR>	[MQTT IF] Other event id:
[0d00h04m49s] 2024-08-31T16:31:32	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h05m04s] 2024-08-31T16:31:47	<ERR>	[MQTT IF] Other event id:
[0d00h05m04s] 2024-08-31T16:31:47	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h05m04s] 2024-08-31T16:31:47	<ERR>	[MQTT IF] Disconnected, multiple reconnect attempts failed, still retrying...
[0d00h05m17s] 2024-08-31T16:32:00	<DBG>	[MAINCTRL] ----------------------------------------------------------------
[0d00h05m17s] 2024-08-31T16:32:00	<INF>	[MAINCTRL] Round #2 started
[0d00h05m17s] 2024-08-31T16:32:00	<DBG>	[FLOWCTRL] Status: Take Image (16:32:00)
[0d00h05m17s] 2024-08-31T16:32:00	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h05m17s] 2024-08-31T16:32:00	<DBG>	[PSRAM] Init shared memory for step 'Take Image' (STBI buffers)
[0d00h05m19s] 2024-08-31T16:32:02	<ERR>	[MQTT IF] Other event id:
[0d00h05m19s] 2024-08-31T16:32:02	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocating memory (307215 bytes) for STBI (use shared memory in PSRAM)...
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocating memory (153615 bytes) for STBI (use shared memory in PSRAM)...
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocating memory (153615 bytes) for STBI (use shared memory in PSRAM)...
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocated 643 bytes in PSRAM for 'STBI'
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocated 643 bytes in PSRAM for 'STBI'
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocated 643 bytes in PSRAM for 'STBI'
[0d00h05m24s] 2024-08-31T16:32:07	<DBG>	[PSRAM] Allocating memory (921601 bytes) for STBI (use shared memory in PSRAM)...
[0d00h05m25s] 2024-08-31T16:32:08	<DBG>	[PSRAM] Part of shared memory used for STBI (PSRAM, part of shared memory) is free again
[0d00h05m25s] 2024-08-31T16:32:08	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m25s] 2024-08-31T16:32:08	<DBG>	[PSRAM] Part of shared memory used for STBI (PSRAM, part of shared memory) is free again
[0d00h05m25s] 2024-08-31T16:32:08	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m25s] 2024-08-31T16:32:08	<DBG>	[PSRAM] Part of shared memory used for STBI (PSRAM, part of shared memory) is free again
[0d00h05m25s] 2024-08-31T16:32:08	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m25s] 2024-08-31T16:32:08	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m27s] 2024-08-31T16:32:10	<DBG>	[C IMG BASIS] Not freeing (zwImage as there was never PSRAM allocated for it)
[0d00h05m27s] 2024-08-31T16:32:10	<DBG>	[PSRAM] Deinit shared memory for step 'Take Image' (STBI buffers)
[0d00h05m27s] 2024-08-31T16:32:10	<DBG>	[FLOWCTRL] Status: Aligning (16:32:10)
[0d00h05m27s] 2024-08-31T16:32:10	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h05m28s] 2024-08-31T16:32:11	<DBG>	[PSRAM] Allocating tmpImage (921600 bytes, use shared memory in PSRAM)...
[0d00h05m30s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h05m30s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m30s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h05m30s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Allocated 1551 bytes in PSRAM for 'STBI'
[0d00h05m30s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Allocated 399 bytes in PSRAM for 'STBI'
[0d00h05m30s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Allocated 399 bytes in PSRAM for 'STBI'
[0d00h05m31s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Allocated 39 bytes in PSRAM for 'STBI'
[0d00h05m31s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Allocated 39 bytes in PSRAM for 'STBI'
[0d00h05m31s] 2024-08-31T16:32:13	<DBG>	[PSRAM] Allocated 39 bytes in PSRAM for 'STBI'
[0d00h05m31s] 2024-08-31T16:32:14	<DBG>	[PSRAM] Allocated 2485 bytes in PSRAM for 'STBI'
[0d00h05m31s] 2024-08-31T16:32:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m31s] 2024-08-31T16:32:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m31s] 2024-08-31T16:32:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m31s] 2024-08-31T16:32:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m31s] 2024-08-31T16:32:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m31s] 2024-08-31T16:32:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m31s] 2024-08-31T16:32:14	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 18456 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 2319 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 591 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 591 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 44 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 44 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 44 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Allocated 4306 bytes in PSRAM for 'STBI'
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m33s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m34s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m34s] 2024-08-31T16:32:16	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m34s] 2024-08-31T16:32:17	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m34s] 2024-08-31T16:32:17	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m34s] 2024-08-31T16:32:17	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m34s] 2024-08-31T16:32:17	<ERR>	[MQTT IF] Other event id:
[0d00h05m34s] 2024-08-31T16:32:17	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h05m38s] 2024-08-31T16:32:21	<DBG>	[PSRAM] Freeing memory in PSRAM used for 'STBI'...
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[PSRAM] Shared memory used for tmpImage (PSRAM, part of shared memory) is free again
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[FLOWCTRL] Status: Digitalization of ROIs (16:32:27)
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[CNN] doFlow after alignment
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[PSRAM] Allocating Tensor Arena (819200 bytes, use shared memory in PSRAM)...
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[TFLITE] CTfLiteClass::LoadModel
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[TFLITE] CTfLiteClass::ReadFileToModel: /sdcard/config/dig-cont_0620_s3_q.tflite
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[TFLITE] Loading Model /sdcard/config/dig-cont_0620_s3_q.tflite /size: 315504 bytes...
[0d00h05m44s] 2024-08-31T16:32:27	<DBG>	[PSRAM] Allocating Model memory (1363148 bytes, use shared memory in PSRAM)...
[0d00h05m45s] 2024-08-31T16:32:28	<DBG>	[TFLITE] CTfLiteClass::MakeAllocate
[0d00h05m45s] 2024-08-31T16:32:28	<DBG>	[CNN] Processing Number 'main'
[0d00h05m45s] 2024-08-31T16:32:28	<DBG>	[CNN] ROI #0 - TfLite
[0d00h05m45s] 2024-08-31T16:32:28	<DBG>	[CNN] CNN Type: DoubleHyprid10
[0d00h05m48s] 2024-08-31T16:32:31	<DBG>	[CNN] After Invoke
[0d00h05m48s] 2024-08-31T16:32:31	<DBG>	[CNN] _num (p, m): 2 3 1 _val (p, m): 0.992188 0.007812 0.000000 result: 2.007812 _fit: 1.000000
[0d00h05m48s] 2024-08-31T16:32:31	<DBG>	[CNN] ROI #1 - TfLite
[0d00h05m48s] 2024-08-31T16:32:31	<DBG>	[CNN] CNN Type: DoubleHyprid10
[0d00h05m49s] 2024-08-31T16:32:32	<ERR>	[MQTT IF] Other event id:
[0d00h05m49s] 2024-08-31T16:32:32	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h05m50s] 2024-08-31T16:32:33	<DBG>	[CNN] After Invoke
[0d00h05m50s] 2024-08-31T16:32:33	<DBG>	[CNN] _num (p, m): 4 5 3 _val (p, m): 0.996094 0.000000 0.000000 result: 4.000000 _fit: 0.996094
[0d00h05m51s] 2024-08-31T16:32:33	<DBG>	[CNN] ROI #2 - TfLite
[0d00h05m51s] 2024-08-31T16:32:33	<DBG>	[CNN] CNN Type: DoubleHyprid10
[0d00h05m53s] 2024-08-31T16:32:36	<DBG>	[CNN] After Invoke
[0d00h05m53s] 2024-08-31T16:32:36	<DBG>	[CNN] _num (p, m): 7 8 6 _val (p, m): 0.996094 0.000000 0.000000 result: 7.000000 _fit: 0.996094
[0d00h05m53s] 2024-08-31T16:32:36	<DBG>	[PSRAM] Shared memory used for Tensor Arena and model (PSRAM, part of shared memory) is free again
[0d00h05m53s] 2024-08-31T16:32:36	<DBG>	[FLOWCTRL] Status: Digitalization of ROIs (16:32:36)
[0d00h05m53s] 2024-08-31T16:32:36	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h05m54s] 2024-08-31T16:32:36	<DBG>	[CNN] doFlow after alignment
[0d00h05m54s] 2024-08-31T16:32:36	<DBG>	[PSRAM] Allocating Tensor Arena (819200 bytes, use shared memory in PSRAM)...
[0d00h05m54s] 2024-08-31T16:32:37	<DBG>	[TFLITE] CTfLiteClass::LoadModel
[0d00h05m54s] 2024-08-31T16:32:37	<DBG>	[TFLITE] CTfLiteClass::ReadFileToModel: /sdcard/config/ana-cont_1208_s2_q.tflite
[0d00h05m54s] 2024-08-31T16:32:37	<DBG>	[TFLITE] Loading Model /sdcard/config/ana-cont_1208_s2_q.tflite /size: 47232 bytes...
[0d00h05m54s] 2024-08-31T16:32:37	<DBG>	[PSRAM] Allocating Model memory (1363148 bytes, use shared memory in PSRAM)...
[0d00h05m54s] 2024-08-31T16:32:37	<DBG>	[TFLITE] CTfLiteClass::MakeAllocate
[0d00h05m54s] 2024-08-31T16:32:37	<DBG>	[CNN] Processing Number 'main'
[0d00h05m54s] 2024-08-31T16:32:37	<DBG>	[CNN] ROI #0 - TfLite
[0d00h05m54s] 2024-08-31T16:32:37	<DBG>	[CNN] CNN Type: Analogue
[0d00h05m55s] 2024-08-31T16:32:37	<DBG>	[CNN] After Invoke
[0d00h05m55s] 2024-08-31T16:32:38	<DBG>	[CNN] ROI #1 - TfLite
[0d00h05m55s] 2024-08-31T16:32:38	<DBG>	[CNN] CNN Type: Analogue
[0d00h05m55s] 2024-08-31T16:32:38	<DBG>	[CNN] After Invoke
[0d00h05m55s] 2024-08-31T16:32:38	<DBG>	[CNN] ROI #2 - TfLite
[0d00h05m55s] 2024-08-31T16:32:38	<DBG>	[CNN] CNN Type: Analogue
[0d00h05m56s] 2024-08-31T16:32:39	<DBG>	[CNN] After Invoke
[0d00h05m56s] 2024-08-31T16:32:39	<DBG>	[CNN] ROI #3 - TfLite
[0d00h05m56s] 2024-08-31T16:32:39	<DBG>	[CNN] CNN Type: Analogue
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] After Invoke
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[PSRAM] Shared memory used for Tensor Arena and model (PSRAM, part of shared memory) is free again
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[FLOWCTRL] Status: Post-Processing (16:32:40)
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] getReadout _analog=0, _extendedResolution=0, prev=-1
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] PointerEvalAnalogNew - No predecessor - Result = 6 number: 6.402930 numeral_preceder = -1 Analog_error = 3
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] PointerEvalAnalogNew - number unambiguous, no correction necessary - result = 0 number: 0.620240 numeral_preceder = 6 Analog_error = 3
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] PointerEvalAnalogNew - number ambiguous, correction upwards - result = 6 number: 5.873668 numeral_preceder = 0 Analog_error = 3
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] PointerEvalAnalogNew - number unambiguous, no correction necessary - result = 1 number: 1.475836 numeral_preceder = 6 Analog_error = 3
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] getReadout _analog=0, _extendedResolution=0, prev=1
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] PointerEvalAnalogToDigitNew - NO digital Uncertainty - Result = 7 number: 7.000000 numeral_preceder = 1.475836
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] PointerEvalHybridNew - Analog predecessor, evaluation over PointerEvalAnalogNew = 7 number: 7.000000 number_of_predecessors = 1.475836 eval_predecessors = 1 Digital_Uncertainty = 0.200000
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] getReadout(dig100)  prev=7
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] PointerEvalHybridNew - NO analogue predecessor, no change of digits, as pre-decimal point far enough away = 4 number: 4.000000 number_of_predecessors = 7.000000 eval_predecessors = 7 Digital_Uncertainty = 0.200000
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] getReadout#PointerEvalHybridNew()= 4
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] getReadout#result= 47
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] PointerEvalHybridNew - NO analogue predecessor, no change of digits, as pre-decimal point far enough away = 2 number: 2.007812 number_of_predecessors = 4.000000 eval_predecessors = 4 Digital_Uncertainty = 0.200000
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] getReadout#PointerEvalHybridNew()= 2
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[CNN] getReadout#result= 247
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[POSTPROC] handleAllowNegativeRate for device: main
[0d00h05m57s] 2024-08-31T16:32:40	<INF>	[POSTPROC] main: Raw: 247.1606, Value: 247.1606, Status: no error
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[FLOWCTRL] Status: Sending MQTT (16:32:40)
[0d00h05m57s] 2024-08-31T16:32:40	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h05m57s] 2024-08-31T16:32:40	<WRN>	[MQTT SERVER] Unable to send Homeassistant Discovery Topics, we are not connected to the MQTT broker!
[0d00h05m58s] 2024-08-31T16:32:40	<WRN>	[MQTT SERVER] Unable to send Static Topics, we are not connected to the MQTT broker!
[0d00h05m58s] 2024-08-31T16:32:40	<WRN>	[MQTT SERVER] One or more MQTT topics failed to be published, will try sending them in the next round!
[0d00h05m58s] 2024-08-31T16:32:40	<WRN>	[MQTT SERVER] Unable to send System Topics, we are not connected to the MQTT broker!
[0d00h05m58s] 2024-08-31T16:32:41	<WRN>	[MQTT] One or more MQTT topics failed to be published!
[0d00h05m58s] 2024-08-31T16:32:41	<DBG>	[MQTT IF] Publish skipped. Client not initalized or not connected. (topic: watermeter/status)
[0d00h05m58s] 2024-08-31T16:32:41	<INF>	[MAINCTRL] Round #2 completed (41 seconds)
[0d00h05m58s] 2024-08-31T16:32:41	<DBG>	[MAINCTRL] CPU Temperature: 53Â°C
[0d00h05m58s] 2024-08-31T16:32:41	<DBG>	[MAINCTRL] WIFI Signal (RSSI): -70dBm
[0d00h06m04s] 2024-08-31T16:32:47	<ERR>	[MQTT IF] Other event id:
[0d00h06m04s] 2024-08-31T16:32:47	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h06m19s] 2024-08-31T16:33:02	<ERR>	[MQTT IF] Other event id:
[0d00h06m19s] 2024-08-31T16:33:02	<WRN>	[MQTT IF] Disconnected, trying to reconnect
[0d00h06m19s] 2024-08-31T16:33:02	<ERR>	[MQTT IF] Disconnected, multiple reconnect attempts failed, still retrying...

Expected Behavior

No response

Screenshots

No response

Additional Context

No response

The text was updated successfully, but these errors were encountered:

SybexX · 2024-08-31T15:07:46Z

#3053

schlamar · 2024-08-31T16:13:35Z

So you should remove these parts from configuration / documentation.

caco3 · 2024-09-01T06:38:35Z

According to #2625 (comment) it should work.
How ever there seems to be a restriction: #3054 (comment)

Can you test if it works with TLS 1.2?

schlamar · 2024-09-01T15:47:04Z

My server (I use traefik as TLS proxy to Mosquitto) supports TLS 1.2 and to be sure I just verified it with a modified Python example.

Possible other causes I want to check:

key size not supported (tasmota requires special config to support rsa keys with 4096 length)
ciphersuite not supported

schlamar · 2024-09-01T16:35:54Z

OK I checked the behavior of the client with a simple TCP/IP honeypot server. The client doesn't send any data at all and just terminates the connection. Which means it doesn't even try to start TLS negotiation.

Could it be that certificate in PEM format is not supported and you have to provide DER format? ESP32 documentation says

For secure connections with TLS used, and to guarantee Broker's identity, the verification struct must be set. The broker certificate may be set in PEM or DER format. To select DER, the equivalent certificate_len field must be set. Otherwise, a null-terminated string in PEM format should be provided to certificate field.

caco3 · 2024-09-01T18:56:05Z

@LordGuilly Can you provide some documentation how you generated your certificate? This seems not to be clear.

I looked at https://tasmota.github.io/docs/TLS/#implementation-notes but there is a lot of information and not all seems to apply to our ESP32.

LordGuilly · 2024-09-02T20:53:25Z

when I added this, I used mutual TLS, so used both server and client certs, connecting to AWS. I don't remember doing any strange formatting for the certs, so I guess the standard Amazon root CA should be a reference for the file format (https://docs.aws.amazon.com/iot/latest/developerguide/server-authentication.html and looks like PEM is ok).
I don't have the device online anymore (moved to the dark side of smart meters), but I am sure I still have the device with the SD card somewhere in a box, so let me try to find it, I vaguely remember having issues with the length, so maybe extra new lines or spaces could mess up things

schlamar added the bug Something isn't working label Aug 31, 2024

caco3 mentioned this issue Sep 1, 2024

added note about only TLS 1.2 is supported #3213

Merged

1 task

caco3 closed this as completed Sep 30, 2024

SybexX mentioned this issue Dec 7, 2024

MQTT-Bug with CA-Certificate #3425

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

MQTT with TLS not working #3211

MQTT with TLS not working #3211

schlamar commented Aug 31, 2024

SybexX commented Aug 31, 2024

schlamar commented Aug 31, 2024

caco3 commented Sep 1, 2024

schlamar commented Sep 1, 2024

schlamar commented Sep 1, 2024

caco3 commented Sep 1, 2024

LordGuilly commented Sep 2, 2024

MQTT with TLS not working #3211

MQTT with TLS not working #3211

Comments

schlamar commented Aug 31, 2024

The Problem

Version

Logfile

Expected Behavior

Screenshots

Additional Context

SybexX commented Aug 31, 2024

schlamar commented Aug 31, 2024

caco3 commented Sep 1, 2024

schlamar commented Sep 1, 2024

schlamar commented Sep 1, 2024

caco3 commented Sep 1, 2024

LordGuilly commented Sep 2, 2024