spacemanspiff2007 / sml2mqtt

Sml to MQTT Bridge
GNU General Public License v3.0
25 stars 8 forks source link

Feedback rewrite #39

Closed spacemanspiff2007 closed 2 months ago

spacemanspiff2007 commented 3 months ago

I've spent the last couple of months completely rewriting sml2mqtt so that it can be extended more easily and customized much better. The way how values processed is completely configurable. It's possible to create virtual meters, e.g. to get the daily power consumption, min max of day and e.g. mean of an interval. With the new operations there are countless possibilities.

Obviously the configuration format has changed so this requires a new config file.

Installation

python3 -m pip install git+https://github.com/spacemanspiff2007/sml2mqtt.git@tibbr

Documentation

I would like to get some feedback to both the docs and sml2mqtt before publishing a new version on pypi. I'm pinging some people who were interested in the past - it would be really nice to get feedback.

@the78mole @MC68030 @MrFr33man123 @christiankratzer

@baiti There is now a weighted average available @aaronk6 stdout can now be used @hgkdd tls can be configured

MrFr33man123 commented 3 months ago

Good Morning,

now i have a few errors that i can share, its always the same.

[2024-04-02 03:28:07,302] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-02 03:35:37,233] [sml.192.168.178.134                                  ] ERROR    | Crc error: 56755 != 41806
[2024-04-02 03:35:37,234] [sml.192.168.178.134.status                           ] INFO     | CRC_ERROR
[2024-04-02 03:35:42,345] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-02 03:50:24,411] [sml.192.168.178.134                                  ] ERROR    | Crc error: 33783 != 27530
[2024-04-02 03:50:24,411] [sml.192.168.178.134.status                           ] INFO     | CRC_ERROR
[2024-04-02 03:50:29,553] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-02 03:50:44,655] [sml.192.168.178.134.status                           ] INFO     | MESSAGE_TIMEOUT
[2024-04-02 03:50:45,583] [sml.192.168.178.134                                  ] ERROR    |
[2024-04-02 03:50:45,583] [sml.192.168.178.134.status                           ] INFO     | ERROR
[2024-04-02 03:50:45,584] [sml.shutdown                                         ] INFO     | Shutting down ...
[2024-04-02 03:50:45,585] [sml.shutdown                                         ] DEBUG    | Starting shutdown
[2024-04-02 03:50:45,585] [sml.shutdown                                         ] DEBUG    | Stop devices
[2024-04-02 03:50:45,585] [sml.tasks                                            ] DEBUG    | Http Task 192.168.178.134 finished!
[2024-04-02 03:50:45,586] [sml.tasks                                            ] DEBUG    | Watchdog Task 192.168.178.134 finished!
[2024-04-02 03:50:45,586] [sml.shutdown                                         ] DEBUG    | Stop devices done!
[2024-04-02 03:50:45,586] [sml.shutdown                                         ] DEBUG    | Shutdown mqtt
[2024-04-02 03:50:45,587] [sml.mqtt                                             ] DEBUG    | Disconnecting
[2024-04-02 03:50:45,588] [sml.tasks                                            ] DEBUG    | MQTT Task finished!
[2024-04-02 03:50:45,588] [sml.shutdown                                         ] DEBUG    | Shutdown mqtt done!
[2024-04-02 03:50:45,588] [sml.shutdown                                         ] DEBUG    | Close http session
[2024-04-02 03:50:45,839] [sml.shutdown                                         ] DEBUG    | Close http session done!
[2024-04-02 03:50:45,840] [sml.shutdown                                         ] DEBUG    | Shutdown complete
[2024-04-02 03:50:45,840] [sml.tasks                                            ] DEBUG    | Shutdown Task finished!
[2024-04-02 03:50:45,840] [sml.tasks                                            ] DEBUG    | All tasks done

Does this help?

baiti commented 3 months ago

Documentation

I would like to get some feedback to both the docs and sml2mqtt before publishing a new version on pypi. I'm pinging some people who were interested in the past - it would be really nice to get feedback.

@baiti There is now a weighted average available @aaronk6 stdout can now be used @hgkdd tls can be configured

Since I have switched providers to Tibber I am currently no longer using sml2mqtt. Instead I use Tibber's Pulse together with the pulse2mqtt package. Once (if ever) I switch to a classic provider which requires me to do manual meter readings, I will switch back to sml2mqtt and provide feedback for the new functions then. Meanwhile, thank you very much for all the good work you put into sml2mqtt

spacemanspiff2007 commented 3 months ago

Does this help?

Thanks for your help. I'm not sure which version you are running as the error message is still missing. Could you update your installation and just start it again. It should say 3.0.DEV-3. Somehow there is still the error missing so it would be nice if you could try again with the latest version. Just run the installation command for the DEV branch again and restart your service. Then there should be a proper error message or there's still a bug 😕

Edit: @MrFr33man123 : DEV-4 has a small retry mechanism which will log with DEBUG if things don't work as expected. If you could try this version it would be great!

@baiti : sml2mqtt supports now reading from tibber meters and extensive value processing (e.g. to get the energy used today), max power draw from grid, max power feed in to grid, etc. . So maybe that's enough to try it again 😉

aaronk6 commented 3 months ago

Hi @spacemanspiff2007, great to see that support for logging to stdout was added! However, I moved my setup to an ESP32 running ESPHome, as I figured a Raspberry Pi (that I previously used with sml2mqtt) is overkill if its only job is reading a power meter. So I’m not able to provide feedback at this point, but I’ll definitely keep it in mind if I have a use case for sml2mqtt in the future again. Thanks for the great work!

spacemanspiff2007 commented 3 months ago

@MrFr33man123 About a week has passed and I'm full of anticipation to hear from you. Have you seen the issue again and has the small workaround already worked? If so could you provide the log snipped? Thanks!

MrFr33man123 commented 3 months ago

Oh man sorry! The log still looks like this:

[2024-04-07 17:17:00,469] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-07 17:20:25,310] [sml.192.168.178.134                                  ] ERROR    | Crc error: 36475 != 32017
[2024-04-07 17:20:25,311] [sml.192.168.178.134.status                           ] INFO     | CRC_ERROR
[2024-04-07 17:20:30,386] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-07 17:24:35,851] [sml.192.168.178.134                                  ] ERROR    | Crc error: 18966 != 17471
[2024-04-07 17:24:35,851] [sml.192.168.178.134.status                           ] INFO     | CRC_ERROR
[2024-04-07 17:24:40,962] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-07 17:32:01,103] [sml.192.168.178.134                                  ] ERROR    | Crc error: 829 != 21361
[2024-04-07 17:32:01,104] [sml.192.168.178.134.status                           ] INFO     | CRC_ERROR
[2024-04-07 17:32:06,205] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-07 17:40:01,722] [sml.192.168.178.134.status                           ] INFO     | MESSAGE_TIMEOUT
[2024-04-07 17:40:02,583] [sml.192.168.178.134                                  ] ERROR    |
[2024-04-07 17:40:02,584] [sml.192.168.178.134.status                           ] INFO     | ERROR
[2024-04-07 17:40:02,584] [sml.shutdown                                         ] INFO     | Shutting down ...
[2024-04-07 17:40:02,585] [sml.shutdown                                         ] DEBUG    | Starting shutdown
[2024-04-07 17:40:02,585] [sml.shutdown                                         ] DEBUG    | Stop devices
[2024-04-07 17:40:02,585] [sml.tasks                                            ] DEBUG    | Http Task 192.168.178.134 finished!
[2024-04-07 17:40:02,586] [sml.tasks                                            ] DEBUG    | Watchdog Task 192.168.178.134 finished!
[2024-04-07 17:40:02,586] [sml.shutdown                                         ] DEBUG    | Stop devices done!
[2024-04-07 17:40:02,587] [sml.shutdown                                         ] DEBUG    | Shutdown mqtt
[2024-04-07 17:40:02,587] [sml.mqtt                                             ] DEBUG    | Disconnecting
[2024-04-07 17:40:02,588] [sml.tasks                                            ] DEBUG    | MQTT Task finished!
[2024-04-07 17:40:02,588] [sml.shutdown                                         ] DEBUG    | Shutdown mqtt done!
[2024-04-07 17:40:02,589] [sml.shutdown                                         ] DEBUG    | Close http session
[2024-04-07 17:40:02,840] [sml.shutdown                                         ] DEBUG    | Close http session done!
[2024-04-07 17:40:02,840] [sml.shutdown                                         ] DEBUG    | Shutdown complete
[2024-04-07 17:40:02,840] [sml.tasks                                            ] DEBUG    | Shutdown Task finished!
[2024-04-07 17:40:02,840] [sml.tasks                                            ] DEBUG    | All tasks done
[2024-04-07 21:14:11,475] [sml                                                  ] INFO     | Starting V3.0.DEV-4
[2024-04-07 21:14:11,476] [asyncio                                              ] DEBUG    | Using selector: EpollSelector
[2024-04-07 21:14:11,478] [sml.mqtt                                             ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-07 21:14:11,490] [sml.mqtt                                             ] DEBUG    | Success!
[2024-04-07 21:14:11,721] [sml.http                                             ] DEBUG    | Requesting data from http://192.168.178.134/data.json?node_id=1
[2024-04-07 21:14:16,821] [sml.192.168.178.134                                  ] DEBUG    | Found obis id 0100600100ff in the sml frame
[2024-04-07 21:14:16,821] [sml.192.168.178.134                                  ] DEBUG    | Device found for 0a014546522102cef068
[2024-04-07 21:14:16,822] [sml.192.168.178.134                                  ] DEBUG    | Found NegativeOnEnergyMeterWorkaroundOperation - skip creating default filters
[2024-04-07 21:14:16,823] [sml.192.168.178.134                                  ] DEBUG    | Found NegativeOnEnergyMeterWorkaroundOperation - skip creating default filters
[2024-04-07 21:14:16,823] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100100700ff, creating default filters
[2024-04-07 21:14:16,824] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100200700ff, creating default filters
[2024-04-07 21:14:16,824] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100340700ff, creating default filters
[2024-04-07 21:14:16,824] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100480700ff, creating default filters
[2024-04-07 21:14:16,825] [sml.192.168.178.134                                  ] INFO     | No filters found for 01001f0700ff, creating default filters
[2024-04-07 21:14:16,825] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100330700ff, creating default filters
[2024-04-07 21:14:16,826] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100470700ff, creating default filters
[2024-04-07 21:14:16,826] [sml.192.168.178.134                                  ] INFO     | No filters found for 01000e0700ff, creating default filters
[2024-04-07 21:14:16,826] [sml.192.168.178.134                                  ] INFO     | No filters found for 010060320101, creating default filters
[2024-04-07 21:14:16,826] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100510701ff, creating default filters
[2024-04-07 21:14:16,827] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100510702ff, creating default filters
[2024-04-07 21:14:16,827] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100510704ff, creating default filters
[2024-04-07 21:14:16,827] [sml.192.168.178.134                                  ] INFO     | No filters found for 010051070fff, creating default filters
[2024-04-07 21:14:16,827] [sml.192.168.178.134                                  ] INFO     | No filters found for 010051071aff, creating default filters
[2024-04-07 21:14:16,827] [sml.192.168.178.134                                  ] INFO     | No filters found for 010000020000, creating default filters
[2024-04-07 21:14:16,828] [sml.192.168.178.134                                  ] INFO     | No filters found for 0100605a0201, creating default filters
[2024-04-07 21:14:16,828] [sml.192.168.178.134                                  ] INFO     | No filters found for 010061610000, creating default filters
[2024-04-07 21:14:16,828] [sml.192.168.178.134                                  ] INFO     | No filters found for 010060320104, creating default filters
[2024-04-07 21:14:16,828] [sml.192.168.178.134                                  ] INFO     | No filters found for 010060320404, creating default filters
[2024-04-07 21:14:16,831] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-07 21:14:27,048] [sml.192.168.178.134                                  ] ERROR    | Crc error: 7127 != 54258
[2024-04-07 21:14:27,048] [sml.192.168.178.134.status                           ] INFO     | CRC_ERROR
[2024-04-07 21:14:32,165] [sml.192.168.178.134.status                           ] INFO     | OK

In between there are successful mitigation's of errors like this one

[2024-04-06 01:36:23,137] [sml.192.168.178.134.status                           ] INFO     | OK
[2024-04-06 01:42:57,178] [sml.http                                             ] DEBUG    | Ignored 1/3 HttpStatusError: 404
[2024-04-06 02:01:13,795] [sml.192.168.178.134                                  ] ERROR    | Crc error: 54910 != 39192
[2024-04-06 02:01:13,796] [sml.192.168.178.134.status                           ] INFO     | CRC_ERROR
[2024-04-06 02:01:18,913] [sml.192.168.178.134.status                           ] INFO     | OK

So its seems to always happen after the Message Timeout message.

hope you had a great easter :)

spacemanspiff2007 commented 3 months ago

I was really hoping that the easter bunny has hidden a propper error message in your logs but as it turns out no luck. I just pushed DEV-5 which should finally be able to log the culprit. Could you try again please? Sorry that it's such a back and forth ... .

christiankratzer commented 3 months ago

Are guys stumbling upon corrupt sml via http from the tibber bridge. This is a thing I am seeing as well on a regular basis. I assume this is just a result of the simple implementation of the tibber bridge with not much possible to do around that. I have tons of sampels of corrupt sml that my tooling has captured that never happens when reading raw from the serial port.

spacemanspiff2007 commented 3 months ago

The CRC_ERROR is not the issue, there is some kind of exception that is not caught and I can't seem to catch it.

[2024-04-07 17:40:02,583] [sml.192.168.178.134                                  ] ERROR    |

I've modified DEV-5 so that the CRC_ERRORS only gets logged as DEBUG so that during normal operation they don't fill up the log file. I currently suspect it's some kind of value that is reported only sporadically or a value that's missing.

christiankratzer commented 3 months ago

I frequently see exceptions out of smllib in my code. Adding logging of raw sml when exceptions happen is what I have done for my tool.

MrFr33man123 commented 3 months ago

@spacemanspiff2007 started dev5 :) lets see if there is an error message.

spacemanspiff2007 commented 2 months ago

@christiankratzer : Interesting - is it because you solely use the shortcut to get the values? If so you can use this logic to make it more robust. If not please open a bug report so I can fix it smllib.

@MrFr33man123 Any news?

MrFr33man123 commented 2 months ago

No news, since i started it no crash. But I'am keeping an eye on it.

christiankratzer commented 2 months ago

@spacemanspiff2007

The higher my polling rate on my tool the more frequent I get errors like this

{
  "message": "Cannot decode SML data",
  "levelname": "WARNING",
  "name": "pulse2mqtt",
  "asctime": "2024-04-11 03:23:09,056",
  "sml": "1b1b1b1b01010101760504b080a9620062007265000001017601010501902ae30b0a014150410100f43f9a7262016501902ab001630d9e00760504b080aa6200620072650000070177010b0a014150410100f43f9a070100620affff7262016501902ab07577070100603201010101010104"
}

from following piece of code in pulse2mqtt.py

def decode_sml( config, smldata ):
    stream = SmlStreamReader()
    stream.add(smldata)

    try:
        sml_frame = stream.get_frame()
    except Exception as e:
        logger.warning(
            'Exception decoding SML data',
            extra={'sml': smldata.hex()}
            )
        return None, []

    if sml_frame is None:
        logger.warning(
            'Cannot decode SML data',
            extra={'sml': smldata.hex()}
            )
        return None, []

So it seems I am getting back a None value from SmlStreamReader when using stream.get_frame()

It seems I need to review my naive approach to using smllib.

I intentionally left the raw output above ungarbled in case you want to trey decoding it.

christiankratzer commented 2 months ago

@spacemanspiff2007 This here demostrates the issue I have

ck@iot:/opt/pulse2mqtt$ cat smltest.py
#!/usr/bin/env python3
# -*- coding: utf-8 -*-
# vim: set expandtab sw=4 ts=4:

from smllib import SmlStreamReader

sml = "1b1b1b1b01010101760504b080a9620062007265000001017601010501902ae30b0a014150410100f43f9a7262016501902ab001630d9e00760504b080aa6200620072650000070177010b0a014150410100f43f9a070100620affff7262016501902ab07577070100603201010101010104"

smldata = bytearray.fromhex(sml)

stream = SmlStreamReader()
stream.add(smldata)
sml_frame = stream.get_frame()

print(sml_frame)
ck@iot:/opt/pulse2mqtt$ venv/bin/python smltest.py
None
spacemanspiff2007 commented 2 months ago

So it seems I am getting back a None value from SmlStreamReaderwhen using stream.get_frame()

None is a valid return value e.g. in case only a partial frame has been received. You'll get None if it's not enough data, the parsed frame or an exception. See the docs

grafik

christiankratzer commented 2 months ago

ok so this being a partial frame confirms my suspicion that the tibber bridge does not properly guard it's buffer when doing http gets.

I never had this issue when consuming the raw stream from a serial port. Only seems to happen when reading from the bridge via http get.

Thanks for confirming.

spacemanspiff2007 commented 2 months ago

If you pick a poll value small enough (e.g. 0.1 secs) you'll get that from the serial port, too. It's just much less likely.

christiankratzer commented 2 months ago

Well I never "poll" the serial port. I read complete frames from it at the rate it sends.

christiankratzer commented 2 months ago

This is just a limitation people consuming via http from the tibber bridge need to be aware of

spacemanspiff2007 commented 2 months ago

This is just a limitation people consuming via http from the tibber bridge need to be aware of

It's a non-issue because sml2mqtt handles None correctly and the smllib docs indicate that it should be handled. My guess is that you looked at the docs once and then forgot about it because it worked most of the time.

christiankratzer commented 2 months ago

It is an issue for people who expect data from the tibber bridge at the desired rate. It is not an issue for smllib which is not at fault here. It is a bug in the tibber bridge.

MrFr33man123 commented 2 months ago

Good Morning,

not much more to see here ¯_(ツ)_/¯ class TimeoutError seems to throw the error.

[2024-04-14 13:33:26,536] [sml.192.168.178.134.status                           ] DEBUG    | OK
[2024-04-14 13:37:06,596] [sml.192.168.178.134                                  ] DEBUG    | Crc error: 16947 != 60684
[2024-04-14 13:37:06,596] [sml.192.168.178.134.status                           ] DEBUG    | CRC_ERROR
[2024-04-14 13:37:11,715] [sml.192.168.178.134.status                           ] DEBUG    | OK
[2024-04-14 13:45:43,173] [sml.192.168.178.134.status                           ] INFO     | MESSAGE_TIMEOUT
[2024-04-14 13:45:43,584] [sml.192.168.178.134                                  ] DEBUG    | Exception <class 'TimeoutError'>: ""
[2024-04-14 13:45:43,584] [sml.192.168.178.134                                  ] ERROR    | <class 'TimeoutError'>:
[2024-04-14 13:45:43,584] [sml.192.168.178.134.status                           ] INFO     | ERROR
[2024-04-14 13:45:43,585] [sml.shutdown                                         ] INFO     | Shutting down ...
[2024-04-14 13:45:43,586] [sml.shutdown                                         ] DEBUG    | Starting shutdown
[2024-04-14 13:45:43,586] [sml.shutdown                                         ] DEBUG    | Stop devices
[2024-04-14 13:45:43,587] [sml.tasks                                            ] DEBUG    | Http Task 192.168.178.134 finished!
[2024-04-14 13:45:43,588] [sml.tasks                                            ] DEBUG    | Watchdog Task 192.168.178.134 finished!
[2024-04-14 13:45:43,588] [sml.shutdown                                         ] DEBUG    | Stop devices done!
[2024-04-14 13:45:43,588] [sml.shutdown                                         ] DEBUG    | Shutdown mqtt
[2024-04-14 13:45:43,589] [sml.mqtt                                             ] DEBUG    | Disconnecting
[2024-04-14 13:45:43,590] [sml.tasks                                            ] DEBUG    | MQTT Task finished!
[2024-04-14 13:45:43,590] [sml.shutdown                                         ] DEBUG    | Shutdown mqtt done!
[2024-04-14 13:45:43,590] [sml.shutdown                                         ] DEBUG    | Close http session
[2024-04-14 13:45:43,841] [sml.shutdown                                         ] DEBUG    | Close http session done!
[2024-04-14 13:45:43,842] [sml.shutdown                                         ] DEBUG    | Shutdown complete
[2024-04-14 13:45:43,842] [sml.tasks                                            ] DEBUG    | Shutdown Task finished!
[2024-04-14 13:45:43,842] [sml.tasks                                            ] DEBUG    | All tasks done
[2024-04-14 15:05:16,894] [sml                                                  ] INFO     | Starting V3.0.DEV-5
[2024-04-14 15:05:16,895] [asyncio                                              ] DEBUG    | Using selector: EpollSelector
spacemanspiff2007 commented 2 months ago

Good morning - that's actually good news. I think I've found the culprit. What is your interval and timeout from the config.yml

MrFr33man123 commented 2 months ago
# Serial port configurations for the sml readers
inputs:
  - type: http
    url: http://192.168.178.134/data.json?node_id=1
    timeout: 10
    user: admin
    password: xxxx-xxxx
    interval: 5

This is my config :)

spacemanspiff2007 commented 2 months ago

I'm very confident that DEV-8 will fix your issue. You should see in the DEBUG log that the error is caught and the request retired.

MrFr33man123 commented 2 months ago

Awesome, thanks for all the energy you put into this. I already installed the new DEV-8 and startet it. Timeout is 3x 15sek now.

spacemanspiff2007 commented 2 months ago

@MrFr33man123 : Anything in the (DEBUG) logs?

MrFr33man123 commented 2 months ago

Since started on 15.04.24 no more unexpected crashes

Got these but it keept working:

[2024-04-15 20:13:11,307] [sml.192.168.178.134.status] DEBUG    | OK
[2024-04-15 20:14:03,017] [sml.http                  ] DEBUG    | Ignored 1/7 HttpStatusError: 404
[2024-04-15 20:19:22,348] [sml.192.168.178.134       ] DEBUG    | Crc error: 47917 != 62265
[2024-04-15 20:19:22,348] [sml.192.168.178.134.status] DEBUG    | CRC_ERROR
[2024-04-15 20:19:27,461] [sml.192.168.178.134.status] DEBUG    | OK

[2024-04-16 03:48:28,973] [sml.192.168.178.134       ] INFO     | get_obis failed - try parsing frame

[2024-04-17 15:03:39,583] [sml.http                  ] DEBUG    | Ignored 1/7

[2024-04-19 12:57:28,503] [sml.mqtt                  ] ERROR    | [code:7] The connection was lost. (MqttCodeError)
[2024-04-19 12:57:29,506] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 12:57:29,508] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 12:57:31,510] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 12:57:31,512] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 12:57:35,515] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 12:57:35,517] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 12:57:43,522] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 12:57:43,524] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 12:57:59,525] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 12:57:59,527] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 12:58:31,530] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 12:58:32,843] [sml.mqtt                  ] DEBUG    | Success!
[2024-04-19 13:06:51,398] [sml.192.168.178.134       ] DEBUG    | Crc error: 23132 != 18832
[2024-04-19 13:06:51,398] [sml.192.168.178.134.status] DEBUG    | CRC_ERROR
[2024-04-19 13:06:56,536] [sml.192.168.178.134.status] DEBUG    | OK
[2024-04-19 13:18:58,135] [sml.192.168.178.134       ] DEBUG    | Crc error: 6549 != 22789
[2024-04-19 13:18:58,135] [sml.192.168.178.134.status] DEBUG    | CRC_ERROR
[2024-04-19 13:19:08,390] [sml.192.168.178.134       ] DEBUG    | Crc error: 61119 != 51887
[2024-04-19 13:19:13,505] [sml.192.168.178.134.status] DEBUG    | OK
[2024-04-19 13:26:43,962] [sml.192.168.178.134       ] DEBUG    | Crc error: 58998 != 58718
[2024-04-19 13:26:43,963] [sml.192.168.178.134.status] DEBUG    | CRC_ERROR
[2024-04-19 13:26:49,085] [sml.192.168.178.134.status] DEBUG    | OK
[2024-04-19 13:27:14,683] [sml.192.168.178.134       ] DEBUG    | Crc error: 26791 != 15617
[2024-04-19 13:27:14,683] [sml.192.168.178.134.status] DEBUG    | CRC_ERROR
[2024-04-19 13:27:19,804] [sml.192.168.178.134.status] DEBUG    | OK
[2024-04-19 13:27:35,169] [sml.mqtt                  ] ERROR    | [code:7] The connection was lost. (MqttCodeError)
[2024-04-19 13:27:36,171] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 13:27:36,174] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 13:27:38,176] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 13:27:38,179] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 13:27:42,182] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 13:27:42,184] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 13:27:50,190] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 13:27:50,192] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 13:28:06,193] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 13:28:11,198] [sml.mqtt                  ] ERROR    | timed out (MqttError)
[2024-04-19 13:28:43,201] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 13:28:46,274] [sml.mqtt                  ] ERROR    | [Errno 113] No route to host (MqttError)
[2024-04-19 13:29:50,277] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 13:29:50,281] [sml.mqtt                  ] ERROR    | [Errno 111] Connection refused (MqttError)
[2024-04-19 13:31:58,284] [sml.mqtt                  ] DEBUG    | Connecting to 192.168.178.3:1883
[2024-04-19 13:31:58,750] [sml.mqtt                  ] DEBUG    | Success!

So no no more Problems, everything is now reconnecting/retrying as it should.

Looks good to me.

spacemanspiff2007 commented 2 months ago

Seems to work as expected. I'll wait a couple of more days and then I'll draft a release

[2024-04-17 15:03:39,583] [sml.http                  ] DEBUG    | Ignored 1/7
spacemanspiff2007 commented 2 months ago

released

aterjung commented 3 weeks ago

Hi, im running version 3 as i know, using the tibber pulse for now. After some time, the process exits with this log:

[2024-06-17 08:09:46,033] [sml ] INFO | Starting V3.0 [2024-06-17 08:09:46,688] [sml.192.168.12.78 ] INFO | No filters found for 010060320101, creating default filters [2024-06-17 08:09:46,689] [sml.192.168.12.78 ] INFO | No filters found for 0100010801ff, creating default filters [2024-06-17 08:09:46,689] [sml.192.168.12.78 ] INFO | No filters found for 0100010802ff, creating default filters [2024-06-17 08:09:46,690] [sml.192.168.12.78 ] INFO | No filters found for 0100020801ff, creating default filters [2024-06-17 08:09:46,690] [sml.192.168.12.78 ] INFO | No filters found for 0100020802ff, creating default filters [2024-06-17 08:09:46,695] [sml.192.168.12.78.status] INFO | OK [2024-06-17 08:30:33,795] [sml.192.168.12.78.status] INFO | MESSAGE_TIMEOUT [2024-06-17 08:30:43,593] [sml.192.168.12.78 ] ERROR | <class 'asyncio.exceptions.TimeoutError'>: [2024-06-17 08:30:43,593] [sml.192.168.12.78.status] INFO | ERROR [2024-06-17 08:30:43,595] [sml.shutdown ] INFO | Shutting down ...

These are the settings for the pulse: interval: 0.5 timeout: 10

Anything i can do?

spacemanspiff2007 commented 3 weeks ago

You can increase the interval (e.g. 1 or more secs) as this will also increase the request timeout and the tibbr pulse is slow to respond anyways. If that's not something you want to do you should set the request timeout to 2-5 secs.

aterjung commented 2 weeks ago

i`ve increased the interval to 1 second, which let the Service run continiusly again. But this affects the zero feed-in badly. I will try what happens with 0.5 seconds and a shorter timeout. As far as i remember sends my meter 1 sml message per second. so if timing is badly (the delay of the pulse is also added) it could be 2 seconds of with an interval von 1 second.

spacemanspiff2007 commented 2 weeks ago

If you modify the request timeout accordingly it should work with 0.5 seconds. If you look up this thread the pulse seems to lock up at least once a day and if the request timeout is too short your are hitting that.