WebThingsIO / gateway

WebThings Gateway - a self-hosted web application for monitoring and controlling a building over the web
http://webthings.io/gateway
Mozilla Public License 2.0
2.62k stars 339 forks source link

[Snap] Latest edge build of snap failing to start #3171

Closed benfrancis closed 1 month ago

benfrancis commented 1 month ago

Automatic edge builds of the snap are now happening on snapcraft.io on GitHub commits (at least for AMD64), but the application doesn't appear to start up successfully after installation.

STR:

Expected:

Actual:

$ sudo journalctl -fu snap.webthings-gateway.webthings-gateway.service
Oct 02 17:59:44 ubuntu webthings-gateway.webthings-gateway[2274]: npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
Oct 02 17:59:44 ubuntu webthings-gateway.webthings-gateway[2274]: npm ERR! A complete log of this run can be found in:
Oct 02 17:59:44 ubuntu webthings-gateway.webthings-gateway[2274]: npm ERR!     /root/snap/webthings-gateway/3/.npm/_logs/2024-10-02T17_59_44_193Z-debug.log
Oct 02 17:59:44 ubuntu systemd[1]: snap.webthings-gateway.webthings-gateway.service: Main process exited, code=exited, status=1/FAILURE
Oct 02 17:59:44 ubuntu systemd[1]: snap.webthings-gateway.webthings-gateway.service: Failed with result 'exit-code'.
Oct 02 17:59:44 ubuntu systemd[1]: snap.webthings-gateway.webthings-gateway.service: Scheduled restart job, restart counter is at 5.
Oct 02 17:59:44 ubuntu systemd[1]: Stopped Service for snap application webthings-gateway.webthings-gateway.
Oct 02 17:59:44 ubuntu systemd[1]: snap.webthings-gateway.webthings-gateway.service: Start request repeated too quickly.
Oct 02 17:59:44 ubuntu systemd[1]: snap.webthings-gateway.webthings-gateway.service: Failed with result 'exit-code'.
Oct 02 17:59:44 ubuntu systemd[1]: Failed to start Service for snap application webthings-gateway.webthings-gateway.
# sudo cat /root/snap/webthings-gateway/3/.npm/_logs/2024-10-02T17_59_44_193Z-debug.log
0 info it worked if it ends with ok
1 verbose cli [ '/snap/webthings-gateway/3/bin/node',
1 verbose cli   '/snap/webthings-gateway/3/bin/npm',
1 verbose cli   '--prefix',
1 verbose cli   '/snap/webthings-gateway/3/lib/node_modules/webthings-gateway',
1 verbose cli   'run',
1 verbose cli   'run-only' ]
2 info using npm@6.14.12
3 info using node@v10.24.1
4 verbose run-script [ 'prerun-only', 'run-only', 'postrun-only' ]
5 info lifecycle webthings-gateway@1.2.0-alpha.1~prerun-only: webthings-gateway@1.2.0-alpha.1
6 info lifecycle webthings-gateway@1.2.0-alpha.1~run-only: webthings-gateway@1.2.0-alpha.1
7 verbose lifecycle webthings-gateway@1.2.0-alpha.1~run-only: unsafe-perm in lifecycle true
8 verbose lifecycle webthings-gateway@1.2.0-alpha.1~run-only: PATH: /snap/webthings-gateway/3/lib/node_modules/npm/node_modules/npm-lifecycle/node-gyp-bin:/snap/webthings-gateway/3/lib/node_modules/webthings-gateway/node_modules/.bin:/snap/webthings-gateway/3/lib/node_modules/.bin:/snap/webthings-gateway/3/usr/sbin:/snap/webthings-gateway/3/usr/bin:/snap/webthings-gateway/3/sbin:/snap/webthings-gateway/3/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games
9 verbose lifecycle webthings-gateway@1.2.0-alpha.1~run-only: CWD: /snap/webthings-gateway/3/lib/node_modules/webthings-gateway
10 silly lifecycle webthings-gateway@1.2.0-alpha.1~run-only: Args: [ '-c', 'node build/app.js' ]
11 silly lifecycle webthings-gateway@1.2.0-alpha.1~run-only: Returned: code: 1  signal: null
12 info lifecycle webthings-gateway@1.2.0-alpha.1~run-only: Failed to exec run-only script
13 verbose stack Error: webthings-gateway@1.2.0-alpha.1 run-only: `node build/app.js`
13 verbose stack Exit status 1
13 verbose stack     at EventEmitter.<anonymous> (/snap/webthings-gateway/3/lib/node_modules/npm/node_modules/npm-lifecycle/index.js:332:16)
13 verbose stack     at EventEmitter.emit (events.js:198:13)
13 verbose stack     at ChildProcess.<anonymous> (/snap/webthings-gateway/3/lib/node_modules/npm/node_modules/npm-lifecycle/lib/spawn.js:55:14)
13 verbose stack     at ChildProcess.emit (events.js:198:13)
13 verbose stack     at maybeClose (internal/child_process.js:982:16)
13 verbose stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:259:5)
14 verbose pkgid webthings-gateway@1.2.0-alpha.1
15 verbose cwd /var/snap/webthings-gateway/3
16 verbose Linux 5.15.0-121-generic
17 verbose argv "/snap/webthings-gateway/3/bin/node" "/snap/webthings-gateway/3/bin/npm" "--prefix" "/snap/webthings-gateway/3/lib/node_modules/webthings-gateway" "run" "run-only"
18 verbose node v10.24.1
19 verbose npm  v6.14.12
20 error code ELIFECYCLE
21 error errno 1
22 error webthings-gateway@1.2.0-alpha.1 run-only: `node build/app.js`
22 error Exit status 1
23 error Failed at the webthings-gateway@1.2.0-alpha.1 run-only script.
23 error This is probably not a problem with npm. There is likely additional logging output above.
24 verbose exit [ 1, true ]
benfrancis commented 1 month ago

@ogra1 FYI

benfrancis commented 1 month ago

I note that local builds of the snap are also broken on master and showing the same errors.

dilyn-corner commented 1 month ago

I think I managed to reproduce the issue; when running I found this:

NPM_CONFIG_LOGLEVEL=verbose npm --prefix $SNAP/lib/node_modules/webthings-gateway/ run run-only
npm info it worked if it ends with ok
npm verb cli [ '/snap/webthings-gateway/x1/bin/node',
npm verb cli   '/snap/webthings-gateway/x1/bin/npm',
npm verb cli   '--prefix',
npm verb cli   '/snap/webthings-gateway/x1/lib/node_modules/webthings-gateway/',
npm verb cli   'run',
npm verb cli   'run-only' ]
npm info using npm@6.14.12
npm info using node@v10.24.1
npm verb run-script [ 'prerun-only', 'run-only', 'postrun-only' ]
npm info lifecycle webthings-gateway@1.2.0-alpha.1~prerun-only: webthings-gateway@1.2.0-alpha.1
npm info lifecycle webthings-gateway@1.2.0-alpha.1~run-only: webthings-gateway@1.2.0-alpha.1

> webthings-gateway@1.2.0-alpha.1 run-only /snap/webthings-gateway/x1/lib/node_modules/webthings-gateway
> node build/app.js

Opening database: /root/snap/webthings-gateway/x1/.webthings/config/db.sqlite3
/snap/webthings-gateway/x1/lib/node_modules/webthings-gateway/node_modules/winston-transport/node_modules/readable-stream/lib/ours/util.js:5
const AbortSignal = globalThis.AbortSignal || require('abort-controller').AbortSignal
                    ^

ReferenceError: globalThis is not defined

globalThis wasn't introduced until Node 12, but npm-node-version is set to 10.24.1? I bumped it to 12.22.1, and the application appears to at least get beyond immediate failure:

snap install --dangerous webthings-gateway_2.0.0_amd64.snap ; snap logs -f webthings-gateway
webthings-gateway 2.0.0 installed
2024-10-08T19:25:52Z systemd[1]: Started Service for snap application webthings-gateway.webthings-gateway.
2024-10-08T19:25:54Z webthings-gateway.webthings-gateway[1856]: > webthings-gateway@1.2.0-alpha.1 run-only /snap/webthings-gateway/x1/lib/node_modules/webthings-gateway
2024-10-08T19:25:54Z webthings-gateway.webthings-gateway[1856]: > node build/app.js
2024-10-08T19:25:54Z webthings-gateway.webthings-gateway[1908]: Creating database: /root/snap/webthings-gateway/x1/.webthings/config/db.sqlite3
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.385 INFO   : Creating database: /root/snap/webthings-gateway/x1/.webthings/log/logs.sqlite3
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.401 INFO   : HTTP server listening on port 8080
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.468 DEBUG  : Ignoring https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/schema.json because it has no messageType
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.702 DEBUG  : Ignoring https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json because it has no messageType
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.730 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.735 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.740 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.787 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.848 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.852 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.856 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.884 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.887 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.890 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.917 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.920 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:25:55Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:25:55.923 WARN   : strict mode: missing type "object" for keyword "properties" at "https://raw.githubusercontent.com/WebThingsIO/gateway-addon-ipc-schema/master/messages/definitions.json#/allOf/1" (strictTypes)
2024-10-08T19:26:06Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:26:06.253 INFO   : Checking for add-on updates...
2024-10-08T19:26:07Z webthings-gateway.webthings-gateway[1908]: 2024-10-08 19:26:07.364 INFO   : Finished updating add-ons

ETA: just checked the content on port 8080, the web application is indeed running (I see some login screen). Uncertain if anything broke under the covers, but that's an idea :)

dilyn-corner commented 1 month ago

Here are three patches closing #3171 and #3167.

Sometimes npm will fail to be installed during iterative builds, I can't quite identify why that's happening but I'll pester the snapcraft folx this week to see if they have ideas :)

From b9c0d88a2bb21dfc35e1ed9378f2d175b19c671f Mon Sep 17 00:00:00 2001
From: Dilyn Corner <dilyn.corner@canonical.com>
Date: Tue, 8 Oct 2024 16:20:12 -0400
Subject: [PATCH 1/3] snapcraft.yaml: bump node version to support globalThis

Signed-off-by: Dilyn Corner <dilyn.corner@canonical.com>
---
 snap/snapcraft.yaml | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/snap/snapcraft.yaml b/snap/snapcraft.yaml
index 65b2ab26..c5db9a09 100644
--- a/snap/snapcraft.yaml
+++ b/snap/snapcraft.yaml
@@ -28,7 +28,7 @@ parts:
     source: https://github.com/WebThingsIO/gateway.git
     after: [ python-deps ]
     npm-include-node: true
-    npm-node-version: 10.24.1
+    npm-node-version: 12.22.1
     build-environment:
       - npm_config_unsafe_perm: "true"
       - NODE_ENV: "dev"
-- 
2.40.1

From 5a8041812b6fb9b5b5124f21ede6b1e2ea92dc73 Mon Sep 17 00:00:00 2001
From: Dilyn Corner <dilyn.corner@canonical.com>
Date: Tue, 8 Oct 2024 16:20:53 -0400
Subject: [PATCH 2/3] snapcraft.yaml: switch autoconf to automake

automake requires autoconf, and most systems using autotools require both

Signed-off-by: Dilyn Corner <dilyn.corner@canonical.com>
---
 snap/snapcraft.yaml | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/snap/snapcraft.yaml b/snap/snapcraft.yaml
index c5db9a09..cd42cc14 100644
--- a/snap/snapcraft.yaml
+++ b/snap/snapcraft.yaml
@@ -34,7 +34,7 @@ parts:
       - NODE_ENV: "dev"
       - CPPFLAGS: "$CPPFLAGS -DPNG_ARM_NEON_OPT=0"
     build-packages:
-      - autoconf
+      - automake
       - build-essential
       - libbluetooth-dev
       - libboost-python-dev
-- 
2.40.1

From 29263338465c46262e3c11f3b922f4ad1f46d7be Mon Sep 17 00:00:00 2001
From: Dilyn Corner <dilyn.corner@canonical.com>
Date: Tue, 8 Oct 2024 16:21:25 -0400
Subject: [PATCH 3/3] snapcraft.yaml: identical files should not fail cp

cp will bail just in case source=dest, and in that case we do not care
if dest is overwritten.

Signed-off-by: Dilyn Corner <dilyn.corner@canonical.com>
---
 snap/snapcraft.yaml | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/snap/snapcraft.yaml b/snap/snapcraft.yaml
index cd42cc14..ffaa37e0 100644
--- a/snap/snapcraft.yaml
+++ b/snap/snapcraft.yaml
@@ -48,7 +48,7 @@ parts:
       craftctl default
       npm install --only-dev
       npm run-script build
-      cp -av build $CRAFT_PART_INSTALL/lib/node_modules/webthings-gateway/
+      cp -avf build $CRAFT_PART_INSTALL/lib/node_modules/webthings-gateway/
       # fix wrongly hardcoded /usr/bin/python interpreter in pagekite
       if [ -e $CRAFT_PART_INSTALL/lib/node_modules/webthings-gateway/pagekite.py ]; then
         sed -i 's;#!.*;#! /usr/bin/env python3;' \
-- 
2.40.1
benfrancis commented 1 month ago

Hi @dilyn-corner, thank you very much for looking into these issues.

I will test your patches properly tomorrow, but in the meantime I'll leave some comments below.

BTW these patches would be more useful as pull requests if you're able to create them.

globalThis wasn't introduced until Node 12, but npm-node-version is set to 10.24.1? I bumped it to 12.22.1, and the application appears to at least get beyond immediate failure:

WebThings Gateway definitely usually runs under Node.js 10. Dubnium LTS is the version defined in .nvmrc, which is currently used for installing Node.js for all distribution methods except the new snap. The reason WebThings Gateway is currently stuck on Node.js 10 is because the current OS images deployed in the field are built on Raspbian Buster, which doesn't support newer versions. For WebThings Gateway 2.0 (which is what the snap and Ubuntu Core based OS image will eventually ship, but won't be pushed out automatically to Raspbian Buster based systems) I'm in the process of upgrading from Node.js 10 to Node.js 20 (the current LTS release), but that is going to be a bit of a long process. This is really a long way of saying that it shouldn't be necessary to upgrade Node.js from version 10 to version 12 to get the snap to build, because the snap was building locally with Node.js 10 before without a problem.

Might there be a reason that local builds of the snap with Node.js 10 were working fine, but remote builds on snapcraft.io are somehow different?

automake requires autoconf, and most systems using autotools require both

OK thanks, I will try this.

cp will bail just in case source=dest, and in that case we do not care if dest is overwritten.

I'm assuming this is intended to fix an error which I also encountered with local builds of the snap. In that case I found that when I started from a fresh git checkout the error went away. Whilst I am OK with the proposed fix, I would prefer to understand the cause of this error. It could be something as simple as the build directory already existing.

Thanks again and I'll take another look at these patches tomorrow, hopefully in PR form.

dilyn-corner commented 1 month ago

Sure, can do.