Opening a channel with "tady je slushovo" (still) crashes my node

Issue and Steps to Reproduce

Last year, I could never open a channel with "tady je slushovo".

ID: 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469

because my node would crash and I always got the same response:

lightning-cli fundchannel 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 all

lightning-cli: reading response: Success

and then my node would crash.

Today I thought let's give it a try maybe things have changed but my node still crashes in exactly the same manner. After a restart my node runs normally again. It's the only node that gives me this problem. This time I decided to open an issue about it. The relevant part of the crash.log:

+93891.109728798 lightning_gossipd(17817):DEBUG: Received channel_update for channel 551825x527x1/1 now ACTIVE was DISABLED (from subdaemon)
+93895.453705678 lightning_gossipd(17817):DEBUG: Received channel_update for channel 550635x685x1/1 now ACTIVE was ACTIVE (from subdaemon)
+93895.454348414 lightning_gossipd(17817):DEBUG: Received channel_update for channel 550602x395x0/1 now ACTIVE was ACTIVE (from subdaemon)
+93896.492888423 lightningd(17805):jcon fd 32:IO_IN: 7b20226a736f6e72706322203a2022322e30222c20226d6574686f6422203a202266756e646368616e6e656c222c2022696422203a20226c696768746e696e67
+93896.492920499 lightningd(17805):jcon fd 32:IO_IN: 2d636c692d37373837222c2022706172616d7322203a5b2022303263646638336566386534353930386231303932313235643235633638646365633737353163
+93896.492953246 lightningd(17805):jcon fd 32:IO_IN: 613864333966353537373735636438343265356263313237343639222c2022616c6c225d207d
+93897.610425409 lightning_gossipd(17817):DEBUG: Received channel_update for channel 536421x2223x0/0 now DISABLED was DISABLED (from subdaemon)
+93897.859212941 lightning_hsmd(17815):DEBUG: Client: Received message 19 from client
+93897.970652527 lightningd(17805):DEBUG: 03b7ce4de04544e081b1910688f0a5b9742c065ec2d11394358d2de524d23c4504
+93898.301639775 lightningd(17805):BROKEN: wallet_channel_insert: UNIQUE constraint failed: peers.node_id
+93898.888737289 lightningd(17805):BROKEN: FATAL SIGNAL 6 (version v0.6.3rc1-104-g287af7b)
+93898.888766664 lightningd(17805):BROKEN: backtrace: common/daemon.c:45 (crashdump) 0x436027
+93898.888777811 lightningd(17805):BROKEN: backtrace: (null):0 ((null)) 0x7fa3cc8c74af
+93898.888784356 lightningd(17805):BROKEN: backtrace: (null):0 ((null)) 0x7fa3cc8c7428
+93898.888791236 lightningd(17805):BROKEN: backtrace: (null):0 ((null)) 0x7fa3cc8c9029
+93898.888798203 lightningd(17805):BROKEN: backtrace: lightningd/log.c:624 (fatal) 0x41a017
+93898.888805587 lightningd(17805):BROKEN: backtrace: wallet/db.c:448 (db_exec_prepared_) 0x45da1b
+93898.888818074 lightningd(17805):BROKEN: backtrace: wallet/wallet.c:1049 (wallet_channel_insert) 0x464854
+93898.888828042 lightningd(17805):BROKEN: backtrace: lightningd/opening_control.c:213 (wallet_commit_channel) 0x41c244
+93898.888835439 lightningd(17805):BROKEN: backtrace: lightningd/opening_control.c:333 (opening_funder_finished) 0x41c952
+93898.888842157 lightningd(17805):BROKEN: backtrace: lightningd/opening_control.c:660 (openingd_msg) 0x41d754
+93898.888850123 lightningd(17805):BROKEN: backtrace: lightningd/subd.c:474 (sd_msg_read) 0x430779
+93898.888857647 lightningd(17805):BROKEN: backtrace: lightningd/subd.c:302 (read_fds) 0x43010f
+93898.888864155 lightningd(17805):BROKEN: backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x473995
+93898.888870345 lightningd(17805):BROKEN: backtrace: ccan/ccan/io/io.c:395 (do_plan) 0x47448a
+93898.888877427 lightningd(17805):BROKEN: backtrace: ccan/ccan/io/io.c:405 (io_ready) 0x4744c8
+93898.888883730 lightningd(17805):BROKEN: backtrace: ccan/ccan/io/poll.c:310 (io_loop) 0x476028
+93898.888889995 lightningd(17805):BROKEN: backtrace: lightningd/lightningd.c:827 (main) 0x41813b
+93898.888897345 lightningd(17805):BROKEN: backtrace: (null):0 ((null)) 0x7fa3cc8b282f
+93898.888903974 lightningd(17805):BROKEN: backtrace: (null):0 ((null)) 0x4037f8
+93898.888910109 lightningd(17805):BROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff

getinfo output

{
"id": "02c5371591b640da03f9a645e2ddfa5620d8537388b03ddd524d36766c0f550db0",
"alias": "Bitkoins.nl",
"color": "23354d",
"num_peers": 63,
"num_pending_channels": 3,
"num_active_channels": 58,
"num_inactive_channels": 3,
"address": [
{
"type": "ipv4",
"address": "82.217.214.215",
"port": 9735
},
{
"type": "torv2",
"address": "id3hrvkqgdgzf42d.onion",
"port": 9735
}
],
"binding": [
{
"type": "ipv6",
"address": "::",
"port": 9735
},
{
"type": "ipv4",
"address": "0.0.0.0",
"port": 9735
}
],
"version": "v0.6.3rc1-104-g287af7b",
"blockheight": 560226,
"network": "bitcoin",
"msatoshi_fees_collected": 29554
}

93898.301639775 lightningd(17805):BROKEN: wallet_channel_insert: UNIQUE constraint failed: peers.node_id

Looks like there is still an old entry in c-lightning's database of a channel with that node_id, does the channel show up in listpeers ?

If you have a developer version of c-lightning, you could try to remove it using dev-forget-channel and then try again.

Yes, it (edit: the node id) does show up in listpeers. When I try to disconnect it with the regular disconnect command (even with force set to true) it reconnects within a view seconds. dev-forget-channel isn't available to me so apparently I don't have the developer version of c-lightning.

EDIT: the node id shows up in listpeers but it has no channels:

    {
      "id": "02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469",
      "connected": true,
      "netaddr": [
        "[::ffff:109.239.79.181]:52078"
      ],
      "global_features": "",
      "local_features": "82",
      "globalfeatures": "",
      "localfeatures": "82",
      "channels": [
      ]
    }

Looking at your version "version": "v0.6.3rc1-104-g287af7b" is fairly recent I assume you build it yourself. If you use ./configure --enable-developer and then make, it will build the developer version.

Thanks! I already did that after your suggestion the first time but (as far as I know), I couldn't use dev-forget-channel because I have no channel with "tady je slushhovo" "channels": [] and dev-forget-channel needs a channel id. Right?

[ctrlbreak-]

You should still be able to call dev-forget-channel with just the peers PubKEY or ID. It looks like specifying a short channel ID is optional.

"command": "dev-forget-channel id [short_channel_id] [force]", "description": "Forget the channel with peer {id}, ignore UTXO check with {force}='true'.",

Fingers crossed it removes the errant DB record for you! :-)

The problem is, executing:

lightning-cli dev-forget-channel 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469

gives me:

{ "code" : -1, "message" : "No channels matching that short_channel_id" }

and so does

lightning-cli dev-forget-channel id=02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469

That's why I thought I needed a channel id.

{ "code" : -1, "message" : "No channels matching that short_channel_id" }

that is indeed a confusing message when you supplied dev-forget-channel with a peer id.

Thanks for reporting so far! If you are willing to investigate further, and have sqlite3 available, you could maybe try this inside $HOME/.lightning:

sqlite3 -header -line lightningd.sqlite3 'SELECT id FROM peers WHERE lower(hex(node_id))="02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469"'

which should return the (dbid) id of the "tady je slushovo" peer and then do another query:

sqlite3 -header -line lightningd.sqlite3 'SELECT id, state FROM channels WHERE peer_id=<id>'

where you replace <id> with the one found earlier. According to the result of listpeers and dev-forget-channel it should return empty.

It would be strange if there is a node_id entry in the peers table in the db but not an associated channel in the channels table because they are inserted into db right after each other here:

lightning/wallet/wallet.c

Lines 1042 to 1055 in c029f2f

	if (chan->peer->dbid == 0) {
	/* Need to create the peer first */
	stmt = db_prepare(w->db, "INSERT INTO peers (node_id, address) VALUES (?, ?);");
	sqlite3_bind_pubkey(stmt, 1, &chan->peer->id);
	sqlite3_bind_text(stmt, 2,
	type_to_string(tmpctx, struct wireaddr_internal, &chan->peer->addr),
	-1, SQLITE_TRANSIENT);
	db_exec_prepared(w->db, stmt);
	chan->peer->dbid = sqlite3_last_insert_rowid(w->db->sql);
	}
	/* Insert a stub, that we update, unifies INSERT and UPDATE paths */
	stmt = db_prepare(w->db, "INSERT INTO channels ("
	"peer_id, first_blocknum, id) VALUES (?, ?, ?);");

I did it quickly this morning, just before going to work. This is the result:

sqlite3 -header -line lightningd.sqlite3 'SELECT id FROM peers WHERE lower(hex(node_id))="02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469"'
   id = 33

sqlite3 -header -line lightningd.sqlite3 'SELECT id, state FROM channels WHERE peer_id=33'

Indeed, the last query returned nothing.

@SimonVrouwe I get a similar result (last query returning nothing) for another node I had issues with (closed issue #2227), while nodes that function normally return a status. So it seems I have a problem in my database that doesn't however give me any problems if I don't try to connect to those 2 nodes. It would be nice if there was a way to remove them from the database. Thanks a lot for all the help.

@SimonVrouwe I stopped lightning, copied .lightning, googled a bit and tried to remove the peer myself via:

sqlite3 -header -line lightningd.sqlite3 'DELETE FROM peers WHERE id=33'

and the ID was gone. I then (fingers crossed)restarted lightning and opened a small channel with the removed node and everything seems to be working just fine! You can observe the channel with "tady je slushhovo" on my website. Thanks for all the help. I'm going to close this issue tomorrow.

Nice, just one last question. Do you remember what c-lightning version you used (or how long ago) in the first attempt to open a channel with "tady je slushhovo"? That may help us trying to find the bug. Groetjes en .. de mazzel :)

No, sorry, that's really too long ago and I'm addicted to updating c-lightning. Now, that you read my comments, I'm going to close this issue. Groetjes terug, nogmaals bedankt en we komen elkaar vast nog wel eens ergens tegen.