ERR_SOCKET_TIMEOUT when running "npm ci" using a Raspberry Pi v1

[swinster]

Hey,

I suspect this has nothing to do with zigbee2mqtt directly, but when installing using the Linux instruction on a Raspberry Pi v1, when issuing the npm ci command, the installation fails with a ERR_SOCKET_TIMEOUT error. The last lines of the log are:

2498 timing command:ci Completed in 2981510ms
2499 verbose type system
2500 verbose stack FetchError: request to https://registry.npmjs.org/delegates/-/delegates-1.0.0.tgz failed, reason: Socket timeout
2500 verbose stack     at ClientRequest.<anonymous> (/usr/share/nodejs/npm/node_modules/minipass-fetch/lib/index.js:97:14)
2500 verbose stack     at ClientRequest.emit (events.js:314:20)
2500 verbose stack     at TLSSocket.socketErrorListener (_http_client.js:427:9)
2500 verbose stack     at TLSSocket.emit (events.js:326:22)
2500 verbose stack     at emitErrorNT (internal/streams/destroy.js:92:8)
2500 verbose stack     at emitErrorAndCloseNT (internal/streams/destroy.js:60:3)
2500 verbose stack     at processTicksAndRejections (internal/process/task_queues.js:84:21)
2501 verbose cwd /opt/zigbee2mqtt
2502 verbose Linux 5.15.32+
2503 verbose argv "/usr/bin/node" "/usr/bin/npm" "ci"
2504 verbose node v12.22.5
2505 verbose npm  v7.5.2
2506 error code ERR_SOCKET_TIMEOUT
2507 error errno ERR_SOCKET_TIMEOUT
2508 error request to https://registry.npmjs.org/delegates/-/delegates-1.0.0.tgz failed, reason: Socket timeout
2509 verbose exit 1

Running npm ci again general stalls and gets automatically killed after some time.

I have very little knowledge of the npm, but running npm info gives:

pi@raspberrypi:/opt/zigbee2mqtt $ npm info

zigbee2mqtt@1.25.1 | GPL-3.0 | deps: 27 | versions: 36
Zigbee to MQTT bridge using Zigbee-herdsman
https://koenkk.github.io/zigbee2mqtt

keywords: xiaomi, tradfri, hue, bridge, zigbee, mqtt, cc2531

bin: zigbee2mqtt

dist
.tarball: https://registry.npmjs.org/zigbee2mqtt/-/zigbee2mqtt-1.25.1.tgz
.shasum: 55e6d6176a010c94a0e1228da71fa23b826b2bb5
.integrity: sha512-dEx3Mkl4N2GfLbkIQGt/mz+S6vujyh2lNCjeUyDS6J75elriHa7ZP7wtX3yVequGxrAH/C2zoX0LZzT2a3q5sg==
.unpackedSize: 1.7 MB

dependencies:
ajv: ^8.11.0                                  git-last-commit: ^1.0.1                       rimraf: ^3.0.2                                
bind-decorator: ^1.0.11                       humanize-duration: ^3.27.1                    semver: ^7.3.7                                
connect-gzip-static: ^2.1.1                   js-yaml: ^4.1.0                               source-map-support: ^0.5.21                   
core-js: ^3.22.2                              json-stable-stringify-without-jsonify: ^1.0.1 uri-js: ^4.4.1                                
debounce: ^1.2.1                              mkdir-recursive: ^0.4.0                       winston-syslog: ^2.5.0                        
deep-object-diff: ^1.1.7                      moment: ^2.29.3                               winston-transport: ^4.5.0                     
fast-deep-equal: ^3.1.3                       mqtt: 4.3.7                                   winston: ^3.7.2                               
finalhandler: ^1.2.0                          object-assign-deep: ^0.4.0                    ws: ^8.5.0                                    
(...and 3 more.)

maintainers:
- koenkk <koenkanters94@gmail.com>
- x-dark <x-dark.npm@valinor.fr>

dist-tags:
latest: 1.25.1  

published yesterday by koenkk <koenkanters94@gmail.com>

And running npm up also ended with an ERR_SOCKET_TIMEOUT error, but this time for a different file.

npm ERR! code ERR_SOCKET_TIMEOUT
npm ERR! request to https://registry.npmjs.org/@babel/types/-/types-7.17.10.tgz failed, reason: Socket timeout

I guess the Pi is struggling with the network, although it's wired and should be OK.

Any ideas on how to get this to complete?

[swinster]

Update:

running npm up again appeared to complete (I think)...

pi@raspberrypi:/opt/zigbee2mqtt $ npm up
[..................] | idealTree:zigbee2mqtt: sill idealTree buildDeps
[..................] | idealTree:zigbee2mqtt-frontend: sill fetch manifest tar-stream@^2.2.0

added 2 packages, removed 6 packages, changed 33 packages, and audited 823 packages in 28m

77 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities

[Koenkk]

FetchError: request to https://registry.npmjs.org/delegates/-/delegates-1.0.0.tgz failed, reason: Socket timeout

Looks like your device cannot connect to the npm repositories, either an issue at npm, or something wrong with your internet.

[swinster]

I have seen some commentary on the npm GitHub with others having the same issue but with different projects (see npm/cli#3078). There were supposed to be some fixes that would help but not sure if these are part of this build.

I think they were talking about being better at handling these situations. In my case, it might be something to do with this being a Raspberry Pi v1 as the network and internet connection should be pretty good.

However, I wonder, now that I have run npm up a couple of times and ended up with what looks like a reasonable report, I guessing that this should now be all ok?

[Koenkk]

If z2m starts correctly I wouldn't worry about it.

[swinster]

Unfortunately not :(

pi@raspberrypi:/opt/zigbee2mqtt $ npm start

> zigbee2mqtt@1.25.1 start
> node index.js

internal/modules/cjs/loader.js:818
  throw err;
  ^

Error: Cannot find module 'source-map-support'
Require stack:
- /opt/zigbee2mqtt/index.js
    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:815:15)
    at Function.Module._load (internal/modules/cjs/loader.js:667:27)
    at Module.require (internal/modules/cjs/loader.js:887:19)
    at require (internal/modules/cjs/helpers.js:74:18)
    at Object.<anonymous> (/opt/zigbee2mqtt/index.js:11:1)
    at Module._compile (internal/modules/cjs/loader.js:999:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1027:10)
    at Module.load (internal/modules/cjs/loader.js:863:32)
    at Function.Module._load (internal/modules/cjs/loader.js:708:14)
    at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:60:12) {
  code: 'MODULE_NOT_FOUND',
  requireStack: [ '/opt/zigbee2mqtt/index.js' ]
}
npm ERR! code 1
npm ERR! path /opt/zigbee2mqtt
npm ERR! command failed
npm ERR! command sh -c node index.js

npm ERR! A complete log of this run can be found in:
npm ERR!     /home/pi/.npm/_logs/2022-05-11T22_45_42_532Z-debug.log

And the content of that log file are:

pi@raspberrypi:/opt/zigbee2mqtt $ cat /home/pi/.npm/_logs/2022-05-11T22_45_42_532Z-debug.log
0 verbose cli [ '/usr/bin/node', '/usr/bin/npm', 'start' ]
1 info using npm@7.5.2
2 info using node@v12.22.5
3 timing config:load:defaults Completed in 90ms
4 timing config:load:file:/usr/share/nodejs/npm/npmrc Completed in 72ms
5 timing config:load:builtin Completed in 77ms
6 timing config:load:cli Completed in 88ms
7 timing config:load:env Completed in 12ms
8 timing config:load:file:/opt/zigbee2mqtt/.npmrc Completed in 19ms
9 timing config:load:project Completed in 50ms
10 timing config:load:file:/home/pi/.npmrc Completed in 7ms
11 timing config:load:user Completed in 9ms
12 timing config:load:file:/etc/npmrc Completed in 3ms
13 timing config:load:global Completed in 6ms
14 timing config:load:cafile Completed in 9ms
15 timing config:load:validate Completed in 26ms
16 timing config:load:setUserAgent Completed in 17ms
17 timing config:load:setEnvs Completed in 45ms
18 timing config:load Completed in 439ms
19 verbose npm-session 9b36322ccd314eb2
20 timing npm:load Completed in 836ms
21 timing command:run-script Completed in 8560ms
22 timing command:start Completed in 8650ms
23 verbose stack Error: command failed
23 verbose stack     at ChildProcess.<anonymous> (/usr/share/nodejs/@npmcli/promise-spawn/index.js:64:27)
23 verbose stack     at ChildProcess.emit (events.js:314:20)
23 verbose stack     at maybeClose (internal/child_process.js:1022:16)
23 verbose stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:287:5)
24 verbose pkgid zigbee2mqtt@1.25.1
25 verbose cwd /opt/zigbee2mqtt
26 verbose Linux 5.15.32+
27 verbose argv "/usr/bin/node" "/usr/bin/npm" "start"
28 verbose node v12.22.5
29 verbose npm  v7.5.2
30 error code 1
31 error path /opt/zigbee2mqtt
32 error command failed
33 error command sh -c node index.js
34 verbose exit 1

[swinster]

Hmm, even manually installing the missing source-map-support module doesn't seem to help

The install seems fine, but it still fails to find the module!

pi@raspberrypi:~ $ npm install source-map-support

added 3 packages, and audited 4 packages in 23s

found 0 vulnerabilities
pi@raspberrypi:~ $ cd /opt/zigbee2mqtt
pi@raspberrypi:/opt/zigbee2mqtt $ npm start


> zigbee2mqtt@1.25.1 start
> node index.js

internal/modules/cjs/loader.js:818
  throw err;
  ^

Error: Cannot find module 'source-map-support'
Require stack:
- /opt/zigbee2mqtt/index.js
    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:815:15)
    at Function.Module._load (internal/modules/cjs/loader.js:667:27)
    at Module.require (internal/modules/cjs/loader.js:887:19)
    at require (internal/modules/cjs/helpers.js:74:18)
    at Object.<anonymous> (/opt/zigbee2mqtt/index.js:11:1)
    at Module._compile (internal/modules/cjs/loader.js:999:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1027:10)
    at Module.load (internal/modules/cjs/loader.js:863:32)
    at Function.Module._load (internal/modules/cjs/loader.js:708:14)
    at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:60:12) {
  code: 'MODULE_NOT_FOUND',
  requireStack: [ '/opt/zigbee2mqtt/index.js' ]
}
npm ERR! code 1
npm ERR! path /opt/zigbee2mqtt
npm ERR! command failed
npm ERR! command sh -c node index.js

npm ERR! A complete log of this run can be found in:
npm ERR!     /home/pi/.npm/_logs/2022-05-12T06_36_59_236Z-debug.log

Log file is the same as above.

[Koenkk]

Not sure how this can be fixed, looks to be an issue with internet on your computer.

[Impact123]

Looks like you ran npm install source-map-support outside of the /opt/zigbee2mqtt directory

[swinster]

@Koenkk hmm, there really is nothing worn with the network/Internet in general. Surely there has to be a way to re-install or download files to be cached locally?

@Impact123 - not sure if this is true. I just re-ran the npm install source-map-support in the required directory, which say all is good yet the error persists:

pi@raspberrypi:/opt/zigbee2mqtt $ npm install source-map-support

up to date, audited 823 packages in 1m

77 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities
pi@raspberrypi:/opt/zigbee2mqtt $ 
pi@raspberrypi:/opt/zigbee2mqtt $ npm start

> zigbee2mqtt@1.25.1 start
> node index.js

internal/modules/cjs/loader.js:818
  throw err;
  ^

Error: Cannot find module 'source-map-support'
Require stack:
- /opt/zigbee2mqtt/index.js
    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:815:15)
    at Function.Module._load (internal/modules/cjs/loader.js:667:27)
    at Module.require (internal/modules/cjs/loader.js:887:19)
    at require (internal/modules/cjs/helpers.js:74:18)
    at Object.<anonymous> (/opt/zigbee2mqtt/index.js:11:1)
    at Module._compile (internal/modules/cjs/loader.js:999:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1027:10)
    at Module.load (internal/modules/cjs/loader.js:863:32)
    at Function.Module._load (internal/modules/cjs/loader.js:708:14)
    at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:60:12) {
  code: 'MODULE_NOT_FOUND',
  requireStack: [ '/opt/zigbee2mqtt/index.js' ]
}
npm ERR! code 1
npm ERR! path /opt/zigbee2mqtt
npm ERR! command failed
npm ERR! command sh -c node index.js

npm ERR! A complete log of this run can be found in:
npm ERR!     /home/pi/.npm/_logs/2022-05-12T22_28_36_004Z-debug.log

[Koenkk]

Since you are running node 12, can you try updating to 16?

[swinster]

OK. I think I'm actually getting somewhere :). However, I'm not there yet :(.

Node.js > v12 running the older Raspberry Pi's (based on the AMR v6 architecture) is no longer officially part of the main builds. It was moved to an experimental branch (see https://github.com/nodejs/unofficial-builds#user-content-builds - linux-armv6l). This means that the Zigbee2MQTT installation instructions for Linux (https://www.zigbee2mqtt.io/guide/installation/01_linux.html#installing) don't quite work for this architecture :(. The line:

sudo apt-get install -y nodejs npm git make g++ gcc

Installs the lower versions.

It would be great if you could add a note here for older Pi users to NOT install nodejs or npm from the default repositories using apt-get.

Instead, these users should install nodejs/npm directly from the binaries.

Using these instructions (https://gist.github.com/davps/6c6e0ba59d023a9e3963cea4ad0fb516) I was able to install the latest LTS version of nodejs (v16.15) and npm, although npm itelf also need to be upgraded (to v8.10).

To determine the Pi architecture, run uname -m. On the model B+, we can see its armv6l

pi@raspberrypi:/opt/zigbee2mqtt $ uname -m
armv6l

In which case, grab that nodejs binaries from the unofficial builds site (currently 16.15 - see https://unofficial-builds.nodejs.org/download/release/v16.15.0/):

wget https://unofficial-builds.nodejs.org/download/release/v16.15.0/node-v16.15.0-linux-armv6l.tar.gz 
tar -xzf node-v16.15.0-linux-armv6l.tar.gz
cd node-v16.15.0-linux-armv6l/
sudo cp -R * /usr/local/

And just to be sure, I updated npm to the latest version:

sudo npm install -g npm@latest

Check the versions to be sure:

pi@raspberrypi:/opt/zigbee2mqtt $ node -v && npm -v
v16.15.0
8.10.0

Note, the npm that was available before updating to the latest version was v8.5.5. This version still had the issue when the network socket would timeout. I'm not sure why this happens. Perhaps it's a NIC setting on the Pi, but the weird thing is that other network related tasks (such as curl, get or even updating the OS) are completed quickly and without issue. Npm, however, is very slow and times out. Version 8.10 of npm does seem to behave better and running npm ci got towards the end (albeit npm is still REALLY slow, like a couple of hours slow on this Pi), but I then ended up with another Fetch Error, this time a Client network socket disconnected before secure TLS connection was establishe error:

Here is the last line of the log:

2502 http fetch GET 200 https://registry.npmjs.org/typescript/-/typescript-4.6.4.tgz 5702108ms (cache miss)
2503 timing reifyNode:node_modules/typescript Completed in 5738411ms
2504 timing reify:rollback:createSparse Completed in 160355ms
2505 timing reify:rollback:retireShallow Completed in 3ms
2506 timing command:ci Completed in 5944771ms
2507 verbose type system
2508 verbose stack FetchError: request to https://registry.npmjs.org/color-name/-/color-name-1.1.4.tgz failed, reason: Client network socket disconnected before secure TLS connection was established
2508 verbose stack     at ClientRequest.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/minipass-fetch/lib/index.js:130:14)
2508 verbose stack     at ClientRequest.emit (node:events:527:28)
2508 verbose stack     at TLSSocket.socketErrorListener (node:_http_client:454:9)
2508 verbose stack     at TLSSocket.emit (node:events:539:35)
2508 verbose stack     at emitErrorNT (node:internal/streams/destroy:157:8)
2508 verbose stack     at emitErrorCloseNT (node:internal/streams/destroy:122:3)
2508 verbose stack     at processTicksAndRejections (node:internal/process/task_queues:83:21)
2509 verbose cwd /opt/zigbee2mqtt
2510 verbose Linux 5.15.32+
2511 verbose node v16.15.0
2512 verbose npm  v8.10.0
2513 error code ECONNRESET
2514 error errno ECONNRESET
2515 error network request to https://registry.npmjs.org/color-name/-/color-name-1.1.4.tgz failed, reason: Client network socket disconnected before secure TLS connection was established
2516 error network This is a problem related to network connectivity.
2516 error network In most cases you are behind a proxy or have bad network settings.
2516 error network
2516 error network If you are behind a proxy, please make sure that the
2516 error network 'proxy' config is set properly.  See: 'npm help config'
2517 verbose exit 1
2518 timing npm Completed in 5950278ms
2519 verbose unfinished npm timer reify 1652438379317
2520 verbose unfinished npm timer reify:unpack 1652438391931
2521 verbose unfinished npm timer reifyNode:node_modules/eslint/node_modules/color-name 1652438394202
2522 verbose unfinished npm timer reifyNode:node_modules/eslint/node_modules/color-convert 1652438394205
2523 verbose unfinished npm timer reifyNode:node_modules/cliui 1652438394516
2524 verbose unfinished npm timer reifyNode:node_modules/babel-plugin-jest-hoist 1652438394647
2525 verbose unfinished npm timer reifyNode:node_modules/@babel/plugin-proposal-async-generator-functions 1652438395576
2526 verbose unfinished npm timer reifyNode:node_modules/@babel/generator 1652438395719
2527 verbose code 1
2528 error A complete log of this run can be found in:
2528 error     /home/pi/.npm/_logs/2022-05-13T10_39_03_016Z-debug-0.log

However, running wget on the file worked with no issue:

pi@raspberrypi:/opt/zigbee2mqtt $ wget https://registry.npmjs.org/color-name/-/color-name-1.1.4.tgz
--2022-05-13 13:21:46--  https://registry.npmjs.org/color-name/-/color-name-1.1.4.tgz
Resolving registry.npmjs.org (registry.npmjs.org)... 104.16.20.35, 104.16.26.35, 104.16.23.35, ...
Connecting to registry.npmjs.org (registry.npmjs.org)|104.16.20.35|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 2868 (2.8K) [application/octet-stream]
Saving to: ‘color-name-1.1.4.tgz’

color-name-1.1.4.tgz                100%[=================================================================>]   2.80K  --.-KB/s    in 0.002s  

2022-05-13 13:21:46 (1.50 MB/s) - ‘color-name-1.1.4.tgz’ saved [2868/2868]

So, for the moment, I'm still stuck. There is NO HTTP proxy involved here, and nothing weird (that I know of) about the network.

[Komsomol]

Thanks. Ran into the same issue with another npm package. Your insights helped.

[swinster]

OK, after 3 weeks+ of trying simply to install Zigbee2MQTT, I finally have a running system. Npm finally completed and will now start. 🎉 .

FWIW, others are still seeing similar issues with npm. I ran a PCAP during an install process and it was clear that most of the TLS connection resets came from the npm registry servers immediately after the npm client sent a TLS Client Hello. I'm not sure if this is as designed, either on the client or server side, but I did follow up in a separate npm issue in their repo.

I tried to reduce the number of concurrent sockets the npm client used (using the --maxsockets x parameter), but after an npm ci failure, the process simply timed out and was killed automatically by the OS. I found I had to clear the npm cache, then re-run npm ci:

pi@raspberrypi:/opt/zigbee2mqtt $ npm cache clean -f                                           
npm WARN using --force Recommended protections disabled.

pi@raspberrypi:/opt/zigbee2mqtt $ npm ci  --noproxy registry.npmjs.org --maxsockets 1          

added 821 packages, and audited 822 packages in 29m

77 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities

And finally:

pi@raspberrypi:/opt/zigbee2mqtt $ npm start

> zigbee2mqtt@1.25.1 start
> node index.js

Building Zigbee2MQTT... (initial build), finished
Zigbee2MQTT:info  2022-05-14 09:04:47: Logging to console and directory: '/opt/zigbee2mqtt/data/log/2022-05-14.09-04-24' filename: log.txt
Zigbee2MQTT:info  2022-05-14 09:04:48: Starting Zigbee2MQTT version 1.25.1 (commit #3f6a1378)
Zigbee2MQTT:info  2022-05-14 09:04:49: Starting zigbee-herdsman (0.14.27)
Zigbee2MQTT:info  2022-05-14 09:05:26: zigbee-herdsman started (reset)
Zigbee2MQTT:info  2022-05-14 09:05:26: Coordinator firmware version: '{"meta":{"maintrel":1,"majorrel":2,"minorrel":7,"product":1,"revision":20210708,"transportrev":2},"type":"zStack3x0"}'
Zigbee2MQTT:info  2022-05-14 09:05:26: Currently 0 devices are joined:
Zigbee2MQTT:warn  2022-05-14 09:05:26: `permit_join` set to  `true` in configuration.yaml.
Zigbee2MQTT:warn  2022-05-14 09:05:26: Allowing new devices to join.
Zigbee2MQTT:warn  2022-05-14 09:05:26: Set `permit_join` to `false` once you joined all devices.
Zigbee2MQTT:info  2022-05-14 09:05:26: Zigbee: allowing new devices to join.
Zigbee2MQTT:info  2022-05-14 09:05:27: Connecting to MQTT server at mqtt://localhost
Zigbee2MQTT:info  2022-05-14 09:05:29: Connected to MQTT server
Zigbee2MQTT:info  2022-05-14 09:05:29: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"online"}'
Zigbee2MQTT:info  2022-05-14 09:05:32: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"online"}'

I hope this might help someone else who thinks it would be a good idea to repurpose an old Raspbery Pi for this purpose.

[swinster]

Argh, I hit this issue again on the upgrade. I have a feeling this is more to do with the hardware (and Pi v1) rather than anything else. Since last time, the ISP has been changed which uses a completely different connection medium (now FTTP) with a bandwidth of 1 Gbps. I don't see anything odd with any other network device on my home network, so I can only point the finger at the old Pi.

I wonder if it would be good to add a note to the installation guide (https://www.zigbee2mqtt.io/guide/installation/01_linux.html#installing) and the upgrade guide (https://www.zigbee2mqtt.io/guide/installation/01_linux.html#for-later-update-zigbee2mqtt-to-the-latest-version) that npm may need some additional teaks when running on older hardware.

In this case on the upgrade, I only needed to reduce the maximum number of sockets:

npm ci  --maxsockets 1

[heisenberg2980]

@swinster you just saved my day!! After trying to install z2m in my raspberry pi 3 and hitting this ERR_SOCKET_TIMEOUT error again and again I found your post and your solution works as a charm. I will try to fork the repo with the z2m instalation instructions and add this for anyone else having this issue in the future when following the instructions