Commands are executing very slowly

Hi,

I have umbrel running on Raspberry Pi 4 and all the recommended devices SSD, original power supply etc.

I also installed pi hole on it and gave it a static ip address.

I am able to opend the dashborad but today i had trouble ssh-ing into it.

After i deleted .know_hosts for that ip address , i was able to ssh into it but i am still having issues executing commands.

I feel like it takes way to long to do anything. For example i run ~/umbrel/scripts/debug --upload and its running 30 minutes already. I am not sure is it something wrong with it.

Also i tried running Troubleshoot through the dashboard but it never finished.

How can i debug this better ?

Did you turn it off and on again? :slight_smile:

First check hardware. Change usb cable and sata adapter. Verify if disk is full.

Man, is never the hardware… is only umbrel :slight_smile:

Maybe I´m infuenced by my car mechanic, he changes lots of parts til he cures the problem… :upside_down_face:

2 Likes

Thanks for replys. I have turned on and off umbrel multiple times, also i have checked cables, sdcard , ssd etc … it all seems to be working just fine.

Anyways debug script has just firnished after couple of hours. Is it safe to share it here ?

Yes, post it. We can´t guess things, or do like my mechanic…

1 Like

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

Umbrel version

0.4.7

Flashed OS version

v0.3.10

Raspberry Pi Model

Revision : c03112
Serial : 100000004ff6da42
Model : Raspberry Pi 4 Model B Rev 1.2

Firmware

Feb 25 2021 12:10:40
Copyright © 2012 Broadcom
version 564e5f9b852b23a330b1764bcf0b2d022a20afd0 (clean) (release) (start)

Temperature

temp=55.0’C

Throttling

throttled=0x0

Memory usage

          total        used        free      shared  buff/cache   available

Mem: 3.8G 1.5G 482M 7.0M 1.8G 2.2G
Swap: 4.1G 8.0M 4.1G

total: 40.1%
system: 40.1%
tor: 0%
pi-hole: 0%
mempool: 0%
lnd: 0%
electrs: 0%
bitcoin: 0%

Memory monitor logs

2022-04-29 04:40:20 Memory monitor running!
2022-04-29 04:51:01 Memory monitor running!
2022-04-29 05:16:19 Memory monitor running!
2022-04-29 05:25:26 Memory monitor running!
2022-04-29 05:31:08 Memory monitor running!
2022-04-29 05:36:32 Memory monitor running!
2022-04-29 05:45:49 Memory monitor running!
2022-05-01 08:19:17 Memory monitor running!
2022-05-01 10:31:12 Memory monitor running!
2022-05-01 10:49:20 Memory monitor running!

Filesystem information

Filesystem Size Used Avail Use% Mounted on
/dev/root 59G 2.8G 54G 5% /
/dev/sda1 916G 515G 355G 60% /home/umbrel/umbrel

Startup service logs

May 01 10:49:28 umbrel umbrel startup[1008]: Creating nginx …
May 01 10:49:28 umbrel umbrel startup[1008]: Creating lnd …
May 01 10:49:31 umbrel umbrel startup[1008]: Creating nginx … done
May 01 10:49:31 umbrel umbrel startup[1008]: Creating bitcoin …
May 01 10:49:32 umbrel umbrel startup[1008]: Creating lnd … done
May 01 10:49:33 umbrel umbrel startup[1008]: Creating bitcoin … done
May 01 10:49:33 umbrel umbrel startup[1008]: Creating middleware …
May 01 10:49:33 umbrel umbrel startup[1008]: Creating neutrino-switcher …
May 01 10:49:52 umbrel umbrel startup[1008]: Creating middleware … done
May 01 10:49:52 umbrel umbrel startup[1008]: Creating neutrino-switcher … done
May 01 10:49:53 umbrel umbrel startup[1008]: Removing status server iptables entry…
May 01 10:49:53 umbrel umbrel startup[1008]: Removed existing iptables entry.
May 01 10:49:53 umbrel umbrel startup[1008]: Starting installed apps…
May 01 10:49:53 umbrel umbrel startup[1008]: Starting app pi-hole…
May 01 10:49:53 umbrel umbrel startup[1008]: Starting app mempool…
May 01 10:49:57 umbrel umbrel startup[1008]: Creating pi-hole_server_1 …
May 01 10:49:57 umbrel umbrel startup[1008]: Creating mempool_mariadb_1 …
May 01 10:49:57 umbrel umbrel startup[1008]: Creating mempool_web_1 …
May 01 10:49:57 umbrel umbrel startup[1008]: Creating mempool_api_1 …
May 01 10:50:01 umbrel umbrel startup[1008]: Creating mempool_web_1 … done
May 01 10:50:02 umbrel umbrel startup[1008]: Creating mempool_mariadb_1 … done
May 01 10:50:02 umbrel umbrel startup[1008]: Creating mempool_api_1 … done
May 01 10:50:02 umbrel umbrel startup[1008]: Creating pi-hole_server_1 … done
May 01 10:50:02 umbrel umbrel startup[1008]: Umbrel is now accessible at
May 01 10:50:02 umbrel umbrel startup[1008]: http: // umbrel.local
May 01 10:50:02 umbrel umbrel startup[1008]: http: // 192.168.1.5
May 01 10:50:02 umbrel systemd[1]: Started Umbrel Startup Service.
May 01 10:50:10 umbrel passwd[4339]: pam_unix(passwd:chauthtok): password changed for umbrel
May 01 13:34:43 umbrel passwd[3124]: pam_unix(passwd:chauthtok): password changed for umbrel

External storage service logs

– Logs begin at Sun 2022-05-01 10:49:02 UTC, end at Sun 2022-05-01 13:40:03 UTC. –
May 01 10:49:07 umbrel systemd[1]: Starting External Storage Mounter…
May 01 10:49:07 umbrel external storage mounter[527]: Running external storage mount script…
May 01 10:49:07 umbrel external storage mounter[527]: Found device “External USB3.0”
May 01 10:49:07 umbrel external storage mounter[527]: Blacklisting USB device IDs against UAS driver…
May 01 10:49:07 umbrel external storage mounter[527]: Rebinding USB drivers…
May 01 10:49:07 umbrel external storage mounter[527]: Checking USB devices are back…
May 01 10:49:07 umbrel external storage mounter[527]: Waiting for USB devices…
May 01 10:49:08 umbrel external storage mounter[527]: Waiting for USB devices…
May 01 10:49:09 umbrel external storage mounter[527]: Checking if the device is ext4…
May 01 10:49:09 umbrel external storage mounter[527]: Yes, it is ext4
May 01 10:49:09 umbrel external storage mounter[527]: Checking if device contains an Umbrel install…
May 01 10:49:09 umbrel external storage mounter[527]: Yes, it contains an Umbrel install
May 01 10:49:09 umbrel external storage mounter[527]: Bind mounting external storage over local Umbrel installation…
May 01 10:49:09 umbrel external storage mounter[527]: Bind mounting external storage over local Docker data dir…
May 01 10:49:09 umbrel external storage mounter[527]: Bind mounting external storage to /swap
May 01 10:49:09 umbrel external storage mounter[527]: Bind mounting SD card root at /sd-card…
May 01 10:49:09 umbrel external storage mounter[527]: Checking Umbrel root is now on external storage…
May 01 10:49:10 umbrel external storage mounter[527]: Checking /var/lib/docker is now on external storage…
May 01 10:49:10 umbrel external storage mounter[527]: Checking /swap is now on external storage…
May 01 10:49:11 umbrel external storage mounter[527]: Setting up swapfile
May 01 10:49:11 umbrel external storage mounter[527]: Setting up swapspace version 1, size = 4 GiB (4294963200 bytes)
May 01 10:49:11 umbrel external storage mounter[527]: no label, UUID=e544a80c-6ac8-4e3f-a918-aec341e4c60c
May 01 10:49:11 umbrel external storage mounter[527]: Checking SD Card root is bind mounted at /sd-root…
May 01 10:49:11 umbrel external storage mounter[527]: Starting external drive mount monitor…
May 01 10:49:11 umbrel external storage mounter[527]: Mount script completed successfully!
May 01 10:49:11 umbrel systemd[1]: Started External Storage Mounter.

External storage SD card update service logs

– Logs begin at Sun 2022-05-01 10:49:02 UTC, end at Sun 2022-05-01 13:40:03 UTC. –
May 01 10:49:19 umbrel systemd[1]: Starting External Storage SDcard Updater…
May 01 10:49:20 umbrel external storage updater[927]: Checking if SD card Umbrel is newer than external storage…
May 01 10:49:20 umbrel external storage updater[927]: No, SD version is not newer, exiting.
May 01 10:49:20 umbrel systemd[1]: Started External Storage SDcard Updater.

Karen logs

raise ReadTimeoutError(self, url, "Read timed out. (read timeout=%s)" % timeout_value)

urllib3.exceptions.ReadTimeoutError: UnixHTTPConnectionPool(host=‘localhost’, port=None): Read timed out. (read timeout=240)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File “/usr/local/lib/python3.7/dist-packages/docker/api/client.py”, line 214, in _retrieve_server_version
return self.version(api_version=False)[“ApiVersion”]
File “/usr/local/lib/python3.7/dist-packages/docker/api/daemon.py”, line 181, in version
return self._result(self._get(url), json=True)
File “/usr/local/lib/python3.7/dist-packages/docker/utils/decorators.py”, line 46, in inner
return f(self, *args, **kwargs)
File “/usr/local/lib/python3.7/dist-packages/docker/api/client.py”, line 237, in _get
return self.get(url, **self._set_request_timeout(kwargs))
File “/usr/lib/python3/dist-packages/requests/sessions.py”, line 546, in get
return self.request(‘GET’, url, **kwargs)
File “/usr/lib/python3/dist-packages/requests/sessions.py”, line 533, in request
resp = self.send(prep, **send_kwargs)
File “/usr/lib/python3/dist-packages/requests/sessions.py”, line 646, in send
r = adapter.send(request, **kwargs)
File “/usr/lib/python3/dist-packages/requests/adapters.py”, line 529, in send
raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: UnixHTTPConnectionPool(host=‘localhost’, port=None): Read timed out. (read timeout=240)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File “/usr/local/bin/docker-compose”, line 10, in
sys.exit(main())
File “/usr/local/lib/python3.7/dist-packages/compose/cli/main.py”, line 81, in main
command_func()
File “/usr/local/lib/python3.7/dist-packages/compose/cli/main.py”, line 200, in perform_command
project = project_from_options(’.’, options)
File “/usr/local/lib/python3.7/dist-packages/compose/cli/command.py”, line 70, in project_from_options
enabled_profiles=get_profiles_from_options(options, environment)
File “/usr/local/lib/python3.7/dist-packages/compose/cli/command.py”, line 153, in get_project
verbose=verbose, version=api_version, context=context, environment=environment
File “/usr/local/lib/python3.7/dist-packages/compose/cli/docker_client.py”, line 43, in get_client
environment=environment, tls_version=get_tls_version(environment)
File “/usr/local/lib/python3.7/dist-packages/compose/cli/docker_client.py”, line 170, in docker_client
client = APIClient(use_ssh_client=not use_paramiko_ssh, **kwargs)
File “/usr/local/lib/python3.7/dist-packages/docker/api/client.py”, line 197, in init
self._version = self._retrieve_server_version()
File “/usr/local/lib/python3.7/dist-packages/docker/api/client.py”, line 222, in _retrieve_server_version
‘Error while fetching server API version: {0}’.format(e)
docker.errors.DockerException: Error while fetching server API version: UnixHTTPConnectionPool(host=‘localhost’, port=None): Read timed out. (read timeout=240)
Debug result file generated
Got signal: change-password
karen is getting triggered!
New password: Retype new password: passwd: password updated successfully

Docker containers

/home/umbrel/umbrel/scripts/debug: line 125: 12737 Bus error docker ps --format=“table {{.Names}}\t{{.Status}}”

Umbrel logs

ERROR: An HTTP request took too long to complete. Retry with --verbose to obtain debug information.
If you encounter this issue regularly because of slow network conditions, consider setting COMPOSE_HTTP_TIMEOUT to a higher value (current value: 60).

Bitcoin Core logs

ERROR: An HTTP request took too long to complete. Retry with --verbose to obtain debug information.
If you encounter this issue regularly because of slow network conditions, consider setting COMPOSE_HTTP_TIMEOUT to a higher value (current value: 60).

LND logs

ERROR: An HTTP request took too long to complete. Retry with --verbose to obtain debug information.
If you encounter this issue regularly because of slow network conditions, consider setting COMPOSE_HTTP_TIMEOUT to a higher value (current value: 60).

electrs logs

ERROR: An HTTP request took too long to complete. Retry with --verbose to obtain debug information.
If you encounter this issue regularly because of slow network conditions, consider setting COMPOSE_HTTP_TIMEOUT to a higher value (current value: 60).

Tor logs

Attaching to umbrel_app_2_tor_1, tor, umbrel_app_3_tor_1, umbrel_app_tor_1
ERROR: An HTTP request took too long to complete. Retry with --verbose to obtain debug information.
If you encounter this issue regularly because of slow network conditions, consider setting COMPOSE_HTTP_TIMEOUT to a higher value (current value: 60).

App logs

mempool

api_1 | May 1 13:51:00 [40] DEBUG: Updating mempool
api_1 | May 1 13:51:00 [40] DEBUG: Fetched transaction 1 / 5
api_1 | May 1 13:51:00 [40] DEBUG: Fetched transaction 2 / 5
api_1 | May 1 13:51:00 [40] DEBUG: Fetched transaction 3 / 5
api_1 | May 1 13:51:00 [40] DEBUG: Fetched transaction 4 / 5
api_1 | May 1 13:51:00 [40] DEBUG: Fetched transaction 5 / 5
api_1 | May 1 13:51:00 [40] DEBUG: Mempool blocks calculated in 0.004 seconds
api_1 | May 1 13:51:00 [40] DEBUG: New mempool size: 668 Change: 5
api_1 | May 1 13:51:00 [40] DEBUG: Mempool updated in 0.059 seconds
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: Using ARMv8 crc32 instructions
mariadb_1 | 2022-05-01 10:50:04 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: Using Linux native AIO
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: Completed initialization of buffer pool
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: 128 rollback segments are active.
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: Creating shared tablespace for temporary tables
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: Setting file ‘./ibtmp1’ size to 12 MB. Physically writing the file full; Please wait …
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: File ‘./ibtmp1’ size is now 12 MB.
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: 10.5.12 started; log sequence number 170759197; transaction id 925426
mariadb_1 | 2022-05-01 10:50:04 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
mariadb_1 | 2022-05-01 10:50:04 0 [Note] Plugin ‘FEEDBACK’ is disabled.
mariadb_1 | 2022-05-01 10:50:04 0 [Note] Server socket created on IP: ‘::’.
mariadb_1 | 2022-05-01 10:50:04 0 [Warning] ‘proxies_priv’ entry ‘@% root@95b4101f72b6’ ignored in --skip-name-resolve mode.
mariadb_1 | 2022-05-01 10:50:04 0 [Note] Reading of all Master_info entries succeeded
mariadb_1 | 2022-05-01 10:50:04 0 [Note] Added new Master_info ‘’ to hash table
mariadb_1 | 2022-05-01 10:50:04 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-05-01 10:50:04 3 [Warning] Aborted connection 3 to db: ‘unconnected’ user: ‘unauthenticated’ host: ‘10.21.21.27’ (This connection closed normally without authentication)
mariadb_1 | 2022-05-01 10:50:05 4 [Warning] Aborted connection 4 to db: ‘unconnected’ user: ‘unauthenticated’ host: ‘10.21.21.26’ (This connection closed normally without authentication)
mariadb_1 | 2022-05-01 10:50:05 0 [Note] InnoDB: Buffer pool(s) load completed at 220501 10:50:05

pi-hole

server_1 | Existing DNS servers detected in setupVars.conf. Leaving them alone
server_1 | ::: Pre existing WEBPASSWORD found
server_1 | DNSMasq binding to default interface: eth0
server_1 | Added ENV to php:
server_1 | “PHP_ERROR_LOG” => “/var/log/lighttpd/error.log”,
server_1 | “ServerIP” => “0.0.0.0”,
server_1 | “CORS_HOSTS” => “”,
server_1 | “VIRTUAL_HOST” => “umbrel.local”,
server_1 | Using IPv4 and IPv6
server_1 | ::: Preexisting ad list /etc/pihole/adlists.list detected ((exiting setup_blocklists early))
server_1 | https://raw.githubusercontent.com/StevenBlack/hosts/master/hosts
server_1 | ::: Testing pihole-FTL DNS: FTL started!
server_1 | ::: Testing lighttpd config: Syntax OK
server_1 | ::: All config checks passed, cleared for startup …
server_1 | ::: Enabling Query Logging
server_1 | [i] Enabling logging…
[✓] Logging has been enabled!
server_1 | ::: Docker start setup complete
server_1 | Checking if custom gravity.db is set in /etc/pihole/pihole-FTL.conf
server_1 | Pi-hole version is v5.6 (Latest: v5.10)
server_1 | AdminLTE version is v5.8 (Latest: v5.12)
server_1 | FTL version is v5.11 (Latest: v5.15)
server_1 | Container tag is: 2021.10.1
server_1 | [cont-init.d] 20-start.sh: exited 0.
server_1 | [cont-init.d] done.
server_1 | [services.d] starting services
server_1 | Starting pihole-FTL (no-daemon) as root
server_1 | Starting crond
server_1 | Starting lighttpd
server_1 | [services.d] done.

==== Result ====

The debug script did not automatically detect any issues with your Umbrel.

No good hints. But try uninstall Pi Hole and reflash Umbrel with last version to SD card (0.4.17)

1 Like

next time, please post your logs on https://0bin.net for better reading

This could be due to a worn out SD card. Can you please SSH into your Umbrel and run a quick speed test on the SD card using the following commands:

  1. Install hdparm:
sudo apt-get install hdparm
  1. Run speedtest on the SD card:
sudo hdparm -tT /dev/mmcblk0
  1. Run speedtest again to get the average speed:
sudo hdparm -tT /dev/mmcblk0

Then post results of the speed test here. If the speeds are super slow, it’s probably a dead SD card, and just flashing a new one with Umbrel OS will get you going without any data loss (since all data is stored on the SSD).

Thanks for reply. I finally got some time to test it.
Here are the results

Timing cached reads: 2 MB in 180.88 seconds = 11.32 kB/sec
HDIO_DRIVE_CMD(identify) failed: Invalid argument
Timing buffered disk reads: 2 MB in 95.93 seconds = 21.35 kB/sec

Maybe help my figures for comparing:
First pass:
/dev/mmcblk0:
Timing cached reads: 1858 MB in 2.00 seconds = 929.94 MB/sec
HDIO_DRIVE_CMD(identify) failed: Invalid argument
Timing buffered disk reads: 130 MB in 3.01 seconds = 43.22 MB/sec
umbrel@umbrel:~ $ sudo hdparm -tT /dev/mmcblk0

Second pass:
/dev/mmcblk0:
Timing cached reads: 1632 MB in 2.00 seconds = 817.26 MB/sec
HDIO_DRIVE_CMD(identify) failed: Invalid argument
Timing buffered disk reads: 130 MB in 3.01 seconds = 43.23 MB/sec

Using a 16GB Sandisk SD, low cost HC type. With a XC type would get better speeds, I guess.

Also the figures to my SSD:
First pass:
/dev/sda1:
Timing cached reads: 1738 MB in 2.00 seconds = 870.33 MB/sec
Timing buffered disk reads: 248 MB in 3.00 seconds = 82.64 MB/sec

Second pass:
/dev/sda1:
Timing cached reads: 1666 MB in 2.00 seconds = 833.57 MB/sec
Timing buffered disk reads: 252 MB in 3.01 seconds = 83.76 MB/sec