CLN doesn't start after updating from v0.12.1 to v22.11.1

[BTCBellyButton]

Issue and Steps to Reproduce

Updated from v0.12.1 to v22.11.1 using clightning-v22.11.1-Ubuntu-20.04.tar.xz when starting up via the very same systemd service file I got this:

sudo systemctl status lightningd.service
● lightningd.service - Core Lightning daemon
     Loaded: loaded (/etc/systemd/system/lightningd.service; disabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Tue 2023-02-07 17:31:25 EST; 19s ago
    Process: 5187 ExecStart=/usr/bin/lightningd --lightning-dir=/mnt/md0/C-Lightning/ --daemon --log-file=/mnt/md0/C-Lightning/log (code=exited, status=1/FAILURE)

Feb 07 17:31:25 BTCPayServer systemd[1]: lightningd.service: Scheduled restart job, restart counter is at 5.
Feb 07 17:31:25 BTCPayServer systemd[1]: Stopped Core Lightning daemon.
Feb 07 17:31:25 BTCPayServer systemd[1]: lightningd.service: Start request repeated too quickly.
Feb 07 17:31:25 BTCPayServer systemd[1]: lightningd.service: Failed with result 'exit-code'.
Feb 07 17:31:25 BTCPayServer systemd[1]: Failed to start Core Lightning daemon.

I then added

RestartSec=60s
StartLimitInterval=10

But CLN does not start.

LOG FILE:

2023-02-07T23:52:56.245Z DEBUG   lightningd: Opened log file /mnt/md0/C-Lightning/log
2023-02-07T23:52:56.245Z DEBUG   lightningd: Opened log file /mnt/md0/C-Lightning/log
2023-02-07T23:52:56.247Z DEBUG   plugin-manager: started(9326) /usr/libexec/c-lightning/plugins/autoclean
2023-02-07T23:52:56.249Z DEBUG   plugin-manager: started(9327) /usr/libexec/c-lightning/plugins/chanbackup
2023-02-07T23:52:56.252Z DEBUG   plugin-manager: started(9328) /usr/libexec/c-lightning/plugins/bcli
2023-02-07T23:52:56.255Z DEBUG   plugin-manager: started(9329) /usr/libexec/c-lightning/plugins/commando
2023-02-07T23:52:56.258Z DEBUG   plugin-manager: started(9330) /usr/libexec/c-lightning/plugins/fetchinvoice
2023-02-07T23:52:56.261Z DEBUG   plugin-manager: started(9331) /usr/libexec/c-lightning/plugins/funder
2023-02-07T23:52:56.264Z DEBUG   plugin-manager: started(9332) /usr/libexec/c-lightning/plugins/topology
2023-02-07T23:52:56.266Z DEBUG   plugin-manager: started(9333) /usr/libexec/c-lightning/plugins/keysend
2023-02-07T23:52:56.269Z DEBUG   plugin-manager: started(9334) /usr/libexec/c-lightning/plugins/offers
2023-02-07T23:52:56.271Z DEBUG   plugin-manager: started(9335) /usr/libexec/c-lightning/plugins/pay
2023-02-07T23:52:56.273Z DEBUG   plugin-manager: started(9336) /usr/libexec/c-lightning/plugins/txprepare
2023-02-07T23:52:56.275Z DEBUG   plugin-manager: started(9337) /usr/libexec/c-lightning/plugins/spenderp
2023-02-07T23:52:56.278Z DEBUG   plugin-manager: started(9338) /usr/libexec/c-lightning/plugins/cln-grpc
2023-02-07T23:52:56.280Z DEBUG   plugin-manager: started(9339) /usr/libexec/c-lightning/plugins/bookkeeper
2023-02-07T23:52:56.283Z DEBUG   plugin-manager: started(9341) /home/go/c-lightning-REST/plugin.js
2023-02-07T23:52:56.328Z DEBUG   lightningd: io_break: check_plugins_manifests
2023-02-07T23:52:56.328Z DEBUG   lightningd: io_loop_with_timers: plugins_init
2023-02-07T23:52:56.329Z DEBUG   lightningd: testing /usr/libexec/c-lightning/lightning_channeld
2023-02-07T23:52:56.331Z DEBUG   lightningd: testing /usr/libexec/c-lightning/lightning_closingd
2023-02-07T23:52:56.332Z DEBUG   lightningd: testing /usr/libexec/c-lightning/lightning_connectd
2023-02-07T23:52:56.333Z DEBUG   lightningd: testing /usr/libexec/c-lightning/lightning_gossipd
2023-02-07T23:52:56.335Z DEBUG   lightningd: testing /usr/libexec/c-lightning/lightning_hsmd
2023-02-07T23:52:56.336Z DEBUG   lightningd: testing /usr/libexec/c-lightning/lightning_onchaind
2023-02-07T23:52:56.338Z DEBUG   lightningd: testing /usr/libexec/c-lightning/lightning_openingd
2023-02-07T23:52:56.340Z DEBUG   hsmd: pid 9355, msgfd 49

Had to go back to v0.12.1

getinfo output

{
   "id": "redacted",
   "alias": "...",
   "color": "0228cc",
   "num_peers": 10,
   "num_pending_channels": 0,
   "num_active_channels": 10,
   "num_inactive_channels": 0,
   "address": [
      {
         "type": "ipv4",
         "address": "redacted",
         "port": 9735
      },
      {
         "type": "torv3",
         "address": "redacted.onion",
         "port": 9735
      }
   ],
   "binding": [
      {
         "type": "ipv6",
         "address": "::",
         "port": 9735
      },
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9735
      }
   ],
   "version": "0.12.1",
   "blockheight": 775505,
   "network": "bitcoin",
   "msatoshi_fees_collected": 25257744,
   "fees_collected_msat": "25257744msat",
   "lightning-dir": "/mnt/md0/C-Lightning/bitcoin",
   "our_features": {
      "init": "08a000080a69a2",
      "node": "88a000080a69a2",
      "channel": "",
      "invoice": "02000000024100"
   }
}

[vincenzopalazzo]

inside the log there is any BROKEN line?

[BTCBellyButton]

None. That above is all I got in the log.

[BTCBellyButton]

lightnind.service file:

[Unit]
Description=Core Lightning daemon
Requires=bitcoind.service
After=bitcoind.service
Wants=network-online.target
After=network-online.target

[Service]
#ExecStart=/usr/bin/lightningd --daemon --conf /etc/lightningd/lightningd.conf --pid-file=/run/lightningd/lightningd.pid
ExecStart=/usr/bin/lightningd --lightning-dir=/mnt/md0/C-Lightning/ --daemon --log-file=/mnt/md0/C-Lightning/log --pid-file=/run/lightningd/lightningd.pid

RuntimeDirectory=lightningd

User=go
Group=go

Type=forking
PIDFile=/run/lightningd/lightningd.pid
Restart=on-failure
RestartSec=60s
StartLimitInterval=10

# Hardening measures
####################

# Provide a private /tmp and /var/tmp.
PrivateTmp=true

# Mount /usr, /boot/ and /etc read-only for the process.
ProtectSystem=full

# Disallow the process and all of its children to gain
# new privileges through execve().
NoNewPrivileges=true

# Use a new /dev namespace only populated with API pseudo devices
# such as /dev/null, /dev/zero and /dev/random.
PrivateDevices=true

# Deny the creation of writable and executable memory mappings.
#MemoryDenyWriteExecute=true

[Install]
WantedBy=multi-user.target

[vincenzopalazzo]

I you ran the following command by removing the log file from the etc/lightningd/lightningd.conf what is the output in your terminal?

lightningd -lightning-dir=/mnt/md0/C-Lightning/

[BTCBellyButton]

Ok. I got this:

Refusing to irreversibly upgrade db from version 199 to 212 in non-final version 22.11.1 (use --database-upgrade=true to override)

[vincenzopalazzo]

this is a bug fixed in the next release, you should add as a parameter also --database-upgrade=true, this give permission to core lightning to upgrade the database!

[BTCBellyButton]

Question. Why "non-final version 22.11.1"? What is considered "final"?

[vincenzopalazzo]

Just a bug fixed in https://github.com/ElementsProject/lightning/pull/5880

[BTCBellyButton]

this is a bug fixed in the next release, you should add as a parameter also --database-upgrade=true

Just a bug fixed in #5880

Cool. Thanks! DB updated. All seems good now.

Maybe in the meantime it'd help putting a note on the release page?

[vincenzopalazzo]

Maybe in the meantime it'd help putting a note on the release page?

Unfortunately, we no longer need this note because in the next couple of weeks, we had a new release v23.02 and this bug is considered just a bad dream!

[BTCBellyButton]

Not bad at all. I learned something new about you doc management process. :)