Svedrin / mqtt-pushgateway

Prometheus Exporter for metrics received via MQTT
15 stars 10 forks source link

Exception in thread Thread-1: on Raspbian with Python 3.9.2 #9

Closed mircsicz closed 1 year ago

mircsicz commented 1 year ago

Hi hi,

I'm trying to push some metrics from Tasmota, Sonoff and M-Bus into my Prometheus but get the following error and don't see (except for mqtt_data_age) any metrics on the interface:

mqtt_data_age{mqtt_topic="tele/AMR/AMR-WASHER/LWT",metric="LWT"} 9.978492
LWT{mqtt_topic="tele/AMR/AMR-WASHER/LWT",LWT="Online"} 1.000000
mqtt_data_age{mqtt_topic="tele/AMR/AMR-OVAG/LWT",metric="LWT"} 9.978426
LWT{mqtt_topic="tele/AMR/AMR-OVAG/LWT",LWT="Online"} 1.000000
mircsicz@pi8:/opt/mqtt-pushgateway $ sudo ./mqtt_pushgateway.py 
 * Serving Flask app "mqtt_pushgateway" (lazy loading)
 * Environment: production
   WARNING: This is a development server. Do not use it in a production deployment.
   Use a production WSGI server instead.
 * Debug mode: off
INFO:werkzeug: * Running on http://10.10.xx0.8:9665/ (Press CTRL+C to quit)
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.9/threading.py", line 892, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 3452, in _thread_main
    self.loop_forever(retry_first_connection=True)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 1779, in loop_forever
    rc = self.loop(timeout, max_packets)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 1181, in loop
    rc = self.loop_read(max_packets)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 1572, in loop_read
    rc = self._packet_read()
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 2310, in _packet_read
    rc = self._packet_handle()
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 2936, in _packet_handle
    return self._handle_publish()
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 3216, in _handle_publish
    self._handle_on_message(message)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 3444, in _handle_on_message
    self.on_message(self, self._userdata, message)
  File "/opt/mqtt-pushgateway/./mqtt_pushgateway.py", line 182, in on_message
    metrics[key_topic].update(key_topic, val)
  File "/opt/mqtt-pushgateway/./mqtt_pushgateway.py", line 81, in update
    elif (parsed_value := _try_date(value)) is not None:
  File "/opt/mqtt-pushgateway/./mqtt_pushgateway.py", line 71, in _try_date
    if not re.match(r'^\d\d\d\d\-\d\d\-\d\d([T ]\d\d:\d\d:\d\d.*)?', value):
  File "/usr/lib/python3.9/re.py", line 191, in match
    return _compile(pattern, flags).match(string)
TypeError: expected string or bytes-like object
INFO:werkzeug:10.10.xy0.201 - - [01/Aug/2023 03:59:08] "GET /metrics HTTP/1.1" 200 -

Hoping for a hint

Svedrin commented 1 year ago

@mircsicz the error is interesting:

TypeError: expected string or bytes-like object

I'm not sure what value could cause this 🤔 lemme add some logging so we can see what it chokes on.

Svedrin commented 1 year ago

@mircsicz there we go - could you please update to latest and see if it logs an error Failed to match "<something>" against a regex? Once we know what the value is, we can decide on how to handle it. :slightly_smiling_face:

mircsicz commented 1 year ago

Thx for the help:

WARNING:root:Failed to match "None" against a regex

Here's my full output after the git pull:

mircsicz@pi8:/opt/mqtt-pushgateway $ sudo ./mqtt_pushgateway.py 
 * Serving Flask app "mqtt_pushgateway" (lazy loading)
 * Environment: production
   WARNING: This is a development server. Do not use it in a production deployment.
   Use a production WSGI server instead.
 * Debug mode: off
WARNING:root:Failed to match "None" against a regex
Traceback (most recent call last):
  File "/opt/mqtt-pushgateway/./mqtt_pushgateway.py", line 72, in _try_date
    if not re.match(r'^\d\d\d\d\-\d\d\-\d\d([T ]\d\d:\d\d:\d\d.*)?', value):
  File "/usr/lib/python3.9/re.py", line 191, in match
    return _compile(pattern, flags).match(string)
TypeError: expected string or bytes-like object
Exception in thread Thread-1:
INFO:werkzeug: * Running on http://10.10.xx0.8:9665/ (Press CTRL+C to quit)
Traceback (most recent call last):
  File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.9/threading.py", line 892, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 3452, in _thread_main
    self.loop_forever(retry_first_connection=True)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 1779, in loop_forever
    rc = self.loop(timeout, max_packets)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 1181, in loop
    rc = self.loop_read(max_packets)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 1572, in loop_read
    rc = self._packet_read()
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 2310, in _packet_read
    rc = self._packet_handle()
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 2936, in _packet_handle
    return self._handle_publish()
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 3216, in _handle_publish
    self._handle_on_message(message)
  File "/usr/lib/python3/dist-packages/paho/mqtt/client.py", line 3444, in _handle_on_message
    self.on_message(self, self._userdata, message)
  File "/opt/mqtt-pushgateway/./mqtt_pushgateway.py", line 187, in on_message
    metrics[key_topic].update(key_topic, val)
  File "/opt/mqtt-pushgateway/./mqtt_pushgateway.py", line 90, in update
    self.value = (value
AttributeError: 'NoneType' object has no attribute 'replace'
mircsicz commented 1 year ago

As none is so weird here's my config:

[exporter]
listen = "10.10.xx0.8"
port   = 9665

# Configure your MQTT broker's address and credentials here.
[mqtt]
client_id = "mqtt_pushgw-%(hostname)s"
broker    = "10.10.xx0.8"
port      = 1883
username  = "prometheus"
password  = "nottelling"

# List some keys we should subscribe to. Use '#' to subscribe to *everything*.
# We will ignore any messages that can't be directly parsed as floats.
subscribe = [
    'tele/AMR/#',
    'zigbee2mqtt/#'
#    'homeassistant/sensor/#'
]

# Expire metrics after 5 Minutes. Can be overridden in the [[topic]] sections.
# Comment to disable.
expire = 300

[[topic]]
match = 'zigbee2mqtt/#'

[[topic]]
#match = 'Temp_*/(?P<sensor_name>\w+)/(?P<__metric__>\w+)'
match = 'tele/AMR/(?P<sensor_name>\w+)/(?P<__metric__>\w+)'

And some json from the topics:

  1. tele/AMR/AMR-WASHER/SENSOR (Tasmota Gosund SP112) {"Time":"2023-08-01T10:18:15","ENERGY":{"TotalStartTime":"2023-07-13T12:07:17","Total":17.189,"Yesterday":0.805,"Today":0.329,"Period":0,"Power":0,"ApparentPower":0,"ReactivePower":0,"Factor":0.00,"Voltage":221,"Current":0.000}}
  2. tele/AMR/mbus/12 (M-Bus Utility Meter read by libmbus) { "MBusData": { "SlaveInformation": { "Id": "30101282", "Manufacturer": "NZR", "Version": "1", "ProductName": "NZR DHZ 5/63", "Medium": "Electricity", "AccessNumber": "166", "Status": "00", "Signature": "0000" }, "DataRecord": [ { "_id": "0", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Energy (Wh)", "Value": "1385406", "Timestamp": "2023-08-01T09:20:02Z" }, { "_id": "1", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Energy (Wh)", "Value": "1385406", "Timestamp": "2023-08-01T09:20:02Z" }, { "_id": "2", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "1e-1 V", "Value": "2306", "Timestamp": "2023-08-01T09:20:02Z" }, { "_id": "3", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "1e-1 A", "Value": "0", "Timestamp": "2023-08-01T09:20:02Z" }, { "_id": "4", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Power (W)", "Value": "0", "Timestamp": "2023-08-01T09:20:02Z" }, { "_id": "5", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Fabrication number", "Value": "30101282", "Timestamp": "2023-08-01T09:20:02Z" }, { "_id": "6", "Function": "Manufacturer specific", "Value": "D5", "Timestamp": "2023-08-01T09:20:02Z" } ] } }
  3. tele/AMR/mbus/14 (M-Bus Utility Meter read by libmbus) { "MBusData": { "SlaveInformation": { "Id": "90003AF", "Manufacturer": "SBC", "Version": "18", "ProductName": null, "Medium": "Electricity", "AccessNumber": "160", "Status": "00", "Signature": "0000" }, "DataRecord": [ { "_id": "0", "Function": "Instantaneous value", "StorageNumber": "0", "Tariff": "1", "Device": "0", "Unit": "Energy (100 Wh)", "Value": "37473", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "1", "Function": "Instantaneous value", "StorageNumber": "2", "Tariff": "1", "Device": "0", "Unit": "Energy (100 Wh)", "Value": "37436", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "2", "Function": "Instantaneous value", "StorageNumber": "0", "Tariff": "2", "Device": "0", "Unit": "Energy (100 Wh)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "3", "Function": "Instantaneous value", "StorageNumber": "2", "Tariff": "2", "Device": "0", "Unit": "Energy (100 Wh)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "4", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "V", "Value": "229", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "5", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "1e-1 A", "Value": "2", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "6", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Power (100 W)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "7", "Function": "Instantaneous value", "StorageNumber": "0", "Tariff": "0", "Device": "1", "Unit": "Power (100 W)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "8", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "V", "Value": "230", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "9", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "1e-1 A", "Value": "4", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "10", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Power (100 W)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "11", "Function": "Instantaneous value", "StorageNumber": "0", "Tariff": "0", "Device": "1", "Unit": "Power (100 W)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "12", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "V", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "13", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "1e-1 A", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "14", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Power (100 W)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "15", "Function": "Instantaneous value", "StorageNumber": "0", "Tariff": "0", "Device": "1", "Unit": "Power (100 W)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "16", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Manufacturer specific", "Value": "1", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "17", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Power (100 W)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "18", "Function": "Instantaneous value", "StorageNumber": "0", "Tariff": "0", "Device": "1", "Unit": "Power (100 W)", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" }, { "_id": "19", "Function": "Instantaneous value", "StorageNumber": "0", "Unit": "Manufacturer specific", "Value": "0", "Timestamp": "2023-08-01T09:20:03Z" } ] } }
  4. zigbee2mqtt/Temp_STH (sonoff SNZB-02) {"battery":100,"humidity":62.42,"linkquality":15,"temperature":21.66,"voltage":3100}
Svedrin commented 1 year ago

@mircsicz there's probably a null in the json somewhere. I've added a check to ignore those (I think that's the nost sensible thing to do). Please give it a try 🙂

mircsicz commented 1 year ago

Awesome, let me add an ignore rule for the zigbee2mqtt/bridge topic and see which stuff with relevance shows up...

So now that I told it to ignore the zigbee2mqtt/bridge topic I see stuff like this:

mqtt_data_age{mqtt_topic="tele/AMR/AMR-SERVER/LWT",metric="LWT"} 4.722667

LWT{mqtt_topic="tele/AMR/AMR-SERVER/LWT",LWT="Online"} 1.000000

mqtt_data_age{mqtt_topic="tele/AMR/AMR-OVAG/LWT",metric="LWT"} 4.722275

LWT{mqtt_topic="tele/AMR/AMR-OVAG/LWT",LWT="Online"} 1.000000

mqtt_data_age{mqtt_topic="zigbee2mqtt/Temp_Bad-EG/availability/state",metric="state"} 4.686952

state{mqtt_topic="zigbee2mqtt/Temp_Bad-EG/availability/state",state="online"} 1.000000

mqtt_data_age{mqtt_topic="zigbee2mqtt/Temp_Wohnzimmer/availability/state",metric="state"} 4.686687

state{mqtt_topic="zigbee2mqtt/Temp_Wohnzimmer/availability/state",state="online"} 1.000000

But it doesn't seem to get my relevant values... How can I debug this?

mircsicz commented 1 year ago

I now see the relevant topics are being read:

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/_id",metric="14"} 970.618888

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Function",metric="14"} 970.618937

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/StorageNumber",metric="14"} 970.619000

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Tariff",metric="14"} 970.619065

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Device",metric="14"} 970.619132

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Unit",metric="14"} 970.619184

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Value",metric="14"} 970.619250

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Timestamp",metric="14"} 970.618743
mqtt_data_age{mqtt_topic="tele/AMR/AMR-OVAG/SENSOR//Power_curr",metric="Power_curr"} 893.405043

mqtt_data_age{mqtt_topic="tele/AMR/AMR-OVAG/SENSOR//total_in",metric="total_in"} 893.405086

But I can't see any of the value's / metrics from those... :-(

Svedrin commented 1 year ago

@mircsicz hmm, I just looked more closely at the JSON structure, and it appears the values are always strings:

"Value": "37473"

This is bad because the pushgateway handles strings different from numbers. In the example from the Readme, voltage is a number while status is a string:

https://github.com/Svedrin/mqtt-pushgateway/blob/9c8bcb56c1155f20c2f5f86ade134505ad573a70/README.md?plain=1#L47

Thus, voltage gets exported like you'd expect it to, but the status value gets converted into a label and exported with a value of 1.0:

https://github.com/Svedrin/mqtt-pushgateway/blob/9c8bcb56c1155f20c2f5f86ade134505ad573a70/README.md?plain=1#L55-L56

Do you have any way to modify the source so it sends numbers as numbers and not as strings? If it's an embedded device, probably not, right?

Svedrin commented 1 year ago

Actually scratch that, pushgateway tries to coerce everything to a float, regardless of which type it comes in as:

https://github.com/Svedrin/mqtt-pushgateway/blob/9c8bcb56c1155f20c2f5f86ade134505ad573a70/mqtt_pushgateway.py#L83-L85

not sure why your metrics don't show up then 🤔

Svedrin commented 1 year ago

@mircsicz I just noticed that all of your mqtt_data_age values here are larger than the default expiry timer:

mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/_id",metric="14"} 970.618888
mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Function",metric="14"} 970.618937
mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/StorageNumber",metric="14"} 970.619000
mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Tariff",metric="14"} 970.619065
mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Device",metric="14"} 970.619132
mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Unit",metric="14"} 970.619184
mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Value",metric="14"} 970.619250
mqtt_data_age{sensor_name="mbus",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Timestamp",metric="14"} 970.618743
mqtt_data_age{mqtt_topic="tele/AMR/AMR-OVAG/SENSOR//Power_curr",metric="Power_curr"} 893.405043
mqtt_data_age{mqtt_topic="tele/AMR/AMR-OVAG/SENSOR//total_in",metric="total_in"} 893.405086

The default expiry is 300 seconds:

https://github.com/Svedrin/mqtt-pushgateway/blob/9c8bcb56c1155f20c2f5f86ade134505ad573a70/config.example.toml#L24

If your sensors send data in longer intervals, try raising the expiry timeout to something like 1800 or 3600. pushgateway will then export the last value it received for longer.

mircsicz commented 1 year ago

It seems I was just not patient enough... :-(

The default expiry is 300 seconds:

https://github.com/Svedrin/mqtt-pushgateway/blob/9c8bcb56c1155f20c2f5f86ade134505ad573a70/config.example.toml#L24

If your sensors send data in longer intervals, try raising the expiry timeout to something like 1800 or 3600. pushgateway will then export the last value it received for longer.

But for the M-Bus Data they come in quite scrambled: `` MBusData{sensor_name="14",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/_id"} 0.000000

MBusData{sensor_name="14",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Function",MBusData="Instantaneousvalue"} 1.000000 MBusData{sensor_name="14",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/StorageNumber"} 0.000000

MBusData{sensor_name="14",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Tariff"} 1.000000

MBusData{sensor_name="14",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Device"} 0.000000

MBusData{sensor_name="14",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Unit",MBusData="Energy(100Wh)"} 1.000000 MBusData{sensor_name="14",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Value"} 37481.000000

MBusData{sensor_name="14",mqtt_topic="tele/AMR/mbus/14/MBusData/DataRecord/0/Timestamp"} 1690895704.000000 `` And this is the json delivered by libmbus.

Whereas the data from the BitShake SmartMeterReader comes (as its Tasmota) as expected: ` Power_curr{mqtt_topic="tele/AMR/AMR-OVAG/SENSOR//Power_curr"} 938.000000

total_in{mqtt_topic="tele/AMR/AMR-OVAG/SENSOR//total_in"} 28160.860000 `

I managed to get my graphs from it anyways, thanks a ton for the project and your help ;-)

Bildschirmfoto 2023-08-01 um 16 55 26

mircsicz commented 1 year ago

If you wanna fix it anyways just let me know and I'll forward the mqtt for you for a while ;-)

Svedrin commented 1 year ago

@mircsicz I'm on the fence here tbh. The pushgateway doesn't really know anything about the semantics of what it's reading, so it can't distinguish metrics from metadata, and I think I'd like to keep it that way. The alternative would be implementing some kind of pattern matching or metric allow/blocklisting for JSON-based metrics, which sounds a lot more complex than what I'd like pushgateway to be.

Are you using Node-RED in your setup? Setting up a few nodes to read from the json topic, discard everything except for the value, then post that to another topic to be consumed by pushgateway should be pretty easy. Not sure if it's worth it though, Prometheus will probably handle the extra metrics just fine.

mircsicz commented 1 year ago

Thats fine with me, as I found a way to deal with the different structure in Grafana ;-)