kaspanet / rusty-kaspa

Kaspa full-node and related libraries in the Rust programming language. This is a stable version at the initial rollout phases.
ISC License
371 stars 118 forks source link

[ERROR] thread 'main' panicked at database/src/db/conn_builder.rs:117:114: #475

Closed whileunless closed 1 month ago

whileunless commented 1 month ago

Describe the bug /home/admin/.rusty-kaspa/kaspa-mainnet/logs/rusty-kaspa_err.log:

 `Result::unwrap()` on an `Err` value: Error { message: "IO error: While lock file: /home/admin/.rusty-kaspa/kaspa-mainnet/datadir/meta/LOCK: Resource temporarily unavailable" }

/home/admin/.rusty-kaspa/kaspa-mainnet/logs/rusty-kaspa.log:

2024-05-14 14:43:09.526+01:00 [ERROR] thread 'main' panicked at database/src/db/conn_builder.rs:117:114: called `Result::unwrap()` on an `Err` value: Error { message: "IO error: While lock file: /home/admin/.rusty-kaspa/kaspa-mainnet/datadir/meta/LOCK: Resource temporarily unavailable" }

My kaspad is launched by systemd, this is my service file:

[Unit]
Description=kaspad
After=network.service

[Service]
User=admin

ExecStart=/usr/local/bin/kaspad --utxoindex -d=warn --disable-upnp
Restart=on-failure
RestartSec=100s

[Install]
WantedBy=multi-user.target

systemctl status kaspad give me :

kaspad.service - kaspad
     Loaded: loaded (/etc/systemd/system/kaspad.service; enabled; preset: enabled)
     Active: active (running) since Tue 2024-05-14 14:26:29 BST; 25min ago
   Main PID: 2962 (kaspad)
      Tasks: 53 (limit: 9259)
        CPU: 27min 45.675s
     CGroup: /system.slice/kaspad.service
             └─2962 /usr/local/bin/kaspad --utxoindex -d=warn --disable-upnp

May 14 14:26:29 raspberrypi systemd[1]: Started kaspad.service - kaspad.
May 14 14:26:36 raspberrypi kaspad[2962]: 2024-05-14 14:26:36.779+01:00 [WARN ] P2P, got reject message: P2P pr>
~
~

and journalctl - kaspad returns:

May 14 14:26:29 raspberrypi systemd[1]: Started kaspad.service - kaspad.
May 14 14:26:36 raspberrypi kaspad[2962]: 2024-05-14 14:26:36.779+01:00 [WARN ] P2P, got reject message: P2P pr>

To Reproduce Steps to reproduce the behavior:

  1. launch kaspad --utxoindex -d=warn --disable-upnp as a systemd daemon
  2. take a look at the logs
  3. systemctl status kaspad
  4. joornalctl -u kaspad

Expected behavior I expected no errors in the logs.

Desktop (please complete the following information):

Additional context The node seems to sync despite the error I get in the logs as evidenced by the growing from minute to minute size of datadir

aspect commented 1 month ago

No idea what the cause can be right now, but

1) can you please try the following? (this is more of a shot in the dark, but could be somehow PI-latency related..)

[Service]
Type=simple

2) your systemd service declares User=j but the logs are failing to access /home/admin/.rusty-kaspa ... how can this be? ...are you sure another instance is not already running? (ps -ax | grep kaspad to check) ...

So far this looks environmental....

whileunless commented 1 month ago
  1. your systemd service declares User=j but the logs are failing to access /home/admin/.rusty-kaspa ... how can this be? ...are you sure another instance is not already running? (ps -ax | grep kaspad to check) ...

So far this looks environmental....

user is admin not j. I didn't want to leak my username here. I am positive, there is only one instance running.

whileunless commented 1 month ago

No idea what the cause can be right now, but

  1. can you please try the following? (this is more of a shot in the dark, but could be somehow PI-latency related..)
[Service]
Type=simple

I get this:

May 14 15:20:29 raspberrypi systemd[1]: /etc/systemd/system/kaspad.service:4: Assignment outside of section. Ignoring.
aspect commented 1 month ago

Are you able to run it manually, outside of systemd?

whileunless commented 1 month ago

Are you able to run it manually, outside of systemd?

No. kaspad --utxoindex -d=warn --disable-upnp gives me:

2024-05-14 17:30:29.152+01:00 [ERROR] thread 'main' panicked at database/src/db/conn_builder.rs:117:114: called `Result::unwrap()` on an `Err` value: Error { message: "IO error: While lock file: /home/admin/.rusty-kaspa/kaspa-mainnet/datadir/meta/LOCK: Resource temporarily unavailable" }
thread 'main' panicked at database/src/db/conn_builder.rs:117:114:
called `Result::unwrap()` on an `Err` value: Error { message: "IO error: While lock file: /home/admin/.rusty-kaspa/kaspa-mainnet/datadir/meta/LOCK: Resource temporarily unavailable" }
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Exiting...

and RUST_BACKTRACE=full kaspad --utxoindex -d=warn --disable-upnp gave me


2024-05-14 17:34:01.072+01:00 [ERROR] thread 'main' panicked at database/src/db/conn_builder.rs:117:114: called `Result::unwrap()` on an `Err` value: Error { message: "IO error: While lock file: /home/admin/.rusty-kaspa/kaspa-mainnet/datadir/meta/LOCK: Resource temporarily unavailable" }
thread 'main' panicked at database/src/db/conn_builder.rs:117:114:
called `Result::unwrap()` on an `Err` value: Error { message: "IO error: While lock file: /home/admin/.rusty-kaspa/kaspa-mainnet/datadir/meta/LOCK: Resource temporarily unavailable" }
stack backtrace:
   0:     0x5556321f2724 - <unknown>
   1:     0x555631203150 - <unknown>
   2:     0x5556321eefbc - <unknown>
   3:     0x5556321f252c - <unknown>
   4:     0x5556321f4158 - <unknown>
   5:     0x5556321f3db4 - <unknown>
   6:     0x5556316afd14 - <unknown>
   7:     0x5556321f46f8 - <unknown>
   8:     0x5556321f4478 - <unknown>
   9:     0x5556321f2bd4 - <unknown>
  10:     0x5556321f421c - <unknown>
  11:     0x5556310d5df4 - <unknown>
  12:     0x5556310d6114 - <unknown>
  13:     0x5556316ba3c0 - <unknown>
  14:     0x555631fcedf8 - <unknown>
  15:     0x555631fce0d8 - <unknown>
  16:     0x555631fbd1b4 - <unknown>
  17:     0x555631fbb650 - <unknown>
  18:     0x555631fbcdb4 - <unknown>
  19:     0x5556321e7770 - <unknown>
  20:     0x555631fbd5ac - <unknown>
  21:     0x7ffec4017780 - __libc_start_call_main
                               at ./csu/../sysdeps/nptl/libc_start_call_main.h:58:16
  22:     0x7ffec4017858 - __libc_start_main_impl
                               at ./csu/../csu/libc-start.c:360:3
  23:     0x5556311637b0 - <unknown>
  24:                0x0 - <unknown>
Exiting...
aspect commented 1 month ago

Can you delete the ~/.rusty-kaspa folder and try again? Do you get the same error?

whileunless commented 1 month ago

I just realized that I did have multiple instance running, I had two separate service files of two different names for the same kaspad daemon. ps -ax | grep kaspad was not detecting it because they were restarting infrequently, every 100s. Thank you so much for your help and apologies for wasting your precious time.