Electrs stuck - reading app logs (and identifying docker processes)

I am trying to determine why electrs is stuck in a state “Waiting for Bitcoin Node to finish syncing…”, so am wanting to review the electrs logs.

As I’ve read in the troubleshooting guide Umbrel Troubleshooting Guide sudo docker-compose logs electrs should achieve this.

This returns

ERROR: No such service: electrs

and running…

sudo docker-compose ps

returns:

  Name                 Command               State                            Ports
-------------------------------------------------------------------------------------------------------------
auth        docker-entrypoint.sh yarn  ...   Up      0.0.0.0:2000->2000/tcp
dashboard   docker-entrypoint.sh serve ...   Up      3004/tcp
manager     docker-entrypoint.sh yarn  ...   Up      3006/tcp
nginx       nginx -g daemon off;             Up      0.0.0.0:80->80/tcp
tor         tor                              Up      29050/tcp, 29051/tcp, 127.0.0.1:9050->9050/tcp, 9051/tcp

I’m confused that bitcoin and electrs are not showing in this list of processes although they show as installed on the UI. I’m successfully accessing bitcoin core from a wallet.

I found the UI export log function and have listed below. I still can’t see why electrs is stuck in this state.

I have removed and re added it a number of times and left it for weeks at a time and it never gets out of this state.

=====================
= Umbrel debug info =
=====================

Umbrel version
--------------
0.5.1

Memory usage
------------
              total        used        free      shared  buff/cache   available
Mem:           3.9G        1.4G        162M         29M        2.4G        2.2G
Swap:          6.0G        809M        5.2G

total: 35.2%
bitcoin: 18.9%
system: 11.5%
electrs: 4.2%
tor: 0.6%
lnd: 0%
electrs: 0%
bitcoin: 0%

Memory monitor logs
-------------------
2022-08-15 20:11:28 Memory monitor running!
2022-08-15 20:17:13 Memory monitor running!
2022-08-15 20:32:34 Memory monitor running!
2022-08-16 08:53:12 Memory monitor running!
2022-09-02 20:55:30 Memory monitor running!
2022-09-02 21:25:57 Memory monitor running!
2022-09-03 09:09:51 Memory monitor running!
2022-09-06 18:23:27 Memory monitor running!
2022-09-06 21:40:56 Memory monitor running!
2022-09-08 09:54:55 Memory monitor running!

Filesystem information
----------------------
Filesystem      Size  Used Avail Use% Mounted on
/dev/sda5       916G  583G  287G  68% /
/dev/sda5       916G  583G  287G  68% /

Karen logs
----------

Pulling app        ... extracting (95.1%)
Pulling app        ... extracting (95.9%)
Pulling app        ... extracting (96.6%)
Pulling app        ... extracting (97.4%)
Pulling app        ... extracting (98.1%)
Pulling app        ... extracting (98.9%)
Pulling app        ... extracting (99.7%)
Pulling app        ... extracting (100.0%)
Pulling app        ... pull complete
Pulling app        ... extracting (100.0%)
Pulling app        ... extracting (100.0%)
Pulling app        ... pull complete
Pulling app        ... digest: sha256:3dae686b22b1fdfd72...
Pulling app        ... status: downloaded newer image fo...
Pulling app        ... done
Starting app electrs...
Creating electrs_app_proxy_1 ... 
Creating electrs_electrs_1   ... 
Creating electrs_tor_server_1 ... 
Creating electrs_tor_server_1 ... done
Creating electrs_app_proxy_1  ... done
Creating electrs_electrs_1    ... done
Creating electrs_app_1        ... 
Creating electrs_app_1        ... done
Saving app electrs in DB...
Successfully installed app electrs
Got signal: backup
karen is getting triggered!
Deriving keys...
Creating backup...
Adding random padding...
1+0 records in
1+0 records out
4710 bytes (4.7 kB, 4.6 KiB) copied, 0.00041598 s, 11.3 MB/s
Creating encrypted tarball...
backup/
backup/.padding
Uploading backup...
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:02 --:--:--     0
100  5237    0     0  100  5237      0   1652  0:00:03  0:00:03 --:--:--  1653
100  5383  100   146  100  5237     37   1334  0:00:03  0:00:03 --:--:--  1371
100  5383  100   146  100  5237     37   1333  0:00:03  0:00:03 --:--:--  1370
{"message":"Successfully uploaded backup 1662649908976.tar.gz.pgp for backup ID aa92fc74d04e65e9689193dc8cd4a5a25131732168889268fd5c4d297844314a"}
=============================
====== Backup success =======
=============================
Got signal: change-password
karen is getting triggered!
This script must only be run on Umbrel OS
Got signal: debug
karen is getting triggered!

Docker containers
-----------------
NAMES                  STATUS
electrs_app_1          Up 8 hours
electrs_app_proxy_1    Up 8 hours
electrs_electrs_1      Restarting (1) 39 seconds ago
electrs_tor_server_1   Up 8 hours
bitcoin_server_1       Up 19 hours
bitcoin_app_proxy_1    Up 19 hours
bitcoin_bitcoind_1     Up 19 hours
bitcoin_tor_server_1   Up 19 hours
nginx                  Up 19 hours
manager                Up 19 hours
auth                   Up 19 hours
tor                    Up 19 hours
dashboard              Up 19 hours

Umbrel logs
-----------

Attaching to manager
manager      |     at Object.getAvailableUpdate (/app/logic/system.js:134:15)
manager      |     at runMicrotasks (<anonymous>)
manager      |     at processTicksAndRejections (internal/process/task_queues.js:97:5)
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:49 GMT] "GET /v1/system/get-update HTTP/1.0" 500 28 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:50 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:51 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:52 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:53 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:54 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:55 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:56 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Thu, 08 Sep 2022 19:19:57 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
manager      | 
manager      | umbrel-manager

Tor logs
--------

Attaching to tor
tor          | Sep 08 17:55:26.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 08 18:00:39.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 08 18:17:54.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 08 18:23:48.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 08 18:32:59.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 08 18:35:14.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 08 18:49:15.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 08 18:59:49.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 08 19:15:38.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.

App logs
--------

bitcoin

bitcoind_1    | 2022-09-08T19:04:05Z New outbound peer connected: version: 70016, blocks=753198, peer=277 (block-relay-only)
bitcoind_1    | 2022-09-08T19:05:25Z New outbound peer connected: version: 70016, blocks=753198, peer=278 (block-relay-only)
bitcoind_1    | 2022-09-08T19:09:05Z Socks5() connect to 2a0a:1c01:0:1410::99:8333 failed: general failure
tor_server_1  | Sep 07 23:55:57.000 [notice] Bootstrapped 100% (done): Done
tor_server_1  | Sep 08 01:20:31.000 [notice] No circuits are opened. Relaxed timeout for circuit 217 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
tor_server_1  | Sep 08 02:58:30.000 [notice] No circuits are opened. Relaxed timeout for circuit 409 (a Hidden service: Establishing introduction point 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
tor_server_1  | Sep 08 04:46:38.000 [notice] No circuits are opened. Relaxed timeout for circuit 674 (a Hidden service: Uploading HS descriptor 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [13 similar message(s) suppressed in last 6540 seconds]
tor_server_1  | Sep 08 05:55:18.000 [notice] Heartbeat: Tor's uptime is 6:00 hours, with 29 circuits open. I've sent 8.00 MB and received 10.34 MB. I've received 0 connections on IPv4 and 0 on IPv6. I've made 9 connections with IPv4 and 0 with IPv6.
tor_server_1  | Sep 08 05:55:18.000 [notice] While bootstrapping, fetched this many bytes: 614417 (consensus network-status fetch); 14096 (authority cert fetch); 5273189 (microdescriptor fetch)
tor_server_1  | Sep 08 05:55:18.000 [notice] While not bootstrapping, fetched this many bytes: 143990 (consensus network-status fetch); 69986 (microdescriptor fetch)
tor_server_1  | Sep 08 06:04:31.000 [notice] No circuits are opened. Relaxed timeout for circuit 804 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [5 similar message(s) suppressed in last 4680 seconds]
tor_server_1  | Sep 08 07:28:36.000 [notice] No circuits are opened. Relaxed timeout for circuit 987 (a Hidden service: Uploading HS descriptor 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [14 similar message(s) suppressed in last 5040 seconds]
tor_server_1  | Sep 08 08:29:27.000 [notice] No circuits are opened. Relaxed timeout for circuit 1299 (a Hidden service: Uploading HS descriptor 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [12 similar message(s) suppressed in last 3660 seconds]
tor_server_1  | Sep 08 10:40:31.000 [notice] No circuits are opened. Relaxed timeout for circuit 1488 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [3 similar message(s) suppressed in last 7920 seconds]
bitcoind_1    | 2022-09-08T19:15:38Z Socks5() connect to 106.69.94.169:8333 failed: general failure
tor_server_1  | Sep 08 11:55:18.000 [notice] Heartbeat: Tor's uptime is 12:00 hours, with 21 circuits open. I've sent 16.34 MB and received 14.60 MB. I've received 0 connections on IPv4 and 0 on IPv6. I've made 14 connections with IPv4 and 0 with IPv6.
tor_server_1  | Sep 08 11:55:18.000 [notice] While bootstrapping, fetched this many bytes: 614417 (consensus network-status fetch); 14096 (authority cert fetch); 5273189 (microdescriptor fetch)
tor_server_1  | Sep 08 11:55:18.000 [notice] While not bootstrapping, fetched this many bytes: 322158 (consensus network-status fetch); 147476 (microdescriptor fetch)
tor_server_1  | Sep 08 12:37:39.000 [notice] No circuits are opened. Relaxed timeout for circuit 1799 (a Hidden service: Establishing introduction point 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [41 similar message(s) suppressed in last 7080 seconds]
tor_server_1  | Sep 08 13:39:04.000 [notice] No circuits are opened. Relaxed timeout for circuit 1893 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [7 similar message(s) suppressed in last 3720 seconds]
tor_server_1  | Sep 08 15:44:50.000 [notice] No circuits are opened. Relaxed timeout for circuit 2383 (a Hidden service: Pre-built vanguard circuit 3-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [39 similar message(s) suppressed in last 7560 seconds]
tor_server_1  | Sep 08 17:22:33.000 [notice] No circuits are opened. Relaxed timeout for circuit 2613 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [17 similar message(s) suppressed in last 5880 seconds]
tor_server_1  | Sep 08 17:55:18.000 [notice] Heartbeat: Tor's uptime is 18:00 hours, with 40 circuits open. I've sent 26.58 MB and received 19.79 MB. I've received 0 connections on IPv4 and 0 on IPv6. I've made 21 connections with IPv4 and 0 with IPv6.
tor_server_1  | Sep 08 17:55:18.000 [notice] While bootstrapping, fetched this many bytes: 614417 (consensus network-status fetch); 14096 (authority cert fetch); 5273189 (microdescriptor fetch)
tor_server_1  | Sep 08 17:55:18.000 [notice] While not bootstrapping, fetched this many bytes: 508799 (consensus network-status fetch); 186887 (microdescriptor fetch)
tor_server_1  | Sep 08 18:23:24.000 [notice] No circuits are opened. Relaxed timeout for circuit 3009 (a Hidden service: Uploading HS descriptor 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [78 similar message(s) suppressed in last 3660 seconds]

electrs

tor_server_1  | Sep 08 11:24:26.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
tor_server_1  | Sep 08 11:24:26.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
tor_server_1  | Sep 08 11:24:27.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
tor_server_1  | Sep 08 11:24:32.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
tor_server_1  | Sep 08 11:24:33.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs
tor_server_1  | Sep 08 11:24:36.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
tor_server_1  | Sep 08 11:24:36.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6570, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
tor_server_1  | Sep 08 11:24:38.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6570, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
tor_server_1  | Sep 08 11:24:38.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 08 11:24:41.000 [notice] The current consensus contains exit nodes. Tor can build exit and internal paths.
tor_server_1  | Sep 08 11:24:57.000 [notice] Bootstrapped 56% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 08 11:25:01.000 [notice] Bootstrapped 63% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 08 11:25:04.000 [notice] Bootstrapped 68% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 08 11:25:05.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
tor_server_1  | Sep 08 11:25:05.000 [notice] Bootstrapped 80% (ap_conn): Connecting to a relay to build circuits
tor_server_1  | Sep 08 11:25:05.000 [notice] Bootstrapped 85% (ap_conn_done): Connected to a relay to build circuits
tor_server_1  | Sep 08 11:25:06.000 [notice] Bootstrapped 89% (ap_handshake): Finishing handshake with a relay to build circuits
tor_server_1  | Sep 08 11:25:06.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
tor_server_1  | Sep 08 11:25:06.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
tor_server_1  | Sep 08 11:25:08.000 [notice] Bootstrapped 100% (done): Done
tor_server_1  | Sep 08 13:36:48.000 [notice] Guard jonasBebe2 ($11ABDB4D0B944F186A898560CB82C70439957DCA) is failing more circuits than usual. Most likely this means the Tor network is overloaded. Success counts are 104/151. Use counts are 58/58. 125 circuits completed, 0 were unusable, 21 collapsed, and 5 timed out. For reference, your timeout cutoff is 60 seconds.
tor_server_1  | Sep 08 13:36:55.000 [notice] Guard mikrogravitation01 ($01759BAA5DE5FA19E36FADAF7D9BC64C15573ABC) is failing more circuits than usual. Most likely this means the Tor network is overloaded. Success counts are 111/159. Use counts are 57/57. 127 circuits completed, 0 were unusable, 16 collapsed, and 3 timed out. For reference, your timeout cutoff is 60 seconds.
tor_server_1  | Sep 08 13:37:44.000 [notice] No circuits are opened. Relaxed timeout for circuit 310 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
tor_server_1  | Sep 08 15:36:49.000 [notice] No circuits are opened. Relaxed timeout for circuit 497 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [14 similar message(s) suppressed in last 7200 seconds]
tor_server_1  | Sep 08 17:08:39.000 [notice] No circuits are opened. Relaxed timeout for circuit 601 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [16 similar message(s) suppressed in last 5520 seconds]
tor_server_1  | Sep 08 17:24:25.000 [notice] Heartbeat: Tor's uptime is 6:00 hours, with 18 circuits open. I've sent 6.95 MB and received 9.98 MB. I've received 0 connections on IPv4 and 0 on IPv6. I've made 13 connections with IPv4 and 0 with IPv6.
tor_server_1  | Sep 08 17:24:25.000 [notice] While bootstrapping, fetched this many bytes: 613678 (consensus network-status fetch); 28192 (authority cert fetch); 5268601 (microdescriptor fetch)
tor_server_1  | Sep 08 17:24:25.000 [notice] While not bootstrapping, fetched this many bytes: 186329 (consensus network-status fetch); 59243 (microdescriptor fetch)
================
==== Result ====
================
The debug script did not automatically detect any issues with your Umbrel.

I am experiencing the same issues. docker-compose logs says there is no such service, and the debug logs from the umbrel GUI show that electrs is continuously restarting.

=====================
= Umbrel debug info =
=====================

Umbrel version
--------------
0.5.1

Memory usage
------------
               total        used        free      shared  buff/cache   available
Mem:             24G         17G        1.9G        156M        4.3G        6.0G
Swap:           2.0G          0B        2.0G

total: 74.1%
system: 63.2%
lightning: 3.3%
bitcoin: 3%
bitfeed: 2.2%
mempool: 1.1%
electrs: 0.8%
lightning-terminal: 0.4%
tor: 0.1%
lnd: 0%
electrs: 0%
bitcoin: 0%

Memory monitor logs
-------------------
   6933 ?        R      0:00 bash ./scripts/memory-monitor
Memory monitor is already running
 401774 pts/1    R+     0:00 bash ./scripts/memory-monitor
 401775 pts/1    R+     0:00 bash ./scripts/memory-monitor
 401776 pts/1    R+     0:00 bash ./scripts/memory-monitor
Memory monitor is already running
2022-09-17 10:39:22 Memory monitor running!
2022-09-18 09:50:00 Memory monitor running!
2022-09-18 10:00:21 Memory monitor running!
2022-09-18 10:06:06 Memory monitor running!

Filesystem information
----------------------
Filesystem                  Size  Used Avail Use% Mounted on
rpool/ROOT/ubuntu_npslo1    407G  4.0G  403G   1% /
rpool/USERDATA/cory_nyvaq4  877G  475G  403G  55% /home/cory

Karen logs
----------

This script must only be run on Umbrel OS
Got signal: backup
karen is getting triggered!
Deriving keys...
Creating backup...
Adding random padding...
1+0 records in
1+0 records out
446 bytes copied, 5.189e-05 s, 8.6 MB/s
Creating encrypted tarball...
backup/
backup/.padding
backup/channel.backup
Uploading backup...
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0
100  3141    0     0  100  3141      0   1404  0:00:02  0:00:02 --:--:--  1404
100  3287  100   146  100  3141     62   1348  0:00:02  0:00:02 --:--:--  1410
{"message":"Successfully uploaded backup 1663512217762.tar.gz.pgp for backup ID f6c0c69b228142aecf719726d7ff2e2891264b5284b947d1bdaceb5a83a113c8"}
=============================
====== Backup success =======
=============================
karen is running in /home/cory/umbrel/events
Got signal: 
karen is getting triggered!
./karen: line 68: /home/cory/umbrel/events/triggers/: Is a directory
Got signal: 
karen is getting triggered!
./karen: line 68: /home/cory/umbrel/events/triggers/: Is a directory
Got signal: change-password
karen is getting triggered!
This script must only be run on Umbrel OS
karen is running in /home/cory/umbrel/events
Got signal: 
karen is getting triggered!
./karen: line 68: /home/cory/umbrel/events/triggers/: Is a directory
Got signal: 
karen is getting triggered!
./karen: line 68: /home/cory/umbrel/events/triggers/: Is a directory
karen is running in /home/cory/umbrel/events
Got signal: 
karen is getting triggered!
Got signal: 
karen is getting triggered!
./karen: line 68: /home/cory/umbrel/events/triggers/: Is a directory
./karen: line 68: /home/cory/umbrel/events/triggers/: Is a directory
Got signal: change-password
karen is getting triggered!
This script must only be run on Umbrel OS
Got signal: debug
karen is getting triggered!

Docker containers
-----------------
NAMES                             STATUS
electrs_app_1                     Up 4 hours
bitfeed_web_1                     Up 4 hours
bitcoin_server_1                  Up 4 hours
lightning_tor_server_1            Up 4 hours
lightning_app_proxy_1             Up 4 hours
lightning_lnd_1                   Up 4 hours
lightning-terminal_tor_server_1   Up 4 hours
mempool_web_1                     Up 4 hours
lightning_app_1                   Up 4 hours
mempool_api_1                     Up 4 hours
lightning-terminal_app_proxy_1    Up 4 hours
mempool_tor_server_1              Up 4 hours
bitfeed_api_1                     Up 4 hours
mempool_app_proxy_1               Up 4 hours
mempool_mariadb_1                 Up 4 hours
electrs_app_proxy_1               Up 4 hours
bitfeed_app_proxy_1               Up 4 hours
lightning-terminal_web_1          Up 4 hours
electrs_electrs_1                 Restarting (1) 43 seconds ago
bitfeed_tor_server_1              Up 4 hours
electrs_tor_server_1              Up 4 hours
bitcoin_bitcoind_1                Up 4 hours
bitcoin_tor_server_1              Up 4 hours
bitcoin_app_proxy_1               Up 4 hours
nginx                             Up 4 hours
manager                           Up 4 hours
tor                               Up 4 hours
dashboard                         Up 4 hours
auth                              Up 4 hours

Umbrel logs
-----------

Attaching to manager
manager      | ::ffff:10.21.0.3 - - [Sun, 18 Sep 2022 19:13:40 GMT] "GET /v1/account/token?token=76f9532b36a28dbf36619bffb9d0f4370a9e13e4e7d5e1f0814831d293f300e8 HTTP/1.1" 200 16 "-" "app-proxy/0.0.1"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Sun, 18 Sep 2022 19:13:44 GMT] "POST /v1/system/debug HTTP/1.0" 200 17 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:104.0) Gecko/20100101 Firefox/104.0"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Sun, 18 Sep 2022 19:13:45 GMT] "GET /v1/system/debug-result HTTP/1.0" 200 23 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:104.0) Gecko/20100101 Firefox/104.0"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.0.3 - - [Sun, 18 Sep 2022 19:13:45 GMT] "GET /v1/account/token?token=76f9532b36a28dbf36619bffb9d0f4370a9e13e4e7d5e1f0814831d293f300e8 HTTP/1.1" 200 16 "-" "app-proxy/0.0.1"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Sun, 18 Sep 2022 19:13:46 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (X11; Linux x86_64; rv:104.0) Gecko/20100101 Firefox/104.0"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Sun, 18 Sep 2022 19:13:47 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (X11; Linux x86_64; rv:104.0) Gecko/20100101 Firefox/104.0"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Sun, 18 Sep 2022 19:13:48 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (X11; Linux x86_64; rv:104.0) Gecko/20100101 Firefox/104.0"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Sun, 18 Sep 2022 19:13:49 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (X11; Linux x86_64; rv:104.0) Gecko/20100101 Firefox/104.0"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.21.2 - - [Sun, 18 Sep 2022 19:13:50 GMT] "GET /v1/system/debug-result HTTP/1.0" 304 - "-" "Mozilla/5.0 (X11; Linux x86_64; rv:104.0) Gecko/20100101 Firefox/104.0"
manager      | 
manager      | umbrel-manager
manager      | ::ffff:10.21.0.3 - - [Sun, 18 Sep 2022 19:13:50 GMT] "GET /v1/account/token?token=76f9532b36a28dbf36619bffb9d0f4370a9e13e4e7d5e1f0814831d293f300e8 HTTP/1.1" 200 16 "-" "app-proxy/0.0.1"
manager      | 
manager      | umbrel-manager

Tor logs
--------

Attaching to tor
tor          | Sep 18 18:52:00.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 18 18:56:29.000 [notice] Your network connection speed appears to have changed. Resetting timeout to 60000ms after 18 timeouts and 426 buildtimes.
tor          | Sep 18 18:57:07.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 18 19:02:14.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 18 19:07:31.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
tor          | Sep 18 19:12:41.000 [notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.

App logs
--------

bitcoin

tor_server_1  | Sep 18 15:06:16.808 [notice] Opened Socks listener connection (ready) on 127.0.0.1:9050
tor_server_1  | Sep 18 15:06:16.000 [notice] Bootstrapped 0% (starting): Starting
tor_server_1  | Sep 18 15:06:16.000 [notice] Starting with guard context "default"
tor_server_1  | Sep 18 15:06:17.000 [notice] Bootstrapped 5% (conn): Connecting to a relay
tor_server_1  | Sep 18 15:06:19.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay
tor_server_1  | Sep 18 15:06:19.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
tor_server_1  | Sep 18 15:06:19.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
tor_server_1  | Sep 18 15:06:19.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
tor_server_1  | Sep 18 15:06:19.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
tor_server_1  | Sep 18 15:06:20.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
tor_server_1  | Sep 18 15:06:22.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
tor_server_1  | Sep 18 15:06:23.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs
tor_server_1  | Sep 18 15:06:23.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
tor_server_1  | Sep 18 15:06:23.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6577, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
tor_server_1  | Sep 18 15:06:24.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:06:25.000 [notice] The current consensus contains exit nodes. Tor can build exit and internal paths.
tor_server_1  | Sep 18 15:06:34.000 [notice] Bootstrapped 56% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:06:36.000 [notice] Bootstrapped 63% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:06:36.000 [notice] Bootstrapped 68% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:06:36.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
tor_server_1  | Sep 18 15:06:37.000 [notice] Bootstrapped 80% (ap_conn): Connecting to a relay to build circuits
tor_server_1  | Sep 18 15:06:37.000 [notice] Bootstrapped 85% (ap_conn_done): Connected to a relay to build circuits
tor_server_1  | Sep 18 15:06:37.000 [notice] Bootstrapped 89% (ap_handshake): Finishing handshake with a relay to build circuits
tor_server_1  | Sep 18 15:06:37.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
tor_server_1  | Sep 18 15:06:37.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
tor_server_1  | Sep 18 15:06:39.000 [notice] Bootstrapped 100% (done): Done
tor_server_1  | Sep 18 16:33:25.000 [notice] No circuits are opened. Relaxed timeout for circuit 183 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
tor_server_1  | Sep 18 18:00:30.000 [notice] Your network connection speed appears to have changed. Resetting timeout to 60000ms after 18 timeouts and 277 buildtimes.
tor_server_1  | Sep 18 18:02:18.000 [notice] No circuits are opened. Relaxed timeout for circuit 436 (a Hidden service: Uploading HS descriptor 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [3 similar message(s) suppressed in last 5340 seconds]

bitfeed

tor_server_1  | Sep 18 15:07:33.000 [notice] Bootstrapped 63% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:07:44.000 [notice] Bootstrapped 68% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:07:44.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
tor_server_1  | Sep 18 15:07:44.000 [notice] Bootstrapped 80% (ap_conn): Connecting to a relay to build circuits
tor_server_1  | Sep 18 15:07:44.000 [notice] Bootstrapped 85% (ap_conn_done): Connected to a relay to build circuits
tor_server_1  | Sep 18 15:07:44.000 [notice] Bootstrapped 89% (ap_handshake): Finishing handshake with a relay to build circuits
tor_server_1  | Sep 18 15:07:45.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
tor_server_1  | Sep 18 15:07:45.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
tor_server_1  | Sep 18 15:07:45.000 [notice] Bootstrapped 100% (done): Done
tor_server_1  | Sep 18 16:22:36.000 [notice] No circuits are opened. Relaxed timeout for circuit 196 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
tor_server_1  | Sep 18 17:43:37.000 [notice] No circuits are opened. Relaxed timeout for circuit 274 (a Hidden service: Uploading HS descriptor 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
web_1         | /docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
web_1         | /docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
web_1         | /docker-entrypoint.sh: Launching /docker-entrypoint.d/05-setup-env.sh
web_1         | /docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh
web_1         | 10-listen-on-ipv6-by-default.sh: info: Getting the checksum of /etc/nginx/conf.d/default.conf
web_1         | 10-listen-on-ipv6-by-default.sh: info: /etc/nginx/conf.d/default.conf differs from the packaged version
web_1         | /docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh
web_1         | /docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh
web_1         | /docker-entrypoint.sh: Configuration complete; ready for start up
web_1         | 2022/09/18 15:06:25 [notice] 1#1: using the "epoll" event method
web_1         | 2022/09/18 15:06:25 [notice] 1#1: nginx/1.21.6
web_1         | 2022/09/18 15:06:25 [notice] 1#1: built by gcc 10.2.1 20210110 (Debian 10.2.1-6) 
web_1         | 2022/09/18 15:06:25 [notice] 1#1: OS: Linux 5.15.0-47-generic
web_1         | 2022/09/18 15:06:25 [notice] 1#1: getrlimit(RLIMIT_NOFILE): 1048576:1048576
web_1         | 2022/09/18 15:06:25 [notice] 1#1: start worker processes
web_1         | 2022/09/18 15:06:25 [notice] 1#1: start worker process 32
web_1         | 2022/09/18 15:06:25 [notice] 1#1: start worker process 33
web_1         | 2022/09/18 15:06:25 [notice] 1#1: start worker process 34
web_1         | 2022/09/18 15:06:25 [notice] 1#1: start worker process 35

electrs

tor_server_1  | Sep 18 15:06:24.323 [notice] Opened Socks listener connection (ready) on 127.0.0.1:9050
tor_server_1  | Sep 18 15:06:24.000 [notice] Bootstrapped 0% (starting): Starting
tor_server_1  | Sep 18 15:06:24.000 [notice] Starting with guard context "default"
tor_server_1  | Sep 18 15:06:25.000 [notice] Bootstrapped 5% (conn): Connecting to a relay
tor_server_1  | Sep 18 15:06:25.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay
tor_server_1  | Sep 18 15:06:25.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
tor_server_1  | Sep 18 15:06:34.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
tor_server_1  | Sep 18 15:06:35.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs
tor_server_1  | Sep 18 15:06:35.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
tor_server_1  | Sep 18 15:06:35.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6577, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
tor_server_1  | Sep 18 15:06:36.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:06:38.000 [notice] The current consensus contains exit nodes. Tor can build exit and internal paths.
tor_server_1  | Sep 18 15:06:44.000 [notice] Bootstrapped 56% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:06:46.000 [notice] Bootstrapped 63% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:06:46.000 [notice] Bootstrapped 69% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:06:47.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
tor_server_1  | Sep 18 15:06:48.000 [notice] Bootstrapped 80% (ap_conn): Connecting to a relay to build circuits
tor_server_1  | Sep 18 15:06:48.000 [notice] Bootstrapped 85% (ap_conn_done): Connected to a relay to build circuits
tor_server_1  | Sep 18 15:06:52.000 [notice] Bootstrapped 89% (ap_handshake): Finishing handshake with a relay to build circuits
tor_server_1  | Sep 18 15:06:52.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
tor_server_1  | Sep 18 15:06:52.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
tor_server_1  | Sep 18 15:06:55.000 [notice] Bootstrapped 100% (done): Done
tor_server_1  | Sep 18 16:38:45.000 [notice] No circuits are opened. Relaxed timeout for circuit 253 (a Hidden service: Establishing introduction point 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
tor_server_1  | Sep 18 18:36:37.000 [warn] Requested exit point '$0D8877392F2FF5AD8D8E5BC438087F02EF97B904' is not known. Closing.
tor_server_1  | Sep 18 18:37:38.000 [notice] No circuits are opened. Relaxed timeout for circuit 463 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [7 similar message(s) suppressed in last 7140 seconds]

lightning

tor_server_1  | Sep 18 15:06:25.000 [notice] Starting with guard context "default"
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 5% (conn): Connecting to a relay
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
tor_server_1  | Sep 18 15:06:26.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
tor_server_1  | Sep 18 15:11:37.000 [warn] Unable to decompress HTTP body (tried deflated, on Directory connection (client reading) with 104.219.236.101:443).
tor_server_1  | Sep 18 15:11:39.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
tor_server_1  | Sep 18 15:11:40.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs
tor_server_1  | Sep 18 15:11:40.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
tor_server_1  | Sep 18 15:11:40.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6570, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
tor_server_1  | Sep 18 15:11:41.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:11:42.000 [notice] The current consensus contains exit nodes. Tor can build exit and internal paths.
tor_server_1  | Sep 18 15:11:43.000 [notice] Bootstrapped 56% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:13:20.000 [notice] Bootstrapped 63% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:13:20.000 [notice] Bootstrapped 68% (loading_descriptors): Loading relay descriptors
tor_server_1  | Sep 18 15:13:22.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
tor_server_1  | Sep 18 15:13:22.000 [notice] Bootstrapped 80% (ap_conn): Connecting to a relay to build circuits
tor_server_1  | Sep 18 15:13:23.000 [notice] Bootstrapped 85% (ap_conn_done): Connected to a relay to build circuits
tor_server_1  | Sep 18 15:13:23.000 [notice] Bootstrapped 89% (ap_handshake): Finishing handshake with a relay to build circuits
tor_server_1  | Sep 18 15:13:23.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
tor_server_1  | Sep 18 15:13:23.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
tor_server_1  | Sep 18 15:13:25.000 [notice] Bootstrapped 100% (done): Done
tor_server_1  | Sep 18 16:54:47.000 [notice] No circuits are opened. Relaxed timeout for circuit 303 (a Measuring circuit timeout 3-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
tor_server_1  | Sep 18 16:57:40.000 [notice] Guard SODrelay ($AC633C90E126E0BCA96F14ECE5D222B586FA0D56) is failing more circuits than usual. Most likely this means the Tor network is overloaded. Success counts are 97/151. Use counts are 68/69. 100 circuits completed, 1 were unusable, 2 collapsed, and 33 timed out. For reference, your timeout cutoff is 60 seconds.
tor_server_1  | Sep 18 16:59:51.000 [notice] Guard redvader ($77A3ADC5D455778B53C2803761916DFB7DA0A790) is failing more circuits than usual. Most likely this means the Tor network is overloaded. Success counts are 97/151. Use counts are 70/70. 98 circuits completed, 0 were unusable, 1 collapsed, and 31 timed out. For reference, your timeout cutoff is 60 seconds.
tor_server_1  | Sep 18 18:54:27.000 [notice] No circuits are opened. Relaxed timeout for circuit 695 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [40 similar message(s) suppressed in last 7020 seconds]

lightning-terminal

web_1         | 2022-09-18 15:06:50.004 [INF] RPCS: Received new block notification: height=754666
web_1         | 2022-09-18 15:06:52.428 [INF] RPCS: Received new block notification: height=754667
web_1         | 2022-09-18 15:16:09.645 [INF] RPCS: Received new block notification: height=754668
web_1         | 2022-09-18 15:17:07.908 [INF] RPCS: Received new block notification: height=754669
web_1         | 2022-09-18 15:20:36.193 [INF] RPCS: Received new block notification: height=754670
web_1         | 2022-09-18 15:24:28.238 [INF] RPCS: Received new block notification: height=754671
web_1         | 2022-09-18 15:29:51.391 [INF] RPCS: Received new block notification: height=754672
web_1         | 2022-09-18 15:44:58.488 [INF] RPCS: Received new block notification: height=754673
web_1         | 2022-09-18 15:54:31.644 [INF] RPCS: Received new block notification: height=754674
web_1         | 2022-09-18 15:54:37.538 [INF] RPCS: Received new block notification: height=754675
web_1         | 2022-09-18 16:02:54.897 [INF] RPCS: Received new block notification: height=754676
web_1         | 2022-09-18 16:03:35.847 [INF] RPCS: Received new block notification: height=754677
web_1         | 2022-09-18 16:12:42.591 [INF] RPCS: Received new block notification: height=754678
web_1         | 2022-09-18 16:43:14.949 [INF] RPCS: Received new block notification: height=754679
web_1         | 2022-09-18 16:43:39.381 [INF] RPCS: Received new block notification: height=754680
web_1         | 2022-09-18 16:46:18.143 [INF] RPCS: Received new block notification: height=754681
web_1         | 2022-09-18 17:11:52.251 [INF] RPCS: Received new block notification: height=754682
web_1         | 2022-09-18 17:25:05.316 [INF] RPCS: Received new block notification: height=754683
web_1         | 2022-09-18 17:29:48.846 [INF] RPCS: Received new block notification: height=754684
web_1         | 2022-09-18 17:52:30.856 [INF] RPCS: Received new block notification: height=754685
web_1         | 2022-09-18 17:57:06.248 [INF] RPCS: Received new block notification: height=754686
web_1         | 2022-09-18 18:01:59.330 [INF] RPCS: Received new block notification: height=754687
web_1         | 2022-09-18 18:10:45.755 [INF] RPCS: Received new block notification: height=754688
web_1         | 2022-09-18 18:11:41.226 [INF] RPCS: Received new block notification: height=754689
web_1         | 2022-09-18 18:17:34.412 [INF] RPCS: Received new block notification: height=754690
web_1         | 2022-09-18 18:17:51.802 [INF] RPCS: Received new block notification: height=754691
web_1         | 2022-09-18 18:51:14.835 [INF] RPCS: Received new block notification: height=754692
web_1         | 2022-09-18 19:01:08.898 [INF] RPCS: Received new block notification: height=754693
web_1         | 2022-09-18 19:04:32.549 [INF] RPCS: Received new block notification: height=754694
web_1         | 2022-09-18 19:12:26.383 [INF] RPCS: Received new block notification: height=754695

mempool

tor_server_1  | Sep 18 15:09:42.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
tor_server_1  | Sep 18 15:09:42.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
tor_server_1  | Sep 18 15:09:45.000 [notice] Bootstrapped 100% (done): Done
tor_server_1  | Sep 18 18:47:32.000 [notice] No circuits are opened. Relaxed timeout for circuit 344 (a Measuring circuit timeout 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
mariadb_1     | 2022-09-18 15:06:19+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:10.5.12+maria~focal started.
mariadb_1     | 2022-09-18 15:06:19 0 [Note] mysqld (mysqld 10.5.12-MariaDB-1:10.5.12+maria~focal) starting as process 1 ...
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Uses event mutexes
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Number of pools: 1
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
mariadb_1     | 2022-09-18 15:06:20 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Using Linux native AIO
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Completed initialization of buffer pool
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: 128 rollback segments are active.
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Creating shared tablespace for temporary tables
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: 10.5.12 started; log sequence number 56531879; transaction id 161669
mariadb_1     | 2022-09-18 15:06:20 0 [Note] Plugin 'FEEDBACK' is disabled.
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mariadb_1     | 2022-09-18 15:06:20 0 [Note] Server socket created on IP: '::'.
mariadb_1     | 2022-09-18 15:06:20 0 [Warning] 'proxies_priv' entry '@% root@a82e021dcc84' ignored in --skip-name-resolve mode.
mariadb_1     | 2022-09-18 15:06:20 0 [Note] Reading of all Master_info entries succeeded
mariadb_1     | 2022-09-18 15:06:20 0 [Note] Added new Master_info '' to hash table
mariadb_1     | 2022-09-18 15:06:20 0 [Note] mysqld: ready for connections.
mariadb_1     | Version: '10.5.12-MariaDB-1:10.5.12+maria~focal'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
mariadb_1     | 2022-09-18 15:06:20 0 [Note] InnoDB: Buffer pool(s) load completed at 220918 15:06:20
mariadb_1     | 2022-09-18 15:06:21 3 [Warning] Aborted connection 3 to db: 'unconnected' user: 'unauthenticated' host: '10.21.21.26' (This connection closed normally without authentication)
mariadb_1     | 2022-09-18 15:06:22 4 [Warning] Aborted connection 4 to db: 'unconnected' user: 'unauthenticated' host: '10.21.21.27' (This connection closed normally without authentication)
================
==== Result ====
================
The debug script did not automatically detect any issues with your Umbrel.

Hi @lonerangir @Louie !
It looks like you have multiple instances of electrs & bitcoin running
you can try to stop all apps using:
sudo ~/umbrel/scripts/stop
and try to restart the apps using:
sudo ~/umbrel/scripts/start

If everything times out during the startup script you can try :
sudo systemctl restart docker
which should make Docker behave normally
Keep us posted !

Hi @Marcaday, thanks for the reply.

I’ve tried stopping and starting things many times, as I read about things to try.

What specifically in the log makes you say that there are multiple instances? This way I can determine that myself, and see if I’m making a difference as I try things.

Update: Nevermind, now I see. there are two instances in the top resource list: one with some resources and at the bottom one with 0%

1 Like

Hey @lonerangir, Yep! We can see the two instances in the memory logs.
Can you confirm that two instances are running using :
ssh -t umbrel@umbrel.local "docker ps"
Restarting docker did not work for you?

@Marcaday, here is the output of ‘docker ps’. Thanks for the continued help.

FWIW, I am running umbrel on Ubuntu 22.04 LTS. I am using an old quad-core desktop. I also have the Tor browser installed.

docker ps:
CONTAINER ID   IMAGE                                           COMMAND                  CREATED        STATUS        PORTS                                                                                                                                 NAMES
3c8d9bd7c636   ghcr.io/bitfeed-project/bitfeed-client:v2.3.4   "/docker-entrypoint.…"   10 hours ago   Up 10 hours   80/tcp                                                                                                                                bitfeed_web_1
28421ae38aeb   getumbrel/umbrel-bitcoin:v0.3.0                 "docker-entrypoint.s…"   10 hours ago   Up 10 hours   3006/tcp                                                                                                                              bitcoin_server_1
07083c46ae23   getumbrel/umbrel-electrs:v1.0.2                 "docker-entrypoint.s…"   10 hours ago   Up 10 hours   3006/tcp                                                                                                                              electrs_app_1
d80c40f811de   getumbrel/app-proxy:v0.5.1                      "docker-entrypoint.s…"   10 hours ago   Up 10 hours   0.0.0.0:2100->2100/tcp, :::2100->2100/tcp                                                                                             bitcoin_app_proxy_1
7ea020736a44   lncm/tor:0.4.7.8                                "tor"                    10 hours ago   Up 10 hours   9050-9051/tcp, 29050-29051/tcp                                                                                                        bitcoin_tor_server_1
ca31c10d7f67   lncm/bitcoind:v23.0                             "bitcoind -chain=mai…"   10 hours ago   Up 10 hours   8080/tcp, 18332-18333/tcp, 18443-18444/tcp, 28332-28333/tcp, 0.0.0.0:8332-8333->8332-8333/tcp, :::8332-8333->8332-8333/tcp            bitcoin_bitcoind_1
a419c1076d99   lncm/tor:0.4.7.8                                "tor"                    10 hours ago   Up 10 hours   9050-9051/tcp, 29050-29051/tcp                                                                                                        bitfeed_tor_server_1
c2102a72829f   ghcr.io/bitfeed-project/bitfeed-server:v2.3.4   "/app/_build/prod/re…"   10 hours ago   Up 10 hours   4000/tcp                                                                                                                              bitfeed_api_1
f4160d736477   getumbrel/app-proxy:v0.5.1                      "docker-entrypoint.s…"   10 hours ago   Up 10 hours   0.0.0.0:8314->8314/tcp, :::8314->8314/tcp                                                                                             bitfeed_app_proxy_1
3ea2241f9aca   getumbrel/app-proxy:v0.5.1                      "docker-entrypoint.s…"   10 hours ago   Up 10 hours   0.0.0.0:3004->3004/tcp, :::3004->3004/tcp                                                                                             lightning-terminal_app_proxy_1
f44fa6239de7   lncm/tor:0.4.7.8                                "tor"                    10 hours ago   Up 10 hours   9050-9051/tcp, 29050-29051/tcp                                                                                                        lightning-terminal_tor_server_1
046d1de6e684   lightninglabs/lightning-terminal:v0.8.0-alpha   "litd --uipassword_e…"   10 hours ago   Up 10 hours   8443/tcp, 9735/tcp, 10009/tcp                                                                                                         lightning-terminal_web_1
bec71dc4a2a6   getumbrel/app-proxy:v0.5.1                      "docker-entrypoint.s…"   10 hours ago   Up 10 hours   0.0.0.0:2102->2102/tcp, :::2102->2102/tcp                                                                                             electrs_app_proxy_1
a2c90b4552d6   lncm/tor:0.4.7.8                                "tor"                    10 hours ago   Up 10 hours   9050-9051/tcp, 29050-29051/tcp                                                                                                        electrs_tor_server_1
728d8858027e   getumbrel/app-proxy:v0.5.1                      "docker-entrypoint.s…"   10 hours ago   Up 10 hours   0.0.0.0:2101->2101/tcp, :::2101->2101/tcp                                                                                             lightning_app_proxy_1
3ee6875741d4   lncm/tor:0.4.7.8                                "tor"                    10 hours ago   Up 10 hours   9050-9051/tcp, 29050-29051/tcp                                                                                                        lightning_tor_server_1
272ed0282cc6   getumbrel/umbrel-lightning:v1.0.4               "docker-entrypoint.s…"   10 hours ago   Up 10 hours   3006/tcp                                                                                                                              lightning_app_1
9bdabefca2b5   mariadb:10.5.12                                 "docker-entrypoint.s…"   10 hours ago   Up 10 hours   3306/tcp                                                                                                                              mempool_mariadb_1
912da40c73f0   lncm/tor:0.4.7.8                                "tor"                    10 hours ago   Up 10 hours   9050-9051/tcp, 29050-29051/tcp                                                                                                        mempool_tor_server_1
fa9b75d13da8   lightninglabs/lnd:v0.15.1-beta                  "lnd --listen=0.0.0.…"   10 hours ago   Up 10 hours   0.0.0.0:8080->8080/tcp, :::8080->8080/tcp, 0.0.0.0:9735->9735/tcp, :::9735->9735/tcp, 0.0.0.0:10009->10009/tcp, :::10009->10009/tcp   lightning_lnd_1
5b30e2e9c235   getumbrel/app-proxy:v0.5.1                      "docker-entrypoint.s…"   10 hours ago   Up 10 hours   0.0.0.0:3006->3006/tcp, :::3006->3006/tcp                                                                                             mempool_app_proxy_1
dfb250d6f006   mempool/backend:v2.4.0                          "docker-entrypoint.s…"   10 hours ago   Up 10 hours   8999/tcp                                                                                                                              mempool_api_1
0e1bec7bdb4a   mempool/frontend:v2.4.0                         "/patch/entrypoint.s…"   10 hours ago   Up 10 hours   80/tcp                                                                                                                                mempool_web_1
4189c7978126   nginx:1.17.8                                    "nginx -g 'daemon of…"   10 hours ago   Up 10 hours   0.0.0.0:80->80/tcp, :::80->80/tcp                                                                                                     nginx
a4abd8f81123   getumbrel/manager:v0.5.0                        "docker-entrypoint.s…"   10 hours ago   Up 10 hours   3006/tcp                                                                                                                              manager
4cf48b25b154   getumbrel/auth-server:v0.5.1                    "docker-entrypoint.s…"   10 hours ago   Up 10 hours   0.0.0.0:2000->2000/tcp, :::2000->2000/tcp                                                                                             auth
92720dc4f00c   getumbrel/dashboard:v0.5.4                      "docker-entrypoint.s…"   10 hours ago   Up 10 hours   3004/tcp                                                                                                                              dashboard
253a24a0bd4e   lncm/tor:0.4.7.8                                "tor"                    10 hours ago   Up 10 hours   9051/tcp, 29050-29051/tcp, 127.0.0.1:9053->9050/tcp                                                                                   tor

@lonerangir @Louie,
as electrs_electrs_1 is constantly restarting it would be worth taking a look directly at the electrs log using:
ssh -t umbrel@umbrel.local "~/umbrel/scripts/app compose electrs logs --tail=100 electrs"
Hopefully, that will give us some insight into what is going on :crossed_fingers:

@Marcaday, here is the output of the electrs log. Is there a port issue concerning tor, since I have Tor the browser installed, perhaps?

Attaching to electrs_electrs_1
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:38:09.429Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:38:09.429Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:38:09.766Z INFO  electrs::db] "/data/db/bitcoin": 26861 SST files, 0.021623105 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:38:09.788Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | [2022-09-20T23:38:09.788Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:39:10.221Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:39:10.221Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:39:10.561Z INFO  electrs::db] "/data/db/bitcoin": 26862 SST files, 0.02162391 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:39:10.582Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | [2022-09-20T23:39:10.582Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:40:11.009Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:40:11.009Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:40:11.351Z INFO  electrs::db] "/data/db/bitcoin": 26863 SST files, 0.021624715 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:40:11.373Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | [2022-09-20T23:40:11.373Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:41:11.849Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:41:11.849Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:41:12.187Z INFO  electrs::db] "/data/db/bitcoin": 26864 SST files, 0.02162552 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:41:12.209Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | [2022-09-20T23:41:12.209Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:42:12.637Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:42:12.637Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:42:12.978Z INFO  electrs::db] "/data/db/bitcoin": 26865 SST files, 0.021626325 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:42:12.999Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | [2022-09-20T23:42:12.999Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:43:13.421Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:43:13.421Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:43:13.762Z INFO  electrs::db] "/data/db/bitcoin": 26866 SST files, 0.02162713 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:43:13.783Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | [2022-09-20T23:43:13.784Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:44:14.193Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:44:14.193Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:44:14.531Z INFO  electrs::db] "/data/db/bitcoin": 26867 SST files, 0.021627935 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:44:14.552Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | [2022-09-20T23:44:14.552Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:45:15.005Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:45:15.005Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:45:15.336Z INFO  electrs::db] "/data/db/bitcoin": 26868 SST files, 0.02162874 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:45:15.360Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | [2022-09-20T23:45:15.360Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:46:15.768Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:46:15.768Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:46:16.110Z INFO  electrs::db] "/data/db/bitcoin": 26869 SST files, 0.021629545 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:46:16.135Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | [2022-09-20T23:46:16.135Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-20T23:47:16.565Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-20T23:47:16.565Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-20T23:47:16.900Z INFO  electrs::db] "/data/db/bitcoin": 26870 SST files, 0.02163035 GB, 0.000000021 Grows
electrs_1     | [2022-09-20T23:47:16.924Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | [2022-09-20T23:47:16.924Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel

Thanks for the reply @Marcaday.

I’ve reinstalled on a new machine now using Ubuntu 22.04. Still having the same problem however. It seems to be to do with the .cookie file missing…

electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50001, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-22T23:10:12.608Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-22T23:10:12.608Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50001
electrs_1     | [2022-09-22T23:10:12.631Z INFO  electrs::db] "/data/db/bitcoin": 78 SST files, 0.00006279 GB, 0.000000021 Grows
electrs_1     | [2022-09-22T23:10:12.635Z INFO  electrs::db] closing DB at /data/db/bitcoin
electrs_1     | Error: electrs failed
electrs_1     |
electrs_1     | Caused by:
electrs_1     |     0: failed to open bitcoind cookie file: /data/.bitcoin/.cookie
electrs_1     |     1: No such file or directory (os error 2)

I’ve tried creating the .cookie file with USER:PASS inside (replaced values) but still no luck.

CookieFile("/data/.bitcoin/.cookie")

Is this location relative to electrs directory?

I’ve tried creating it in a number of spots…

~/umbrel/app-data/electrs/data/electrs/.bitcoin

Also here - the bitcoin data dir (that has the blocks dir) …

~/umbrel/app-data/bitcoin/data/bitcoin

I resolved my issue!

Comment out rpcuser= and rpcpassword= in the bitcoin.conf file, restart umbrel using the stop start scripts and then bitcoind will create the .cookie file. Electrs can then find the .cookie file and will no longer fail startup :slight_smile:

@Louie, this is great to hear.

What is the content of your bitcoin.conf file?

Where did the .cookie file get placed specifically? What is the content of that file?

hey @lonerangir, as far as I understand, bitcoind will only create the .cookie file if the rpcuser and rpcpassword settings are empty in bitcoin.conf. It gets created on my system under:

~/umbrel/app-data/bitcoin/data/bitcoin/

once I restarted everything and bitcoind had created the file, Electrs started synchronizing and it’s logs were clear of the errors

my bitcoin.conf file looks like this…

#rpcuser=umbrel
#rpcpassword=[password was here]

[main]
rpcbind=127.0.0.1
rpcbind=192.168.1.10
rpcbind=10.21.21.8
rpcbind=btcnode.local
rpcallowip=127.0.0.1
rpcallowip=192.168.1.0/24

to be honest, I can’t remember if I added the rpcuser and rpcpassword settings into bitcoin.conf myself when trying different things or if they were there from the original set up!

Hey @Louie,

I did confirm that the .cookie file is getting updated properly when the user/pass is omitted from the bitcoin.conf file. What was throwing me off was the fact that it’s a hidden file, so I cannot rely on the file explorer to tell me whether it exists or not, since it does not display hidden files.

I did notice this, though. electrs is looking for the cookie file in “/data/.bitcoin/.cookie”, but the file actually exists in “/data/bitcoin/.cookie”. I am concentrating on finding how that gets set.

electrs_1     | Error: electrs failed
electrs_1     | 
electrs_1     | Caused by:
electrs_1     |     receiving on an empty and disconnected channel
electrs_1     | Starting electrs 0.9.4 on x86_64 linux with Config { network: Bitcoin, db_path: "/data/db/bitcoin", daemon_dir: "/data/.bitcoin", daemon_auth: CookieFile("/data/.bitcoin/.cookie"), daemon_rpc_addr: 10.21.21.8:8332, daemon_p2p_addr: 10.21.21.8:8333, electrum_rpc_addr: 0.0.0.0:50000, monitoring_addr: 127.0.0.1:4224, wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: None, reindex_last_blocks: 0, auto_reindex: true, ignore_mempool: false, sync_once: false, disable_electrum_rpc: false, server_banner: "Umbrel Electrs (0.9.4-build-2)", args: [] }
electrs_1     | [2022-09-25T18:05:09.057Z INFO  electrs::metrics::metrics_impl] serving Prometheus metrics on 127.0.0.1:4224
electrs_1     | [2022-09-25T18:05:09.057Z INFO  electrs::server] serving Electrum RPC on 0.0.0.0:50000
electrs_1     | [2022-09-25T18:05:09.645Z INFO  electrs::db] "/data/db/bitcoin": 31857 SST files, 0.025644885 GB, 0.000000021 Grows
electrs_1     | [2022-09-25T18:05:09.829Z WARN  electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)
electrs_1     | [2022-09-25T18:05:09.829Z INFO  electrs::db] closing DB at /data/db/bitcoin

Also, when you go to Settings -> Troubleshoot, do you still see multiple instances of bitcoin and electrs in the memory usage list, or did that go away now that electrs is working?

@lonerangir I was looking at exactly the same thing - I can’t figure out why .bitcoin is referenced everywhere in config as the directory yet it clearly uses the bitcoin directory. I had tried changing config to use bitcoin instead of .bitcoin and it didn’t work. Also creating a .bitcoin dir didn’t work. It was only the rpcuser and pass stuff that fixed it for me

My umbrel logs still show additional 0% processes for bitcoin and electrs in the top summary which is weird because everything seems to be working ok for me now.

Is your electrs still stuck synchronizing?

Is this log line an issue perhaps?

[2022-09-25T18:05:09.829Z WARN electrs::p2p] failed to shutdown p2p connection: Transport endpoint is not connected (os error 107)

@Louie, yes still stuck synchronizing.

I assumed that was all part of the same transaction that is failing: it cannot shut down the connection because it was not opened!

Hey Guys! Sorry for the delay.
I’m glad that you’ve managed to fix your issue @Louie :fire: ,

The double instance of bitcoin & electrs was a bug in the memory monitoring script. The debug script won’t show duplicate entries after the next Umbrel update.
This memory monitoring script should show you the correct data:
sudo ~/umbrel/scripts/status/memory

@lonerangir have you added anything special to your bitcoin.conf file?
If not, you can remove the bitcoin.conf file:
sudo rm ~/umbrel/app-data/bitcoin/data/bitcoin/bitcoin.conf

(If you want to conserve what you’ve added to your bitcoin.conf file, you can remove the rpcuser & rpcpassword entries, and tell us what you have modified in your bitcoin.conf)

Then you could try to run the electrs update script to see if it fixes electrs:
sudo ~/umbrel/scripts/app update electrs

This is the current content of my bitcoin.conf file. I originally added it so I could re-index the chain state, since I side-loaded from another trusted node, rather than re-downloaded. Then I’ve been adding/editing various setting in order to get things to work. However…

Moving the bitcoin.conf file and restarting is now allowing electrs to sync! Something below was causing my issues.

# [core]
# Rebuild chain state and block index from the blk*.dat files on disk. WARNING: very slow!
reindex=0

[main]
rpcbind=127.0.0.1
rpcbind=192.168.1.10
rpcbind=btcnode.local
rpcbind=10.21.21.8
rpcallowip=127.0.0.1
rpcallowip=192.168.1.0/24

# [network]
# Maintain at most N connections to peers.
maxconnections=3
whitebind=127.0.0.1:8333
1 Like

So I narrowed it down to the maxconnections=3. I added this to limit my data usage for my node.

Hi,
I have the same problem with electrs: “Waiting for Bitcoin Node to finish syncing…”
Will there be a fix or do I have to do stuff like described above? I really have no idea what you guys are talking about.