Rule condition shows TRUE in UI but Rule never transitions to SET — survives full restart

[apocalypsehobby]

@toggledbits Do you mind helping me understand why the "socket hang up" & "ECONNREFUSED" messages mean that Vera is reloading a lot?

[toggledbits]

The ECONNREFUSED means that your Vera is not accepting connections. This happens during reloads, when the box is up and running but LuaUPnP is not ready to answer requests. It could also mean you have the wrong IP address configured, or the IP is not reachable on the network segment you are on, but I'm assuming you know the correct IP of the box and have configured it correctly, and the other message suggests something is reachable at the IP and port given (and the port is very unusual and specific to Vera).

The "socket hang up" means that the LuaUPnP engine accepted the connection but the connection was terminated before the request could be sent, or terminated with no response data -- the server/Vera closed the connection without saying anything, or didn't say anything within the connection timeout period, although timeouts are usually more definitive and reported as such.

I'm assuming you're seeing a lot of these, and that's why you posted.

[Buxton]

@apocalypsehobby You might also have authentication on. Check in the highlit file below to make sure "auth" is commented out --- like you see in the subsequent screenshot. The file is located in the etc folder on the vera:

you also need to make the same adjustment in the same name file stored in the lighttpd folder that is under etc/:

[apocalypsehobby]

Thank you both. @Buxton I followed these directions and commented out "auth" in both files, restarted Vera, still got the same error messages.

What's strange is-- I took one of the request URLs (like http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632187568275) and pasted it into my laptop's web browser, and I got a huge output file. So it seems like Vera is working.

Maybe it's a network configuration problem like you suggested, @toggledbits ? So I went to my Raspberry Pi that's running MSR, and I used wget then it successfully downloaded the output file to the pi as well. So I'm not sure why it's not working within MSR!

[toggledbits]

Let's go back to a previous question... are you getting a ton of these, or just occasionally?

[apocalypsehobby]

@toggledbits A ton

pi@MSR-raspberrypi:~/reactor $ node app.js
basedir /home/pi/reactor
confdir /home/pi/reactor/config
datadir /home/pi/reactor/storage
logsdir /home/pi/reactor/logs
plugindir /home/pi/reactor/ext
module.paths [
  '/home/pi/reactor/node_modules',
  '/home/pi/node_modules',
  '/home/node_modules',
  '/node_modules'
]
NODE_PATH undefined
2021-09-25T18:29:17.047Z <app:null> Reactor "1.0.1-21243-83a87ba" starting on v14.17.6
2021-09-25T18:29:17.051Z <app:INFO> Process ID 3194; platform linux/arm #1449 SMP Wed Aug 25 15:00:01 BST 2021; locale [ "en-GB", "UTF-8" ]
2021-09-25T18:29:17.053Z <app:INFO> Basedir /home/pi/reactor; data in /home/pi/reactor/storage
2021-09-25T18:29:17.054Z <app:INFO> NODE_PATH (undefined); module paths [ "/home/pi/reactor/node_modules", "/home/pi/node_modules", "/home/node_modules", "/node_modules" ]
2021-09-25T18:29:17.245Z <Plugin:null> Module Plugin v21173
2021-09-25T18:29:17.270Z <default:INFO> Module Entity v21177
2021-09-25T18:29:17.280Z <Controller:null> Module Controller v21226
2021-09-25T18:29:17.281Z <default:null> Module Structure v21229
2021-09-25T18:29:17.303Z <default:null> Module Ruleset v21096
2021-09-25T18:29:17.304Z <default:null> Module Rulesets v21096
2021-09-25T18:29:17.373Z <default:null> Module Rule v21224
2021-09-25T18:29:17.388Z <default:null> Module Engine v21213
2021-09-25T18:29:17.390Z <default:null> Module httpapi v21238
2021-09-25T18:29:17.396Z <default:null> Module httpproxy v21054
2021-09-25T18:29:17.443Z <default:null> Module wsapi v21196
2021-09-25T18:29:17.447Z <app:NOTICE> Starting Structure...
2021-09-25T18:29:17.455Z <default:NOTICE> Structure#1 plugin ID influx disabled; skipping
2021-09-25T18:29:17.459Z <default:INFO> Structure#1 starting controller interface vera (VeraController)
2021-09-25T18:29:17.470Z <default:INFO> Structure#1 starting controller interface hass (HassController)
2021-09-25T18:29:17.473Z <default:INFO> Structure#1 starting controller interface reactor_system (SystemController)
2021-09-25T18:29:17.614Z <default:null> Module VeraController v21236
2021-09-25T18:29:17.625Z <default:null> Module HassController v21243
2021-09-25T18:29:17.630Z <default:null> Module SystemController v21102
2021-09-25T18:29:17.641Z <VeraController:NOTICE> VeraController#vera starting
2021-09-25T18:29:17.809Z <VeraController:INFO> VeraController#vera loaded mapping ver 21236 rev 1 format 1 notice
2021-09-25T18:29:17.812Z <VeraController:INFO> VeraController: deviceclass vera_system_object capability sys_system does not provide attribute state
2021-09-25T18:29:17.926Z <HassController:INFO> HassController#hass device mapping data loaded; checking...
2021-09-25T18:29:17.997Z <HassController:NOTICE> HassController#hass attempting reconnection to ws://10.0.0.108:8123/api/websocket
2021-09-25T18:29:18.002Z <HassController:NOTICE> HassController#hass connecting via WS to ws://10.0.0.108:8123/api/websocket
2021-09-25T18:29:18.018Z <default:NOTICE> Controller SystemController#reactor_system is now online.
2021-09-25T18:29:18.192Z <app:INFO> Structure running; pausing for controllers' initial ready
2021-09-25T18:29:18.261Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594557823 failed, reason: socket hang up
2021-09-25T18:29:18.285Z <HassController:NOTICE> HassController#hass connected, starting protocol
2021-09-25T18:29:18.304Z <HassController:INFO> HassController#hass successful authentication with ws://10.0.0.108:8123; fetching initial data...
2021-09-25T18:29:18.317Z <HassController:INFO> HassController#hass Hass reports version "2021.8.6" location Home timezone America/Detroit state RUNNING safe_mode false
2021-09-25T18:29:18.553Z <HassController:NOTICE> Controller HassController#hass is now online.
2021-09-25T18:29:23.290Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594563265 failed, reason: socket hang up
2021-09-25T18:29:28.312Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594568291 failed, reason: socket hang up
2021-09-25T18:29:33.339Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594573317 failed, reason: socket hang up
2021-09-25T18:29:39.363Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594579344 failed, reason: socket hang up
2021-09-25T18:29:46.392Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594586368 failed, reason: socket hang up
2021-09-25T18:29:54.420Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594594399 failed, reason: socket hang up
2021-09-25T18:30:03.448Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594603429 failed, reason: socket hang up
2021-09-25T18:30:13.468Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594613450 failed, reason: socket hang up
2021-09-25T18:30:18.265Z <app:NOTICE> Starting Reaction Engine...
2021-09-25T18:30:18.269Z <Engine:INFO> Reaction Engine starting
2021-09-25T18:30:18.273Z <Engine:INFO> Checking rule sets...
2021-09-25T18:30:18.285Z <Engine:INFO> Checking rules...
2021-09-25T18:30:18.287Z <Engine:INFO> Data check complete; no corrections.
2021-09-25T18:30:18.296Z <Engine:NOTICE> Reaction Engine running!
2021-09-25T18:30:18.297Z <app:NOTICE> Starting HTTP server and API...
2021-09-25T18:30:18.314Z <app:NOTICE> Startup complete
2021-09-25T18:30:18.323Z <app:NOTICE> HTTP API v1 21238 base URL http://10.0.0.5:8111; listening
2021-09-25T18:30:18.362Z <app:NOTICE> HTTP server running; registering proxy endpoints.
2021-09-25T18:30:18.365Z <app:NOTICE> Starting WSAPI...
2021-09-25T18:30:18.368Z <app:NOTICE> wsapi: starting version 21196
2021-09-25T18:30:18.405Z <Engine:INFO> Engine#1 master timer tick, local time "25/09/2021, 14:30:18" (TZ offset -240 mins from UTC)
2021-09-25T18:30:18.687Z <app:INFO> wsapi: connection from ::ffff:10.0.0.91
2021-09-25T18:30:24.490Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594624469 failed, reason: socket hang up
2021-09-25T18:30:36.518Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594636500 failed, reason: socket hang up
2021-09-25T18:30:49.536Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594649518 failed, reason: socket hang up
2021-09-25T18:31:03.567Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594663549 failed, reason: socket hang up
2021-09-25T18:31:18.580Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594678567 failed, reason: socket hang up
2021-09-25T18:31:34.607Z <VeraController:ERR> VeraController#vera update request failed: FetchError: request to http://10.0.0.141:3480/data_request?id=user_data&ns=1&Timeout=15&output_format=json&_r=1632594694590 failed, reason: socket hang up

[toggledbits]

What version of Vera firmware are you running? What are the specs of the Pi?

pasted it into my laptop's web browser, and I got a huge output file. So it seems like Vera is working.

How long did it take to get the response?

[apocalypsehobby]

@toggledbits
Vera Firmware: 1.7.5186 (7.31)
Pi: Raspberry Pi 3 Model B Plus Rev 1.3, and the Debian version is 10.10

The response was immediate from the web browser, and from when I used wget within the Pi.

[toggledbits]

I have it running on both a 1GB 3B+ and a 4GB 4, but under Raspberry Pi OS/Raspian. I'd suggest trying that next.

[apocalypsehobby]

@toggledbits Sorry, I should have been more specific, it’s running Raspberry Pi OS Lite. Are you saying it should be the regular Raspberry Pi OS?

[toggledbits]

OK. The version of nodejs you've got running isn't the one installed by the install script... did you run the install script? It will still let you use that version, that "should not" be a/the problem, but the script does other things... installs dependencies, certain versions... should not be run as root or under su/sudo... did all that happen?

[apocalypsehobby]

@toggledbits Oh jeez, I followed the wrong set of instructions from the get-go. When you asked about the install script, I retraced my steps and realized what happened.

I followed the "Linux (various) Bare Metal" instructions because I did not read that the 4B instructions also worked for the 3B+.

So I just started fresh and followed the correct instructions, and everything seems to be working. Thank you for your help!

[toggledbits]

Sounds good. Still leaves me wondering what was going on, because the bare metal steps basically take you in the same direction as the installer (and the reverse is also true — you could run the Pi install script on pretty much any Linux box and probably get a valid install). In the background, I also brought up a 3B+ on RaspiOS and did a bare metal install with node 14.17.6 as you had, and it worked fine. So, not sure what may have gone sideways with your original install, but I'm glad the script straightened it out.

Did you let the install script install node 14.15, or did you let it go ahead with the 14.17 previously installed? That would narrow down some variables.

[apocalypsehobby]

I just let it run with the 14.17