[SOLVED] Fatal error on upgrade to 22021 / Raspberry Pi4 Docker
-
I attempted to upgrade my Docker container to "toggledbits/reactor:latest-raspbian-armv7l" and the container started but the Reactor interface wouldn't load in the browser. The logs showed this:
# # Fatal error in , line 0 # unreachable code # # # #FailureMessage Object: 0xbec2458c # # Fatal error in , line 0 # unreachable code # # # #FailureMessage Object: 0xbedec58c # # Fatal error in , line 0 # unreachable code # # # #FailureMessage Object: 0xbed3358c # # Fatal error in , line 0 # unreachable code # # # #FailureMessage Object: 0xbef7f58c # # Fatal error in , line 0 # unreachable code # # # #FailureMessage Object: 0xbedd958c # # Fatal error in , line 0 # unreachable code # # # #FailureMessage Object: 0xbe86958c
The logs continued throwing errors with different object IDs.
I removed the container and tried to install again using toggledbits/reactor:1.0.2-raspbian-armv7l and now the container won't start and the logs show this:
NODE_PATH /opt/reactor FileLogStream { type: 'file', name: 'reactor.log', mode: 438, maxsize: 2, keep: 5 } [1.0.2-21350]2022-01-22T14:35:21.715Z <app:null> Reactor "1.0.2-21350-252f948" starting on v16.11.1 [1.0.2-21350]2022-01-22T14:35:21.717Z <app:INFO> Process ID 1; platform linux/arm #1457 SMP Tue Sep 28 11:26:14 BST 2021; locale (undefined) [1.0.2-21350]2022-01-22T14:35:21.718Z <app:INFO> Basedir /opt/reactor; data in /var/reactor/storage [1.0.2-21350]2022-01-22T14:35:21.719Z <app:INFO> NODE_PATH=/opt/reactor [1.0.2-21350]2022-01-22T14:35:21.727Z <app:INFO> Configured locale (undefined); selected locale(s) en-US.UTF-8 [1.0.2-21350]2022-01-22T14:35:21.786Z <app:INFO> Loaded locale en-US [1.0.2-21350]2022-01-22T14:35:21.812Z <Capabilities:null> Module Capabilities v21333 [1.0.2-21350]2022-01-22T14:35:21.890Z <Plugin:null> Module Plugin v21186 [1.0.2-21350]2022-01-22T14:35:21.902Z <TimerBroker:null> Module TimerBroker v21333 [1.0.2-21350]2022-01-22T14:35:21.908Z <default:INFO> Module Entity v21334 [1.0.2-21350]2022-01-22T14:35:21.916Z <Controller:null> Module Controller v21333 [1.0.2-21350]2022-01-22T14:35:21.917Z <default:null> Module Structure v21338 [1.0.2-21350]2022-01-22T14:35:21.934Z <default:null> Module Ruleset v21096 [1.0.2-21350]2022-01-22T14:35:21.935Z <default:null> Module Rulesets v21096 [1.0.2-21350]2022-01-22T14:35:21.956Z <GlobalExpression:null> Module GlobalExpression v21333 [1.0.2-21350]2022-01-22T14:35:21.986Z <default:null> Module Rule v21348 [1.0.2-21350]2022-01-22T14:35:21.994Z <GlobalReaction:null> Module GlobalReaction v21333 [1.0.2-21350]2022-01-22T14:35:21.997Z <AlertManager:null> Module AlertManager v21333 [1.0.2-21350]2022-01-22T14:35:21.998Z <default:null> Module Engine v21346 [1.0.2-21350]2022-01-22T14:35:21.999Z <default:null> Module httpapi v21345 [1.0.2-21350]2022-01-22T14:35:22.004Z <default:null> Module httpproxy v21333 [1.0.2-21350]2022-01-22T14:35:22.037Z <default:null> Module wsapi v21334 [1.0.2-21350]2022-01-22T14:35:22.048Z <app:NOTICE> Starting Structure... [1.0.2-21350]2022-01-22T14:35:22.131Z <InfluxFeed:null> Module InfluxFeed v21345 [1.0.2-21350]2022-01-22T14:35:22.135Z <Structure:INFO> Structure#1 starting plugin influx (InfluxFeed) [1.0.2-21350]2022-01-22T14:35:22.137Z <Structure:INFO> Structure#1 loading controller interface hubitat (HubitatController) [1.0.2-21350]2022-01-22T14:35:22.162Z <HubitatController:null> Module HubitatController v21338 [1.0.2-21350]2022-01-22T14:35:22.174Z <Structure:INFO> Structure#1 loading controller interface hubitat_11705 (HubitatController) [1.0.2-21350]2022-01-22T14:35:22.180Z <Structure:INFO> Structure#1 loading controller interface weather (OWMWeatherController) [1.0.2-21350]2022-01-22T14:35:22.194Z <OWMWeatherController:null> Module OWMWeatherController v21313 [1.0.2-21350]2022-01-22T14:35:22.198Z <Structure:INFO> Structure#1 loading controller interface reactor_system (SystemController) [1.0.2-21350]2022-01-22T14:35:22.205Z <SystemController:null> Module SystemController v21345 [1.0.2-21350]2022-01-22T14:35:22.211Z <Structure:INFO> Structure#1 loading controller interface mqtt (MQTTController) [1.0.2-21350]2022-01-22T14:35:22.223Z <MQTTController:null> Module MQTTController v21361 [1.0.2-21350]2022-01-22T14:35:22.227Z <Controller:CRIT> Controller: failed to load mqtt implementation file:///var/reactor/ext/MQTTController/MQTTController.js: [TypeError]TypeError: require(...).requires is not a function [1.0.2-21350]2022-01-22T14:35:22.229Z <Controller:CRIT> TypeError: require(...).requires is not a function TypeError: require(...).requires is not a function at Object.<anonymous> (/var/reactor/ext/MQTTController/MQTTController.js:14:53) at Module._compile (node:internal/modules/cjs/loader:1101:14) at Object.Module._extensions..js (node:internal/modules/cjs/loader:1153:10) at Module.load (node:internal/modules/cjs/loader:981:32) at Function.Module._load (node:internal/modules/cjs/loader:822:12) at ModuleWrap.<anonymous> (node:internal/modules/esm/translators:196:29) at ModuleJob.run (node:internal/modules/esm/module_job:183:25) at async Loader.import (node:internal/modules/esm/loader:178:24) at async importModuleDynamicallyWrapper (node:internal/vm/module:437:15) Trapped unhandled Promise rejection TypeError: require(...).requires is not a function at Object.<anonymous> (/var/reactor/ext/MQTTController/MQTTController.js:14:53) at Module._compile (node:internal/modules/cjs/loader:1101:14) at Object.Module._extensions..js (node:internal/modules/cjs/loader:1153:10) at Module.load (node:internal/modules/cjs/loader:981:32) at Function.Module._load (node:internal/modules/cjs/loader:822:12) at ModuleWrap.<anonymous> (node:internal/modules/esm/translators:196:29) at ModuleJob.run (node:internal/modules/esm/module_job:183:25) at async Loader.import (node:internal/modules/esm/loader:178:24) at async importModuleDynamicallyWrapper (node:internal/vm/module:437:15) TypeError: require(...).requires is not a function at Object.<anonymous> (/var/reactor/ext/MQTTController/MQTTController.js:14:53) at Module._compile (node:internal/modules/cjs/loader:1101:14) at Object.Module._extensions..js (node:internal/modules/cjs/loader:1153:10) at Module.load (node:internal/modules/cjs/loader:981:32) at Function.Module._load (node:internal/modules/cjs/loader:822:12) at ModuleWrap.<anonymous> (node:internal/modules/esm/translators:196:29) at ModuleJob.run (node:internal/modules/esm/module_job:183:25) at async Loader.import (node:internal/modules/esm/loader:178:24) at async importModuleDynamicallyWrapper (node:internal/vm/module:437:15) { <rejected> TypeError: require(...).requires is not a function at Object.<anonymous> (/var/reactor/ext/MQTTController/MQTTController.js:14:53) at Module._compile (node:internal/modules/cjs/loader:1101:14) at Object.Module._extensions..js (node:internal/modules/cjs/loader:1153:10) at Module.load (node:internal/modules/cjs/loader:981:32) at Function.Module._load (node:internal/modules/cjs/loader:822:12) at ModuleWrap.<anonymous> (node:internal/modules/esm/translators:196:29) at ModuleJob.run (node:internal/modules/esm/module_job:183:25) at async Loader.import (node:internal/modules/esm/loader:178:24) at async importModuleDynamicallyWrapper (node:internal/vm/module:437:15) } Trace at process.<anonymous> (/opt/reactor/app.js:267:142) at process.emit (node:events:390:28) at process.emit (node:domain:475:12) at emit (node:internal/process/promises:136:22) at processPromiseRejections (node:internal/process/promises:242:25) at processTicksAndRejections (node:internal/process/task_queues:97:32) [1.0.2-21350]2022-01-22T14:35:22.234Z <app:ERR> Trapped unhandled Promise rejection: [TypeError]TypeError: require(...).requires is not a function [1.0.2-21350]2022-01-22T14:35:22.234Z <app:ERR> Please refer to the console log for trace
I noticed the reference to MQTT so I changed MQTT controller to enabled:False in my reactor.yaml file. I tried reinstalling latest with the same results as before. I was then able to install 1.0.2 successfully and Reactor is running. I'm only getting this error on the status page:
An Entity Attribute condition in rule "Notify when Reactor Alert is raised" failed because the referenced entity Reactor System (reactor_system>system) does not have attribute reactor_system.alert_last
I assume that 1.0.2 was prior to that feature being implemented.
Any advice on how to successfully upgrade to 22021 would be appreciated. I saw the instructions for bare metal, but I don't think that applies when I'm pulling the docker image and creating a new container.
-
@toggledbits Setting aside the hijack of my Raspberry Pi Docker thread by a Windows bare metal issue... any thoughts on why my docker install of "latest" failed?
-
@Alan_F version 1.0.2 will not support the version of MQTTController you are using. I have no issue starting a container on latest; not getting the error you are reporting (and I ran the container before deploying it and didn't see it then, either).
I think your first step should not be going backwards, but reinstalling the current version. If MQTTController won't load on latest, then disable it via config and try restarting. Post overall doesn't have much context (log snippet needs more context).
-
That wasn't a log snippet... at least not the first one. That was the entire log after upgrading to latest. The issue doesn't appear to be that MQTT controller won't load on latest. With MQTT set to false I still get nothing in the log file but "Fatal Error at line 0".
I assume something in my config file is the issue, so I'll start commenting out sections that aren't default and hope I can get it working.
Edit: I think I see one source of confusion... that first set of log entries is from the logs of the docker container, which I pulled from Portainer (used to manage my Docker containers). While Portainer shows the container as running, Reactor itself is not saving any logs at all. I guess that makes sense if it crashed out on line zero...
How can I get a new/clean version of reactor.yaml? I tried deleting my docker image, renaming the existing file, and pulling/running the docker image again, but it doesn't create a new reactor.yaml.
I also tried making sure my RPi4 was up to date (apt update / apt full-upgrade) then rebooted, but I'm still stuck.
-
After barking up many wrong trees I found this: https://www.giters.com/SensorsIot/IOTstack/issues/401
Which provided these steps to fix the issue
$ sudo apt-key adv --keyserver hkps://keyserver.ubuntu.com:443 --recv-keys 04EE7237B7D453EC 648ACFD622F3D138 $ echo "deb http://httpredir.debian.org/debian buster-backports main contrib non-free" | sudo tee -a "/etc/apt/sources.list.d/debian-backports.list" $ sudo apt update $ sudo apt install libseccomp2 -t buster-backports
After running those command, MSR is back in business on the latest build.
-
Interesting, so I found Sam Cater's blog, the source for your first link. That was necessary to build the image for RPi because docker would not even build the container on Alpine 3.13 or 3.14 without the patch. I did not anticipate that effect of the patch would penetrate the container, but I can see how it could.
I'm not inclined to back off back to 3.12, though. As your link points out, newer versions of Grafana and Mosquitto are affected in the same way, and I'm sure the other tools mentioned will soon follow. We're all in the same boat. So, I'm going to incorporate this step into the installation instructions for docker container users on Raspbian Buster.