Nanocul stops to work after few/several hours with add-on in HA

[Jordan87]

Hi

Here is my last hope because I'm already helpless :)

I bought my first Arduino Nano mini USB (clone) + CC1101 Modul for 868MHz Connected to Arduino to those pins

I flashed it with this firmware https://www.nanocul.de/upload/nanoCUL868-1.67_MBUS.zip?fbclid=IwAR0nZ2r61hxkWnmt3eIs8w6HY3NkE6coQxfrdQox_eJrhil1KbfMQetcz_g It is working with my water meter but most often only few/several hours, and i need to disconnect and connect again USB to Arduino to have it working

Config:

data_path: /config/wmbusmeters enable_mqtt_discovery: false conf:	- loglevel=debug device=/dev/serial/by-id/usb-1a86_USB_Serial-if00-port0:cul:t1 logtelegrams=true format=json logfile=/dev/stdout shell=/wmbusmeters/mosquitto_pub.sh wmbusmeters/$METER_NAME "$METER_JSON" meters:

name=MainWater
driver=izar
id=2119e135
key=

mqtt: {}

First i bought second Arduino nano (clone but this time with USB C) and i even flashed it with linux like it is described here https://weetmuts.github.io/wmbusmeterswiki/nanoCUL.html but for some reason with this one it doesn't work at all. shortly after starting add-on in HA, led "L" on arduino starts to blink rapidly and that's all (same behavior like with first one but after few hour when it occurs)

Log:

s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service legacy-services: starting s6-rc: info: service legacy-services successfully started Syncing wmbusmeters configuration ... Registering meters ... Adding meter-0001 ... Generating MQTT configuration ... Broker core-mosquitto will be used. MQTT Discovery cleanup... Running wmbusmeters ... (config) "device" "/dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0:cul:t1" (wmbusmeters) version: 1.9.0-129-g53a2d65 (config) using device: /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0:cul:t1 (config) number of meters: 1 (lookup) with file/hex "/dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0" cul (serial) check if /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 can be accessed (serial) tty /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 can be accessed (serial) EVENT thread interrupted (serial) before config: /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 speed(B9600) input(ICRNL|IXON) output(ONLCR|OPOST) control(CLOCAL|CREAD|CSIZE|HUPCL) local(ECHO|ECHOCTL|ECHOE|ECHOK|ECHOKE|ICANON|IEXTEN|ISIG) special_chars(3,28,127,21,4,1,17,19,26,18,15,23,22,233,126,126,99,153,105,155,14) modem(DTR|RTS) (serial) after config: /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars(233,126,126,99,16) modem(DTR|RTS) (serialtty) opened /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 fd 3 (detect cul) (serial /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0) sent "560D0A" (serial) EVENT thread interrupted (serial) received binary "" (cul) probe response "" (serial /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0) sent "560D0A" (serial) EVENT thread interrupted (serial) received binary "" (cul) probe response "" (serial /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0) sent "560D0A" (serial) EVENT thread interrupted (serial) received binary "" (cul) probe response "" (serialtty) closed /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 (detect cul) (serial) EVENT thread interrupted (cul) are you there? no Expected cul on /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 but did not find it! Ignoring tty! (verbose) ignoring device t1 No wmbus device detected, waiting for a device to be plugged in. (shell) exec (capture output) "/bin/pidof" (shell) arg "wmbusmetersd" (shell) output: >>><<< (serial) EVENT thread interrupted (shell) return code 1 (shell) 154 exited (shell) exec (capture output) "/bin/pidof" (shell) arg "wmbusmeters" (shell) output: >>>151 <<< (serial) EVENT thread interrupted (shell) return code 0 (shell) 155 exited (serial) registered regular callback HOT_PLUG_DETECTOR(0) every 2 seconds (serial) waiting for stop (serial) EVENT thread interrupted (serial) TIMER thread interrupted (lookup) with file/hex "/dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0" cul (serial) check if /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 can be accessed (serial) tty /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 can be accessed (serial) EVENT thread interrupted (serial) before config: /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars(61,127,126,99,153,105,155,14) modem(DTR|RTS) (serial) after config: /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars(61,127,126,99,16) modem(DTR|RTS) (serialtty) opened /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 fd 5 (detect cul) (serial /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0) sent "560D0A" (serial) EVENT thread interrupted (serial) received binary "3F2028605620697320756E6B6E6F776E2920557365206F6E65206F66204220622043206520462047204B206C204D20522054207420562057205820780D0A" (cul) probe response "? (`V is unknown) Use one of B b C e F G K l M R T t V W X x<0D><0A>" (serial /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0) sent "560D0A" (serial) EVENT thread interrupted (serial) received binary "5620312E3637206E616E6F43554C3836385F723536380D0A" (cul) probe response "V 1.67 nanoCUL868_r568<0D><0A>" (serialtty) closed /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 (detect cul) (serial) EVENT thread interrupted (cul) are you there? yes (main) opening /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0:cul:t1 Started config cul on /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 listening on t1 (cul) on /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 (serial) EVENT thread interrupted (serial) before config: /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars(65,127,126,99,153,105,155,14) modem(DTR|RTS) (serial) after config: /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars(65,127,126,99,16) modem(DTR|RTS) (serialtty) opened /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 fd 5 (cul) (main) regular reset of cul on /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0 will happen every 82800 seconds (cul) set link mode t (serial /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0) sent "6272740D0A" (serial) EVENT thread interrupted (serial) received binary "544D4F44450D0A" (cul) checkCULFrame "TMODE<0D><0A>" (cul) no leading 'b' so it is text and no frame (cul) received "TMODE"(serial /dev/serial/by-id/usb-1a86USB2.0-Ser-if00-port0) sent "5832310D0A" (wmbus) no alarm (expected activity) for cul (serial) EVENT thread interrupted

I even bought second CC1101 module but this one doesn't work at all with both Arduino's... Soldering and connections were checked at least four times according to schema from picture attached here.

Thanks

[Jordan87]

Here is the end of log when after few/several hours it stops to work

... (wmbus) skipping already handled telegram leng=26. (serial) received binary "6231393434333034433335453131393231393830314239383741323431313630" (cul) checkCULFrame "b1944304C35E119219801B987A241160" (cul) no eol found yet, partial frame (serial) received binary "3031333242463337414138423038453835313542383434414633353633383631" (cul) checkCULFrame "b1944304C35E119219801B987A2411600132BF37AA8B08E8515B844AF3563861" (cul) no eol found yet, partial frame (serial) received binary "370D0A" (cul) checkCULFrame "b1944304C35E119219801B987A2411600132BF37AA8B08E8515B844AF35638617<0D><0A>" (cul) checkCULFrame RSSI_RAW=23 (cul) checkCULFrame LQI=67 (wmbus) trimming frame A "1944304C35E119219801B987A2411600132BF37AA8B08E8515B844AF3563" (wmbus) ff a dll crc 0-9 b987 ok (wmbus) ff a dll crc mid 12-27 3563 ok (wmbus) trimming frame A "1944304C35E119219801B987A2411600132BF37AA8B08E8515B844AF3563" (wmbus) trimmed 4 dll crc bytes from frame a and ignored 0 suffix bytes. (wmbus) trimmed frame A "1944304C35E119219801A2411600132BF37AA8B08E8515B844AF" (cul) received full T1 frame (wmbus) skipping already handled telegram leng=26.

No visible errors from wmbusmeters

Unplug and again to HA server and again its working.

[magcode]

You could look into flashing the optiboot bootloader on your nano. For me it helped. My nanocul did stop working after a few days with rapidly blinking LEDs. After changing to optiboot the issue was gone...

[Jordan87]

Thanks. Both of my Nano's were having old bootloader, now both are updated but after updeto non of them is recieving any telegrams from my water meter.

Started auto cul on /dev/ttyUSB0 listening on t1 Started auto cul on /dev/ttyUSB3 listening on t1 No meters configured. Printing id:s of all telegrams heard!

This is the end of log (at this moment both are connected).

Do i need to change something now for optiboot in nanoCUL firmware settings?

[Jordan87]

Today I flashed them again and one which was able to work few/several hours is working also with new bootloader. Will see if it will solve my issue at lest with one nanoCUL :)

[Jordan87]

After bootloader update I dont need to disconnect physically any more but but I need to restart wmbusmeters once a day.

Without debug logs I see this on the end and its probably related with time when add-on stops to collect data.

s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service legacy-services: starting s6-rc: info: service legacy-services successfully started Syncing wmbusmeters configuration ... Registering meters ... Adding meter-0001 ... Generating MQTT configuration ... Broker core-mosquitto will be used. MQTT Discovery cleanup... Running wmbusmeters ... Started auto cul on /dev/ttyACM0 listening on t1 (wmbus) resetting /dev/ttyACM0:cul[] (wmbus) reset completed /dev/ttyACM0:cul[]

I ordered ESP8266 and will try to read my meter with it because i have too many problems with arduino and wmbusmeters. I found some info that Arduino needs voltage converter from 5V to 3V for signals (not power supply).

[weetmuts]

So wmbusmeters performs a reset of the dongle every 23 hours by default. This is to flush out problems with some dongles that stop working after a few weeks, yes really.

If you can provoke the cul bad behaviour using --resetafter=1m (it will reset once per minute instead) then we can take a look at the debug logs to see what is going on.

[Jordan87]

Thanks for hint with resetafter=1m, i tried with 3min and constant water usage during 21min so there was around 7 restarts and no reading gaps are visible so most probably this default 23h restart time was not causing my issue.

But one observation, in earlier presented log last two lines were:

(wmbus) resetting /dev/ttyACM0:cul[] (wmbus) reset completed /dev/ttyACM0:cul[]

Now with time 1 or 3min log is almost every time cleared like in case when whole add-on is restarted but not always, sometimes in console log show only those two lines miltiple times (with configured resetafter time).

ps Finally I have working log file (not log console in add-on) and time stamps so maybe now I will be able to find exact time when issue is happening and correlate it with logs. I have changed logfile to /config/wmbusmeters/logs/log.txt (default path was not working in HAOS) and added logtimestamps=always

[Jordan87]

From my last post problem occured two times. first affter almost 3h and second after 5 days (i was preety sure that HA update to 2022.12 solved issue because it was first time when it was working that long)

In both cases logs didnt show any abnormal prints:

[2022-12-12_10:06:41] (wmbus) skipping already handled telegram leng=26. [2022-12-12_10:06:49] (serial) received binary "6231393434333034433335453131393231393830314239383741323631313530" [2022-12-12_10:06:49] (cul) checkCULFrame "b1944304C35E119219801B987A261150" [2022-12-12_10:06:49] (cul) no eol found yet, partial frame [2022-12-12_10:06:49] (serial) received binary "3031333132374138463531393941454243454336334436414345393046383132" [2022-12-12_10:06:49] (cul) checkCULFrame "b1944304C35E119219801B987A261150013127A8F5199AEBCEC63D6ACE90F812" [2022-12-12_10:06:49] (cul) no eol found yet, partial frame [2022-12-12_10:06:49] (serial) received binary "310D0A" [2022-12-12_10:06:49] (cul) checkCULFrame "b1944304C35E119219801B987A261150013127A8F5199AEBCEC63D6ACE90F8121<0D><0A>" [2022-12-12_10:06:49] (cul) checkCULFrame RSSI_RAW=33 [2022-12-12_10:06:49] (cul) checkCULFrame LQI=64 [2022-12-12_10:06:49] (wmbus) trimming frame A "1944304C35E119219801B987A261150013127A8F5199AEBCEC63D6ACE90F" [2022-12-12_10:06:49] (wmbus) ff a dll crc 0-9 b987 ok [2022-12-12_10:06:49] (wmbus) ff a dll crc mid 12-27 e90f ok [2022-12-12_10:06:49] (wmbus) trimming frame A "1944304C35E119219801B987A261150013127A8F5199AEBCEC63D6ACE90F" [2022-12-12_10:06:49] (wmbus) trimmed 4 dll crc bytes from frame a and ignored 0 suffix bytes. [2022-12-12_10:06:49] (wmbus) trimmed frame A "1944304C35E119219801A261150013127A8F5199AEBCEC63D6AC" [2022-12-12_10:06:49] (cul) received full T1 frame [2022-12-12_10:06:49] (wmbus) skipping already handled telegram leng=26. Here i changed log file so addon was restarted [2022-12-12_12:45:24] (serial) stopping manager [2022-12-12_12:45:24] (serial) MAIN thread interrupted [2022-12-12_12:45:24] (serial) TIMER thread interrupted [2022-12-12_12:45:24] (serial) EVENT thread interrupted [2022-12-12_12:45:24] (serial) closing 6 devices [2022-12-12_12:45:24] (serial) event loop stopped! [2022-12-12_12:45:24] (serialtty) closed /dev/ttyUSB2 (detect amb8465/amb3665) [2022-12-12_12:45:24] (serialtty) closed /dev/ttyUSB2 (detect im871a) [2022-12-12_12:45:24] (serialtty) closed /dev/ttyUSB2 (detect rc1180) [2022-12-12_12:45:24] (serialtty) closed /dev/ttyUSB2 (detect cul) [2022-12-12_12:45:24] (serialtty) closed /dev/ttyUSB2 (detect iu880b) [2022-12-12_12:45:24] (wmbus) disconnected /dev/ttyUSB3 cul [2022-12-12_12:45:24] (serialtty) closed /dev/ttyUSB3 (cul) [2022-12-12_12:45:24] (wmbus) deleted cul [2022-12-12_12:45:24] (serial) closing 6 devices

Now i will set resetafter=2h and check if it recovers from this problematic state.

[Jordan87]

Parameter "resetafter" can be used as a workaround in my case. From logs i see that it starts to work after programmed reset.

[2022-12-16_17:11:36] (cul) received full T1 frame [2022-12-16_17:11:36] (wmbus) skipping already handled telegram leng=26. [2022-12-16_18:34:49] (wmbus) regular reset of /dev/ttyUSB0 cul [2022-12-16_18:34:49] (serial) initiate reset [2022-12-16_18:34:49] (serialtty) closed /dev/ttyUSB0 (cul) [2022-12-16_18:34:49] (wmbus) resetting /dev/ttyUSB0:cul[] [2022-12-16_18:34:52] (serial) before config: /dev/ttyUSB0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars(27,144,156,99,174,217,86,13) modem(DTR|RTS) [2022-12-16_18:34:52] (serial) after config: /dev/ttyUSB0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars(27,144,156,99,16) modem(DTR|RTS) [2022-12-16_18:34:52] (serialtty) opened /dev/ttyUSB0 fd 4 (cul) [2022-12-16_18:34:52] (serial) reset completed [2022-12-16_18:34:52] (cul) set link mode t [2022-12-16_18:34:52] (serial /dev/ttyUSB0) sent "6272740D0A"

[torliPL]

The problem is with Arduino Nano clone version. Use original Arduino Nano and the problem with software reset will be gone. Somehow clone version of Arduino Nano can hang and dissapear from the host. The only way to bring it to life is to replug the dongle.

[Jordan87]

For issue with disconnecting Arduino bootloader loader helped. Other software issue with add-on was still present.

[github-actions[bot]]

This issue is stale because it has been open for 2 month with no activity. Remove stale label or comment or this will be closed in 1 month.

[tonivss]

I had the exact same problem. Flashing the new bootloader to my Arduino Nano clone version solved the problem. Thank you!

You could look into flashing the optiboot bootloader on your nano. For me it helped. My nanocul did stop working after a few days with rapidly blinking LEDs. After changing to optiboot the issue was gone...

[github-actions[bot]]

This issue is stale because it has been open for 2 month with no activity. Remove stale label or comment or this will be closed in 1 month.

[github-actions[bot]]

This issue was closed because it has been stalled for 1 month with no activity.