Learn how to test libraries/apps that interact with CLN nodes

LIVE #14・September 28, 2023

In this live we see how how to test lnsocket/go library using pyln-testing library.

Transcript with corrections and improvements

Tests are tools like any other.

They are useful in at least two ways:

  1. For designing: if we have the chance to start building our program/system writing the tests at the same time, we can see the parts that shouldn't be together, separate them and test them separately,

  2. For regression: once we have our tests in place, we can add some features or simplify/rewrite some ugly parts fearlessly. Running the tests will tell us if we broke something!

As a tool we can use them to test the dependencies of our program on other libraries or applications.

In this live we try to see how can we ensure that a library depending on Core Lightning nodes continues to work as expected when we switch from a version of Core Lightning to another.

To do so we take lnsocket commando client library as an example and we write some tests with pyln-testing Python library.

That library allows:

  • to spin up nodes running on a regtest chain,

  • to manage those nodes with Python and

  • to test their behavior.

For instance we can ask a node to generate an invoice and another to pay that invoice and finally check if that invoice has been effectively paid.

So if we write a library that talks to a node we can use pyln-testing to mock the Lightning Network, connect our library to one of the nodes and test our library's behavior.

Black box tests in Core Lightning

In the tests directory of Core Lightning we can find a lot of tests written with pyln-testing. This is a good place to start to get inspired. For instance:

In number this is what we have, 22494 lines of Python code that we can leverage to write our tests: 

◉ tony@tony:~/clnlive/lightning/tests:[git»(HEAD detached at v23.08.1)]
$ cloc .
     499 text files.
     463 unique files.
     376 files ignored.

github.com/AlDanial/cloc v 1.90  T=0.69 s (180.3 files/s, 53330.0 lines/s)
-------------------------------------------------------------------------------
Language                     files          blank        comment           code
-------------------------------------------------------------------------------
Python                          97           6910           5755          22494
C                               20            220            145           1054
C/C++ Header                     2             35             39            128
make                             2             10              1             73
JSON                             2              0              0             63
Bourne Shell                     2              9              3             35
-------------------------------------------------------------------------------
SUM:                           125           7184           5943          23847
-------------------------------------------------------------------------------

lnsocket

A few months ago, when I was trying to fix something in lnsocket (it happened that there were already a PR open with the fix) I wrote a test using pyln-testing that we are going to use today.

We are going to look at it, but first what is lnsocket written for?

The Go lnsocket library lets us send commando messages to lightning nodes, so with the right hostname and the name of the node (a rune also), we can connect to that node and send commando messages.

And the commando plugin allows to run commands even if we are not the node.

With lnsocket we are an application, we connect to the node and we say for example "Hey, please run some bookkeeper commands and send me back the response".

For an example see Simple CLN bookkeeper web app powered by lnsocket & Golang - part 1.

Deprecate commando JSON commands without an id in v23.02

If we are the author of that library (lnsocket), at some point we might want to test that library against Core Lightning to be sure that when Core Lightning changes, our library continues to work as expected.

For instance, in v23.02 release, something changed in the commando plugin that affects libraries that send commando messages like lnsocket: 

Deprecated

Note: You should always set allow-deprecated-apis=false to test for
changes.

- ...
- plugins: commando JSON commands without an id (see
  doc/lightningd-rpc.7.md for how to construct a good id
  field). ([#5866])

What does that mean?

Before v23.02, the json part of a commando message must contain:

  • the method we want to run,

  • a rune that authorizes to run that method and

  • its parameters.

Now, from v23.02, in that json part we also have to pass and id.

So if our library doesn't send commando messages with that id we'll get an error.

With no test at all (and if we don't read Core Lightning changelog) we won't catch that change that breaks our library.

Be if we wrote some tests beforehand (they don't have to be fancy nor exhaustive), we could catch that error due to the library's dependency on Core Lightning nodes.

Having those tests in place and running it regularly (for each new release of CLN for instance) and adapting our library if necessary, we could prevent to pass the error to the library's user that are switching to a new version of Core Lightning.

Note that with Core Lightning deprecation cycle, when a 'feature' is deprecated we can still use it during some time by setting allow-deprecated-apis config option to true

Encode function in lnsocket/go

The function Encode in lnsocket:go/lnsocket.go file was affected by Core Lightning deprecation described above and has been fixed by adding the line buf.WriteString("\",\"id\":\"d0\",\"jsonrpc\":\"2.0\"}") as we can see here: 

func (msg *CommandoMsg) Encode(buf *bytes.Buffer, pver uint32) error {
    if err := lnwire.WriteUint64(buf, msg.RequestId); err != nil {
        return err
    }

    buf.WriteString("{\"method\": \"")
    buf.WriteString(msg.Method)
    buf.WriteString("\",\"params\":")
    buf.WriteString(msg.Params)
    buf.WriteString(",\"rune\":\"")
    buf.WriteString(msg.Rune)
    buf.WriteString("\",\"id\":\"d0\",\"jsonrpc\":\"2.0\"}")

    return nil
}

Testing lnsocket/go

Now the question is how can we write a test using pyln-testing library to test lnsocket/go library that would have passed before CLN v23.02 and failed when we switched to CLN v23.02?

If the library that we want to test was written in Python this would be easier because we could use the library directly in the test program (written in Python).

But this in not the case of lnsocket/go.

No problem, we still can write an application or a small script that uses our library and prints out some data. Then we run that application in our test connecting it to a regtest node started by pyln-testing and we retrieve its output and finally check it against whatever we want.

getinfo.go script using lnsocket/go library

We've already clone lnsocket repository under lnsocket directory. Let's jump into its go subdirectory where lnsocket/go is implemented: 

◉ tony@tony:~/clnlive:
$ cd lnsocket/go/

Then we copy the test directory that contains the tests we are going to use today in the current directory: 

◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ cp -r ../../test/ .
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ ls
test/  go.mod  go.sum  lnsocket.go

Then we start 2 lightning nodes running on regtest using contrib/startup_regtest.sh script from lightning repository and print getinfo information of l1 node: 

◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ source ../../lightning/contrib/startup_regtest.sh
...
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ start_ln
...
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ alias l1-cli
alias l1-cli='lightning-cli --lightning-dir=/tmp/l1-regtest'
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ l1-cli getinfo
{
   "id": "0252b837dc56fc76497f8e485993494bcaeaa1eca095c332bc8aac4922ce4d5d85",
   "alias": "PEEVEDSPAWN",
   "color": "0252b8",
   "num_peers": 0,
   "num_pending_channels": 0,
   "num_active_channels": 0,
   "num_inactive_channels": 0,
   "address": [],
   "binding": [
      {
         "type": "ipv4",
         "address": "127.0.0.1",
         "port": 7171
      }
   ],
   "version": "v23.08.1",
   "blockheight": 1,
   "network": "regtest",
   "fees_collected_msat": 0,
   "lightning-dir": "/tmp/l1-regtest/regtest",
   "our_features": {
      "init": "08a0000a0269a2",
      "node": "88a0000a0269a2",
      "channel": "",
      "invoice": "02000002024100"
   }
}

Now we run getinfo.go program in the test directory which takes 3 arguments, the node id, the hostname of the node and a rune and returns the node id retrieved using lnsocket/go library: 

package main

import (
    "fmt"
    "os"
    "github.com/tidwall/gjson"
    lnsocket "github.com/jb55/lnsocket/go"
)

func main() {
    nodeid := os.Args[1]
    hostname := os.Args[2]
    rune := os.Args[3]
    ln := lnsocket.LNSocket{}
    ln.GenKey()
    err := ln.ConnectAndInit(hostname, nodeid)
    if err != nil {
        panic(err)
    }
    body, err := ln.Rpc(rune, "getinfo", "[]")
    if err != nil {
        panic(err)
    }
    getinfoNodeid := gjson.Get(body, "result.id").String()
    fmt.Printf(getinfoNodeid)
}

To do so, we create a rune on l1 node 

◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ l1-cli createrune
{
   "rune": "srRc7kl_g-_7aRfsfhG_Y0PdKzgrTgEDQY7dG7P2SWM9MA==",
   "unique_id": "0",
   "warning_unrestricted_rune": "WARNING: This rune has no restrictions! Anyone who has access to this rune could drain funds from your node. Be careful when giving this to apps that you don't trust. Consider using the restrictions parameter to only allow access to specific rpc methods."
}

we install the program dependencies 

◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ go get github.com/tidwall/gjson
go: added github.com/tidwall/gjson v1.17.0
go: added github.com/tidwall/match v1.1.1
go: added github.com/tidwall/pretty v1.2.0

and we run it: 

◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ cd test/
◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ go run getinfo.go 0252b837dc56fc76497f8e485993494bcaeaa1eca095c332bc8aac4922ce4d5d85 127.0.0.1:7171 srRc7kl_g-_7aRfsfhG_Y0PdKzgrTgEDQY7dG7P2SWM9MA==
0252b837dc56fc76497f8e485993494bcaeaa1eca095c332bc8aac4922ce4d5d85

As we are running CLN v23.08.1 and the patched version of lnsocket/go, everything worked well.

Using getinfo.go in the test

Now we look at test_lnsocket.py test file written with pyln-testing library and that uses getinfo.go program: 

from pyln.testing.fixtures import *
import os

def test_getinfo(node_factory):
    node = node_factory.get_node()
    node_info = node.rpc.getinfo()
    node_id = node_info["id"]
    node_address = node_info["binding"][0]["address"]
    node_port = node_info["binding"][0]["port"]
    node_hostname = node_address + ":" + str(node_port)
    # when `commando-rune` deprecated, we'll use `createrune` instead
    # rune = node.rpc.createrune()["rune"]
    rune = node.rpc.commando_rune()["rune"]
    getinfo_cmd = f"go run getinfo.go {node_id} {node_hostname} {rune}"
    assert os.popen(getinfo_cmd).read() == node_id

Note that we test lnsocket/go library by testing getinfo.go program behavior.

Let's install pyln-testing in a Python virtual environment 

◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ python -m venv .venv
◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ source .venv/bin/activate
(.venv) ◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ pip install pyln-testing
...

and run that test: 

(.venv) ◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ pytest test_lnsocket.py
======================================= test session starts ========================================
platform linux -- Python 3.10.12, pytest-7.4.2, pluggy-1.3.0
rootdir: /home/tony/clnlive/lnsocket/go/test
collected 1 item

test_lnsocket.py .                                                                           [100%]

======================================== 1 passed in 24.12s ========================================

As we are running CLN v23.08.1 and the patched version of lnsocket/go, the test passes.

Failing test at with lnsocket at commit b7d9bce

Now, let's checkout at commit b7d9bce in lnsocket repository.

The function Encode no longer include an id field in the json part of the commando message: 

func (msg *CommandoMsg) Encode(buf *bytes.Buffer, pver uint32) error {
    if err := lnwire.WriteUint64(buf, msg.RequestId); err != nil {
        return err
    }

    buf.WriteString("{\"method\": \"")
    buf.WriteString(msg.Method)
    buf.WriteString("\",\"params\":")
    buf.WriteString(msg.Params)
    buf.WriteString(",\"rune\":\"")
    buf.WriteString(msg.Rune)
    buf.WriteString("\"}")

    return nil
}

And as we are running CLN v23.08.1 which expects that id, the test fails: 

(.venv) ◉ tony@tony:~/clnlive/lnsocket/go/test:[git»(HEAD detached at b7d9bce)]
$ pytest test_lnsocket.py
======================================= test session starts ========================================
platform linux -- Python 3.10.12, pytest-7.4.2, pluggy-1.3.0
rootdir: /home/tony/clnlive/lnsocket/go/test
collected 1 item

test_lnsocket.py F                                                                           [100%]

============================================= FAILURES =============================================
___________________________________________ test_getinfo ___________________________________________

node_factory = <pyln.testing.utils.NodeFactory object at 0x7f9251624430>

    def test_getinfo(node_factory):
        node = node_factory.get_node()
        node_info = node.rpc.getinfo()
        node_id = node_info["id"]
        node_address = node_info["binding"][0]["address"]
        node_port = node_info["binding"][0]["port"]
        node_hostname = node_address + ":" + str(node_port)
        # when `commando-rune` deprecated, we'll use `createrune` instead
        # rune = node.rpc.createrune()["rune"]
        rune = node.rpc.commando_rune()["rune"]
        getinfo_cmd = f"go run getinfo.go {node_id} {node_hostname} {rune}"
>       assert os.popen(getinfo_cmd).read() == node_id
E       AssertionError: assert '' == '0266e4598d1d...283b315c03518'
E         - 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518

test_lnsocket.py:15: AssertionError
-------------------------------------- Captured stdout setup ---------------------------------------
Running tests in /tmp/ltests-km5ej2sv
--------------------------------------- Captured stdout call ---------------------------------------
lightningd-1 2023-09-28T14:51:34.248Z DEBUG   lightningd: Opened log file -
lightningd-1 2023-09-28T14:51:34.248Z DEBUG   lightningd: Opened log file /tmp/ltests-km5ej2sv/test_getinfo_1/lightning-1/log
lightningd-1 2023-09-28T14:51:34.251Z DEBUG   plugin-manager: started(1683553) /usr/local/libexec/c-lightning/plugins/autoclean
lightningd-1 2023-09-28T14:51:34.253Z DEBUG   plugin-manager: started(1683554) /usr/local/libexec/c-lightning/plugins/chanbackup
lightningd-1 2023-09-28T14:51:34.257Z DEBUG   plugin-manager: started(1683555) /usr/local/libexec/c-lightning/plugins/bcli
lightningd-1 2023-09-28T14:51:34.260Z DEBUG   plugin-manager: started(1683556) /usr/local/libexec/c-lightning/plugins/commando
lightningd-1 2023-09-28T14:51:34.262Z DEBUG   plugin-manager: started(1683557) /usr/local/libexec/c-lightning/plugins/fetchinvoice
lightningd-1 2023-09-28T14:51:34.266Z DEBUG   plugin-manager: started(1683558) /usr/local/libexec/c-lightning/plugins/funder
lightningd-1 2023-09-28T14:51:34.269Z DEBUG   plugin-manager: started(1683559) /usr/local/libexec/c-lightning/plugins/topology
lightningd-1 2023-09-28T14:51:34.274Z DEBUG   plugin-manager: started(1683560) /usr/local/libexec/c-lightning/plugins/keysend
lightningd-1 2023-09-28T14:51:34.277Z DEBUG   plugin-manager: started(1683561) /usr/local/libexec/c-lightning/plugins/offers
lightningd-1 2023-09-28T14:51:34.281Z DEBUG   plugin-manager: started(1683562) /usr/local/libexec/c-lightning/plugins/pay
lightningd-1 2023-09-28T14:51:34.289Z DEBUG   plugin-manager: started(1683563) /usr/local/libexec/c-lightning/plugins/txprepare
lightningd-1 2023-09-28T14:51:34.294Z DEBUG   plugin-manager: started(1683564) /usr/local/libexec/c-lightning/plugins/cln-renepay
lightningd-1 2023-09-28T14:51:34.297Z DEBUG   plugin-manager: started(1683565) /usr/local/libexec/c-lightning/plugins/spenderp
lightningd-1 2023-09-28T14:51:34.301Z DEBUG   plugin-manager: started(1683566) /usr/local/libexec/c-lightning/plugins/sql
lightningd-1 2023-09-28T14:51:34.305Z DEBUG   plugin-manager: started(1683567) /usr/local/libexec/c-lightning/plugins/bookkeeper
lightningd-1 2023-09-28T14:51:34.308Z DEBUG   plugin-manager: started(1683568) /usr/local/libexec/c-lightning/plugins/clnrest/clnrest.py
lightningd-1 2023-09-28T14:51:34.352Z INFO    plugin-clnrest.py: Killing plugin: disabled itself: No module named 'gunicorn'
lightningd-1 2023-09-28T14:51:34.352Z DEBUG   lightningd: io_break: check_plugins_manifests
lightningd-1 2023-09-28T14:51:34.352Z DEBUG   lightningd: io_loop_with_timers: plugins_init
lightningd-1 2023-09-28T14:51:34.353Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_channeld
lightningd-1 2023-09-28T14:51:34.354Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_closingd
lightningd-1 2023-09-28T14:51:34.355Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_connectd
lightningd-1 2023-09-28T14:51:34.357Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_gossipd
lightningd-1 2023-09-28T14:51:34.358Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_hsmd
lightningd-1 2023-09-28T14:51:34.359Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_onchaind
lightningd-1 2023-09-28T14:51:34.360Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_openingd
lightningd-1 2023-09-28T14:51:34.361Z DEBUG   hsmd: pid 1683576, msgfd 48
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_CHECK_PUBKEY
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_SIGN_ANY_DELAYED_PAYMENT_TO_US
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_SIGN_ANCHORSPEND
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_SIGN_HTLC_TX_MINGLE
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_SIGN_SPLICE_TX
lightningd-1 2023-09-28T14:51:34.362Z INFO    lightningd: Creating database
lightningd-1 2023-09-28T14:51:34.940Z DEBUG   connectd: pid 1683577, msgfd 52
lightningd-1 2023-09-28T14:51:34.941Z DEBUG   hsmd: Client: Received message 27 from client
lightningd-1 2023-09-28T14:51:34.941Z DEBUG   hsmd: Client: Received message 27 from client
lightningd-1 2023-09-28T14:51:34.941Z DEBUG   hsmd: new_client: 0
lightningd-1 2023-09-28T14:51:34.942Z DEBUG   connectd: Created listener on 127.0.0.1:44233
lightningd-1 2023-09-28T14:51:34.942Z DEBUG   connectd: REPLY WIRE_CONNECTD_INIT_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:34.942Z DEBUG   lightningd: io_break: connect_init_done
lightningd-1 2023-09-28T14:51:34.942Z DEBUG   lightningd: io_loop: connectd_init
lightningd-1 2023-09-28T14:51:35.070Z INFO    plugin-bcli: bitcoin-cli initialized and connected to bitcoind.
lightningd-1 2023-09-28T14:51:35.070Z DEBUG   lightningd: io_break: plugin_config_cb
lightningd-1 2023-09-28T14:51:35.070Z DEBUG   lightningd: io_loop_with_timers: config_plugin
lightningd-1 2023-09-28T14:51:35.070Z DEBUG   lightningd: All Bitcoin plugin commands registered
lightningd-1 2023-09-28T14:51:35.196Z DEBUG   lightningd: Adding block 100: 6e5b51ac4fdc2a9d1892290d616bfb2771c0d59fa9ab7adf8f7797b618ee311b
lightningd-1 2023-09-28T14:51:35.196Z DEBUG   lightningd: io_break: maybe_completed_init
lightningd-1 2023-09-28T14:51:35.242Z DEBUG   lightningd: io_loop_with_timers: setup_topology
lightningd-1 2023-09-28T14:51:35.242Z DEBUG   wallet: Loaded 0 channels from DB
lightningd-1 2023-09-28T14:51:35.243Z DEBUG   gossipd: pid 1683587, msgfd 51
lightningd-1 2023-09-28T14:51:35.243Z DEBUG   hsmd: new_client: 0
lightningd-1 2023-09-28T14:51:35.244Z DEBUG   gossipd: total store load time: 0 msec
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   gossipd: gossip_store: Read 0/0/0/0 cannounce/cupdate/nannounce/cdelete from store (0 deleted) in 1 bytes
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   gossipd: seeker: state = STARTING_UP New seeker
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   gossipd: REPLY WIRE_GOSSIPD_INIT_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   lightningd: io_break: gossipd_init_done
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   lightningd: io_loop: gossip_init
lightningd-1 2023-09-28T14:51:35.253Z DEBUG   lightningd: Looking for [autoclean,succeededforwards,num]
lightningd-1 2023-09-28T14:51:35.254Z DEBUG   lightningd: Looking for [autoclean,failedforwards,num]
lightningd-1 2023-09-28T14:51:35.255Z DEBUG   lightningd: Looking for [autoclean,succeededpays,num]
lightningd-1 2023-09-28T14:51:35.255Z DEBUG   lightningd: Looking for [autoclean,failedpays,num]
lightningd-1 2023-09-28T14:51:35.255Z DEBUG   plugin-fetchinvoice: Killing plugin: disabled itself at init: offers not enabled in config
lightningd-1 2023-09-28T14:51:35.256Z DEBUG   hsmd: Client: Received message 27 from client
lightningd-1 2023-09-28T14:51:35.256Z DEBUG   lightningd: Looking for [autoclean,paidinvoices,num]
lightningd-1 2023-09-28T14:51:35.257Z DEBUG   lightningd: Looking for [autoclean,expiredinvoices,num]
lightningd-1 2023-09-28T14:51:35.257Z DEBUG   hsmd: Client: Received message 27 from client
lightningd-1 2023-09-28T14:51:35.329Z DEBUG   plugin-chanbackup: Chanbackup Initialised!
lightningd-1 2023-09-28T14:51:35.329Z INFO    plugin-chanbackup: Creating Emergency Recovery
lightningd-1 2023-09-28T14:51:35.400Z DEBUG   plugin-bookkeeper: Setting up database at sqlite3://accounts.sqlite3
lightningd-1 2023-09-28T14:51:35.400Z INFO    plugin-bookkeeper: Creating database
lightningd-1 2023-09-28T14:51:35.400Z DEBUG   connectd: REPLY WIRE_CONNECTD_ACTIVATE_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:35.400Z DEBUG   lightningd: io_break: connect_activate_done
lightningd-1 2023-09-28T14:51:35.400Z DEBUG   lightningd: io_loop: connectd_activate
lightningd-1 2023-09-28T14:51:35.400Z INFO    lightningd: --------------------------------------------------
lightningd-1 2023-09-28T14:51:35.400Z INFO    lightningd: Server started with public key 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518, alias JUNIORBEAM (color #0266e4) and lightningd v23.08.1
lightningd-1 2023-09-28T14:51:35.411Z DEBUG   lightningd: Adding block 101: 2e829364aa8a973634277a9f4f1e40b7b75a1b0260d8d63e84f410f2e777fdd1
lightningd-1 2023-09-28T14:51:35.531Z DEBUG   gossipd: REPLY WIRE_GOSSIPD_NEW_BLOCKHEIGHT_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:35.587Z DEBUG   plugin-bookkeeper: account wallet has balance 0msat
lightningd-1 2023-09-28T14:51:35.587Z DEBUG   plugin-bookkeeper: Snapshot balance does not equal ondisk reported 0msat, off by (+0msat/-0msat) (account wallet) Logging journal entry.
lightningd-1 2023-09-28T14:51:35.587Z INFO    plugin-bookkeeper: account wallet not found, adding along with new balance
lightningd-1 2023-09-28T14:51:35.587Z DEBUG   plugin-bookkeeper: Snapshot balances updated
lightningd-1 2023-09-28T14:51:36.569Z DEBUG   0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-hsmd: Got WIRE_HSMD_ECDH_REQ
lightningd-1 2023-09-28T14:51:36.569Z DEBUG   hsmd: Client: Received message 1 from client
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: Connect IN
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: peer_out WIRE_INIT
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: peer_in WIRE_INIT
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   lightningd: Calling peer_connected hook of plugin chanbackup
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: Handed peer, entering loop
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   lightningd: Plugin chanbackup returned from peer_connected hook call
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: peer_in INVALID 19535
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   lightningd: Calling custommsg hook of plugin chanbackup
lightningd-1 2023-09-28T14:51:36.571Z DEBUG   lightningd: Plugin chanbackup returned from custommsg hook call
lightningd-1 2023-09-28T14:51:36.571Z DEBUG   lightningd: Calling custommsg hook of plugin commando
lightningd-1 2023-09-28T14:51:36.571Z DEBUG   lightningd: Plugin commando returned from custommsg hook call
lightningd-1 2023-09-28T14:51:36.571Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: peer_out INVALID 22861
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   connectd: drain_peer
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-lightningd: peer_disconnect_done
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-lightningd: Not reconnecting: no active channel
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   connectd: maybe_free_peer freeing peer!
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   plugin-funder: Cleaning up inflights for peer id 027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9
------------------------------------- Captured stdout teardown -------------------------------------
lightningd-1 2023-09-28T14:51:36.641Z UNUSUAL lightningd: JSON-RPC shutdown
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   lightningd: io_break: start_json_stream
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   lightningd: io_loop_with_timers: main
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   connectd: REPLY WIRE_CONNECTD_START_SHUTDOWN_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   lightningd: io_break: connectd_start_shutdown_reply
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   plugin-autoclean: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-chanbackup: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-bcli: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-commando: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-funder: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-topology: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-keysend: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-offers: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-pay: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-txprepare: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-cln-renepay: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-spenderp: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-sql: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   lightningd: io_break: destroy_plugin
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-bookkeeper: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   lightningd: Command returned result after jcon close
lightningd-1 2023-09-28T14:51:36.643Z DEBUG   connectd: Shutting down
lightningd-1 2023-09-28T14:51:36.643Z DEBUG   gossipd: Shutting down
lightningd-1 2023-09-28T14:51:36.643Z DEBUG   hsmd: Shutting down
===================================== short test summary info ======================================
FAILED test_lnsocket.py::test_getinfo - AssertionError: assert '' == '0266e4598d1d...283b315c03518'
======================================== 1 failed in 23.17s ========================================

Terminal session

We ran the following commands in this order: 

$ cd lnsocket/go/
$ cp -r ../../test/ .
$ ls
$ source ../../lightning/contrib/startup_regtest.sh
$ start_ln
$ alias l1-cli
$ l1-cli getinfo
$ l1-cli createrune
$ go get github.com/tidwall/gjson
$ cd test/
$ go run getinfo.go 0252b837dc56fc76497f8e485993494bcaeaa1eca095c332bc8aac4922ce4d5d85 127.0.0.1:7171 srRc7kl_g-_7aRfsfhG_Y0PdKzgrTgEDQY7dG7P2SWM9MA==
$ l1-cli getinfo | jq -r .id
$ python -m venv .venv
$ source .venv/bin/activate
$ pip install pyln-testing
$ pytest test_lnsocket.py
$ pytest test_lnsocket.py

And below you can read the terminal session (command lines and outputs): 

◉ tony@tony:~/clnlive:
$ cd lnsocket/go/
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ cp -r ../../test/ .
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ ls
test/  go.mod  go.sum  lnsocket.go
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ source ../../lightning/contrib/startup_regtest.sh
lightning-cli is /usr/local/bin/lightning-cli
lightningd is /usr/local/bin/lightningd
Useful commands:
  start_ln 3: start three nodes, l1, l2, l3
  connect 1 2: connect l1 and l2
  fund_nodes: connect all nodes with channels, in a row
  stop_ln: shutdown
  destroy_ln: remove ln directories
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ start_ln
Bitcoin Core starting
awaiting bitcoind...
Making "default" bitcoind wallet.
error code: -35
error message:
Wallet "default" is already loaded.
[1] 1681267
[2] 1681312
WARNING: eatmydata not found: install it for faster testing
Commands:
        l1-cli, l1-log,
        l2-cli, l2-log,
        bt-cli, stop_ln, fund_nodes
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ alias l1-cli
alias l1-cli='lightning-cli --lightning-dir=/tmp/l1-regtest'
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ l1-cli getinfo
{
   "id": "0252b837dc56fc76497f8e485993494bcaeaa1eca095c332bc8aac4922ce4d5d85",
   "alias": "PEEVEDSPAWN",
   "color": "0252b8",
   "num_peers": 0,
   "num_pending_channels": 0,
   "num_active_channels": 0,
   "num_inactive_channels": 0,
   "address": [],
   "binding": [
      {
         "type": "ipv4",
         "address": "127.0.0.1",
         "port": 7171
      }
   ],
   "version": "v23.08.1",
   "blockheight": 1,
   "network": "regtest",
   "fees_collected_msat": 0,
   "lightning-dir": "/tmp/l1-regtest/regtest",
   "our_features": {
      "init": "08a0000a0269a2",
      "node": "88a0000a0269a2",
      "channel": "",
      "invoice": "02000002024100"
   }
}
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ l1-cli createrune
{
   "rune": "srRc7kl_g-_7aRfsfhG_Y0PdKzgrTgEDQY7dG7P2SWM9MA==",
   "unique_id": "0",
   "warning_unrestricted_rune": "WARNING: This rune has no restrictions! Anyone who has access to this rune could drain funds from your node. Be careful when giving this to apps that you don't trust. Consider using the restrictions parameter to only allow access to specific rpc methods."
}
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ go get github.com/tidwall/gjson
go: added github.com/tidwall/gjson v1.17.0
go: added github.com/tidwall/match v1.1.1
go: added github.com/tidwall/pretty v1.2.0
◉ tony@tony:~/clnlive/lnsocket/go:[git»master]
$ cd test/
◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ go run getinfo.go 0252b837dc56fc76497f8e485993494bcaeaa1eca095c332bc8aac4922ce4d5d85 127.0.0.1:7171 srRc7kl_g-_7aRfsfhG_Y0PdKzgrTgEDQY7dG7P2SWM9MA==
0252b837dc56fc76497f8e485993494bcaeaa1eca095c332bc8aac4922ce4d5d85
◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ l1-cli getinfo | jq -r .id
0252b837dc56fc76497f8e485993494bcaeaa1eca095c332bc8aac4922ce4d5d85
◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ python -m venv .venv
◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ source .venv/bin/activate
(.venv) ◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ pip install pyln-testing
...
(.venv) ◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ pytest test_lnsocket.py
======================================= test session starts ========================================
platform linux -- Python 3.10.12, pytest-7.4.2, pluggy-1.3.0
rootdir: /home/tony/clnlive/lnsocket/go/test
collected 1 item

test_lnsocket.py .                                                                           [100%]

======================================== 1 passed in 24.12s ========================================
(.venv) ◉ tony@tony:~/clnlive/lnsocket/go/test:[git»master]
$ pytest test_lnsocket.py
======================================= test session starts ========================================
platform linux -- Python 3.10.12, pytest-7.4.2, pluggy-1.3.0
rootdir: /home/tony/clnlive/lnsocket/go/test
collected 1 item

test_lnsocket.py F                                                                           [100%]

============================================= FAILURES =============================================
___________________________________________ test_getinfo ___________________________________________

node_factory = <pyln.testing.utils.NodeFactory object at 0x7f9251624430>

    def test_getinfo(node_factory):
        node = node_factory.get_node()
        node_info = node.rpc.getinfo()
        node_id = node_info["id"]
        node_address = node_info["binding"][0]["address"]
        node_port = node_info["binding"][0]["port"]
        node_hostname = node_address + ":" + str(node_port)
        # when `commando-rune` deprecated, we'll use `createrune` instead
        # rune = node.rpc.createrune()["rune"]
        rune = node.rpc.commando_rune()["rune"]
        getinfo_cmd = f"go run getinfo.go {node_id} {node_hostname} {rune}"
>       assert os.popen(getinfo_cmd).read() == node_id
E       AssertionError: assert '' == '0266e4598d1d...283b315c03518'
E         - 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518

test_lnsocket.py:15: AssertionError
-------------------------------------- Captured stdout setup ---------------------------------------
Running tests in /tmp/ltests-km5ej2sv
--------------------------------------- Captured stdout call ---------------------------------------
lightningd-1 2023-09-28T14:51:34.248Z DEBUG   lightningd: Opened log file -
lightningd-1 2023-09-28T14:51:34.248Z DEBUG   lightningd: Opened log file /tmp/ltests-km5ej2sv/test_getinfo_1/lightning-1/log
lightningd-1 2023-09-28T14:51:34.251Z DEBUG   plugin-manager: started(1683553) /usr/local/libexec/c-lightning/plugins/autoclean
lightningd-1 2023-09-28T14:51:34.253Z DEBUG   plugin-manager: started(1683554) /usr/local/libexec/c-lightning/plugins/chanbackup
lightningd-1 2023-09-28T14:51:34.257Z DEBUG   plugin-manager: started(1683555) /usr/local/libexec/c-lightning/plugins/bcli
lightningd-1 2023-09-28T14:51:34.260Z DEBUG   plugin-manager: started(1683556) /usr/local/libexec/c-lightning/plugins/commando
lightningd-1 2023-09-28T14:51:34.262Z DEBUG   plugin-manager: started(1683557) /usr/local/libexec/c-lightning/plugins/fetchinvoice
lightningd-1 2023-09-28T14:51:34.266Z DEBUG   plugin-manager: started(1683558) /usr/local/libexec/c-lightning/plugins/funder
lightningd-1 2023-09-28T14:51:34.269Z DEBUG   plugin-manager: started(1683559) /usr/local/libexec/c-lightning/plugins/topology
lightningd-1 2023-09-28T14:51:34.274Z DEBUG   plugin-manager: started(1683560) /usr/local/libexec/c-lightning/plugins/keysend
lightningd-1 2023-09-28T14:51:34.277Z DEBUG   plugin-manager: started(1683561) /usr/local/libexec/c-lightning/plugins/offers
lightningd-1 2023-09-28T14:51:34.281Z DEBUG   plugin-manager: started(1683562) /usr/local/libexec/c-lightning/plugins/pay
lightningd-1 2023-09-28T14:51:34.289Z DEBUG   plugin-manager: started(1683563) /usr/local/libexec/c-lightning/plugins/txprepare
lightningd-1 2023-09-28T14:51:34.294Z DEBUG   plugin-manager: started(1683564) /usr/local/libexec/c-lightning/plugins/cln-renepay
lightningd-1 2023-09-28T14:51:34.297Z DEBUG   plugin-manager: started(1683565) /usr/local/libexec/c-lightning/plugins/spenderp
lightningd-1 2023-09-28T14:51:34.301Z DEBUG   plugin-manager: started(1683566) /usr/local/libexec/c-lightning/plugins/sql
lightningd-1 2023-09-28T14:51:34.305Z DEBUG   plugin-manager: started(1683567) /usr/local/libexec/c-lightning/plugins/bookkeeper
lightningd-1 2023-09-28T14:51:34.308Z DEBUG   plugin-manager: started(1683568) /usr/local/libexec/c-lightning/plugins/clnrest/clnrest.py
lightningd-1 2023-09-28T14:51:34.352Z INFO    plugin-clnrest.py: Killing plugin: disabled itself: No module named 'gunicorn'
lightningd-1 2023-09-28T14:51:34.352Z DEBUG   lightningd: io_break: check_plugins_manifests
lightningd-1 2023-09-28T14:51:34.352Z DEBUG   lightningd: io_loop_with_timers: plugins_init
lightningd-1 2023-09-28T14:51:34.353Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_channeld
lightningd-1 2023-09-28T14:51:34.354Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_closingd
lightningd-1 2023-09-28T14:51:34.355Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_connectd
lightningd-1 2023-09-28T14:51:34.357Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_gossipd
lightningd-1 2023-09-28T14:51:34.358Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_hsmd
lightningd-1 2023-09-28T14:51:34.359Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_onchaind
lightningd-1 2023-09-28T14:51:34.360Z DEBUG   lightningd: testing /usr/local/libexec/c-lightning/lightning_openingd
lightningd-1 2023-09-28T14:51:34.361Z DEBUG   hsmd: pid 1683576, msgfd 48
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_CHECK_PUBKEY
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_SIGN_ANY_DELAYED_PAYMENT_TO_US
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_SIGN_ANCHORSPEND
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_SIGN_HTLC_TX_MINGLE
lightningd-1 2023-09-28T14:51:34.362Z DEBUG   hsmd: capability +WIRE_HSMD_SIGN_SPLICE_TX
lightningd-1 2023-09-28T14:51:34.362Z INFO    lightningd: Creating database
lightningd-1 2023-09-28T14:51:34.940Z DEBUG   connectd: pid 1683577, msgfd 52
lightningd-1 2023-09-28T14:51:34.941Z DEBUG   hsmd: Client: Received message 27 from client
lightningd-1 2023-09-28T14:51:34.941Z DEBUG   hsmd: Client: Received message 27 from client
lightningd-1 2023-09-28T14:51:34.941Z DEBUG   hsmd: new_client: 0
lightningd-1 2023-09-28T14:51:34.942Z DEBUG   connectd: Created listener on 127.0.0.1:44233
lightningd-1 2023-09-28T14:51:34.942Z DEBUG   connectd: REPLY WIRE_CONNECTD_INIT_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:34.942Z DEBUG   lightningd: io_break: connect_init_done
lightningd-1 2023-09-28T14:51:34.942Z DEBUG   lightningd: io_loop: connectd_init
lightningd-1 2023-09-28T14:51:35.070Z INFO    plugin-bcli: bitcoin-cli initialized and connected to bitcoind.
lightningd-1 2023-09-28T14:51:35.070Z DEBUG   lightningd: io_break: plugin_config_cb
lightningd-1 2023-09-28T14:51:35.070Z DEBUG   lightningd: io_loop_with_timers: config_plugin
lightningd-1 2023-09-28T14:51:35.070Z DEBUG   lightningd: All Bitcoin plugin commands registered
lightningd-1 2023-09-28T14:51:35.196Z DEBUG   lightningd: Adding block 100: 6e5b51ac4fdc2a9d1892290d616bfb2771c0d59fa9ab7adf8f7797b618ee311b
lightningd-1 2023-09-28T14:51:35.196Z DEBUG   lightningd: io_break: maybe_completed_init
lightningd-1 2023-09-28T14:51:35.242Z DEBUG   lightningd: io_loop_with_timers: setup_topology
lightningd-1 2023-09-28T14:51:35.242Z DEBUG   wallet: Loaded 0 channels from DB
lightningd-1 2023-09-28T14:51:35.243Z DEBUG   gossipd: pid 1683587, msgfd 51
lightningd-1 2023-09-28T14:51:35.243Z DEBUG   hsmd: new_client: 0
lightningd-1 2023-09-28T14:51:35.244Z DEBUG   gossipd: total store load time: 0 msec
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   gossipd: gossip_store: Read 0/0/0/0 cannounce/cupdate/nannounce/cdelete from store (0 deleted) in 1 bytes
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   gossipd: seeker: state = STARTING_UP New seeker
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   gossipd: REPLY WIRE_GOSSIPD_INIT_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   lightningd: io_break: gossipd_init_done
lightningd-1 2023-09-28T14:51:35.245Z DEBUG   lightningd: io_loop: gossip_init
lightningd-1 2023-09-28T14:51:35.253Z DEBUG   lightningd: Looking for [autoclean,succeededforwards,num]
lightningd-1 2023-09-28T14:51:35.254Z DEBUG   lightningd: Looking for [autoclean,failedforwards,num]
lightningd-1 2023-09-28T14:51:35.255Z DEBUG   lightningd: Looking for [autoclean,succeededpays,num]
lightningd-1 2023-09-28T14:51:35.255Z DEBUG   lightningd: Looking for [autoclean,failedpays,num]
lightningd-1 2023-09-28T14:51:35.255Z DEBUG   plugin-fetchinvoice: Killing plugin: disabled itself at init: offers not enabled in config
lightningd-1 2023-09-28T14:51:35.256Z DEBUG   hsmd: Client: Received message 27 from client
lightningd-1 2023-09-28T14:51:35.256Z DEBUG   lightningd: Looking for [autoclean,paidinvoices,num]
lightningd-1 2023-09-28T14:51:35.257Z DEBUG   lightningd: Looking for [autoclean,expiredinvoices,num]
lightningd-1 2023-09-28T14:51:35.257Z DEBUG   hsmd: Client: Received message 27 from client
lightningd-1 2023-09-28T14:51:35.329Z DEBUG   plugin-chanbackup: Chanbackup Initialised!
lightningd-1 2023-09-28T14:51:35.329Z INFO    plugin-chanbackup: Creating Emergency Recovery
lightningd-1 2023-09-28T14:51:35.400Z DEBUG   plugin-bookkeeper: Setting up database at sqlite3://accounts.sqlite3
lightningd-1 2023-09-28T14:51:35.400Z INFO    plugin-bookkeeper: Creating database
lightningd-1 2023-09-28T14:51:35.400Z DEBUG   connectd: REPLY WIRE_CONNECTD_ACTIVATE_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:35.400Z DEBUG   lightningd: io_break: connect_activate_done
lightningd-1 2023-09-28T14:51:35.400Z DEBUG   lightningd: io_loop: connectd_activate
lightningd-1 2023-09-28T14:51:35.400Z INFO    lightningd: --------------------------------------------------
lightningd-1 2023-09-28T14:51:35.400Z INFO    lightningd: Server started with public key 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518, alias JUNIORBEAM (color #0266e4) and lightningd v23.08.1
lightningd-1 2023-09-28T14:51:35.411Z DEBUG   lightningd: Adding block 101: 2e829364aa8a973634277a9f4f1e40b7b75a1b0260d8d63e84f410f2e777fdd1
lightningd-1 2023-09-28T14:51:35.531Z DEBUG   gossipd: REPLY WIRE_GOSSIPD_NEW_BLOCKHEIGHT_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:35.587Z DEBUG   plugin-bookkeeper: account wallet has balance 0msat
lightningd-1 2023-09-28T14:51:35.587Z DEBUG   plugin-bookkeeper: Snapshot balance does not equal ondisk reported 0msat, off by (+0msat/-0msat) (account wallet) Logging journal entry.
lightningd-1 2023-09-28T14:51:35.587Z INFO    plugin-bookkeeper: account wallet not found, adding along with new balance
lightningd-1 2023-09-28T14:51:35.587Z DEBUG   plugin-bookkeeper: Snapshot balances updated
lightningd-1 2023-09-28T14:51:36.569Z DEBUG   0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-hsmd: Got WIRE_HSMD_ECDH_REQ
lightningd-1 2023-09-28T14:51:36.569Z DEBUG   hsmd: Client: Received message 1 from client
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: Connect IN
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: peer_out WIRE_INIT
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: peer_in WIRE_INIT
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   lightningd: Calling peer_connected hook of plugin chanbackup
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: Handed peer, entering loop
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   lightningd: Plugin chanbackup returned from peer_connected hook call
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: peer_in INVALID 19535
lightningd-1 2023-09-28T14:51:36.570Z DEBUG   lightningd: Calling custommsg hook of plugin chanbackup
lightningd-1 2023-09-28T14:51:36.571Z DEBUG   lightningd: Plugin chanbackup returned from custommsg hook call
lightningd-1 2023-09-28T14:51:36.571Z DEBUG   lightningd: Calling custommsg hook of plugin commando
lightningd-1 2023-09-28T14:51:36.571Z DEBUG   lightningd: Plugin commando returned from custommsg hook call
lightningd-1 2023-09-28T14:51:36.571Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-connectd: peer_out INVALID 22861
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   connectd: drain_peer
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-lightningd: peer_disconnect_done
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9-lightningd: Not reconnecting: no active channel
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   connectd: maybe_free_peer freeing peer!
lightningd-1 2023-09-28T14:51:36.572Z DEBUG   plugin-funder: Cleaning up inflights for peer id 027127434a55ebb1cd027583c2282892be24657800eeddefe685c48af70e8947d9
------------------------------------- Captured stdout teardown -------------------------------------
lightningd-1 2023-09-28T14:51:36.641Z UNUSUAL lightningd: JSON-RPC shutdown
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   lightningd: io_break: start_json_stream
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   lightningd: io_loop_with_timers: main
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   connectd: REPLY WIRE_CONNECTD_START_SHUTDOWN_REPLY with 0 fds
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   lightningd: io_break: connectd_start_shutdown_reply
lightningd-1 2023-09-28T14:51:36.641Z DEBUG   plugin-autoclean: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-chanbackup: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-bcli: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-commando: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-funder: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-topology: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-keysend: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-offers: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-pay: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-txprepare: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-cln-renepay: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-spenderp: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-sql: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   lightningd: io_break: destroy_plugin
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   plugin-bookkeeper: Killing plugin: exited during normal operation
lightningd-1 2023-09-28T14:51:36.642Z DEBUG   lightningd: Command returned result after jcon close
lightningd-1 2023-09-28T14:51:36.643Z DEBUG   connectd: Shutting down
lightningd-1 2023-09-28T14:51:36.643Z DEBUG   gossipd: Shutting down
lightningd-1 2023-09-28T14:51:36.643Z DEBUG   hsmd: Shutting down
===================================== short test summary info ======================================
FAILED test_lnsocket.py::test_getinfo - AssertionError: assert '' == '0266e4598d1d...283b315c03518'
======================================== 1 failed in 23.17s ========================================

lnsocket/go source code

lnsocket.go

lnsocket:go/lnsocket.go 

package lnsocket

import (
    "bytes"
    "encoding/hex"
    "fmt"
    "io"
    "net"

    "github.com/btcsuite/btcd/btcec/v2"
    "github.com/lightningnetwork/lnd/brontide"
    "github.com/lightningnetwork/lnd/keychain"
    "github.com/lightningnetwork/lnd/lnwire"
    "github.com/lightningnetwork/lnd/tor"
)

const (
    COMMANDO_CMD             = 0x4c4f
    COMMANDO_REPLY_CONTINUES = 0x594b
    COMMANDO_REPLY_TERM      = 0x594d
)

type CommandoMsg struct {
    Rune      string
    Method    string
    Params    string
    RequestId uint64
}

func NewCommandoMsg(token string, method string, params string) CommandoMsg {
    return CommandoMsg{
        Rune:   token,
        Method: method,
        Params: params,
    }
}

// A compile time check to ensure Init implements the lnwire.Message
// interface.

func (msg *CommandoMsg) MsgType() lnwire.MessageType {
    return COMMANDO_CMD
}

func (msg *CommandoMsg) Decode(reader io.Reader, size uint32) error {
    return fmt.Errorf("implememt commando decode?")
}

func (msg *CommandoMsg) Encode(buf *bytes.Buffer, pver uint32) error {
    if err := lnwire.WriteUint64(buf, msg.RequestId); err != nil {
        return err
    }

    buf.WriteString("{\"method\": \"")
    buf.WriteString(msg.Method)
    buf.WriteString("\",\"params\":")
    buf.WriteString(msg.Params)
    buf.WriteString(",\"rune\":\"")
    buf.WriteString(msg.Rune)
    buf.WriteString("\",\"id\":\"d0\",\"jsonrpc\":\"2.0\"}")

    return nil
}

type LNSocket struct {
    Conn        net.Conn
    PrivKeyECDH *keychain.PrivKeyECDH
}

func (ln *LNSocket) GenKey() {
    remotePriv, _ := btcec.NewPrivateKey()
    ln.PrivKeyECDH = &keychain.PrivKeyECDH{PrivKey: remotePriv}
}

func (ln *LNSocket) ConnectWith(netAddr *lnwire.NetAddress) error {
    conn, err := brontide.Dial(ln.PrivKeyECDH, netAddr, tor.DefaultConnTimeout, net.DialTimeout)
    ln.Conn = conn
    return err
}

func (ln *LNSocket) Connect(hostname string, pubkey string) error {
    addr, err := net.ResolveTCPAddr("tcp", hostname)
    if err != nil {
        return err
    }
    bytes, err := hex.DecodeString(pubkey)
    if err != nil {
        return err
    }
    key, err := btcec.ParsePubKey(bytes)
    if err != nil {
        return err
    }

    netAddr := &lnwire.NetAddress{
        IdentityKey: key,
        Address:     addr,
    }

    return ln.ConnectWith(netAddr)
}

func (ln *LNSocket) PerformInit() error {
    no_features := lnwire.NewRawFeatureVector()
    init_reply_msg := lnwire.NewInitMessage(no_features, no_features)

    var b bytes.Buffer
    _, err := lnwire.WriteMessage(&b, init_reply_msg, 0)
    if err != nil {
        return err
    }
    _, err = ln.Conn.Write(b.Bytes())

    // receive the first init msg
    _, _, err = ln.Recv()
    if err != nil {
        return err
    }

    return nil
}

func (ln *LNSocket) Rpc(token string, method string, params string) (string, error) {
    commando_msg := NewCommandoMsg(token, method, params)

    var b bytes.Buffer
    _, err := lnwire.WriteMessage(&b, &commando_msg, 0)
    if err != nil {
        return "", err
    }

    bs := b.Bytes()
    _, err = ln.Conn.Write(bs)
    if err != nil {
        return "", err
    }

    return ln.rpcReadAll()
}

func ParseMsgType(bytes []byte) uint16 {
    return uint16(bytes[0])<<8 | uint16(bytes[1])
}

func (ln *LNSocket) Recv() (uint16, []byte, error) {
    res := make([]byte, 65535)
    n, err := ln.Conn.Read(res)
    if err != nil {
        return 0, nil, err
    }
    if n < 2 {
        return 0, nil, fmt.Errorf("read too small")
    }
    res = res[:n]
    msgtype := ParseMsgType(res)
    return msgtype, res[2:], nil
}

func (ln *LNSocket) rpcReadAll() (string, error) {
    all := []byte{}
    for {
        msgtype, res, err := ln.Recv()
        if err != nil {
            return "", err
        }
        switch msgtype {
        case COMMANDO_REPLY_CONTINUES:
            all = append(all, res[8:]...)
            continue
        case COMMANDO_REPLY_TERM:
            all = append(all, res[8:]...)
            return string(all), nil
        default:
            continue
        }
    }
}

func (ln *LNSocket) Disconnect() {
    ln.Conn.Close()
}

func (ln *LNSocket) ConnectAndInit(hostname string, pubkey string) error {
    err := ln.Connect(hostname, pubkey)
    if err != nil {
        return err
    }

    return ln.PerformInit()
}

Source code

getinfo.go

package main

import (
    "fmt"
    "os"
    "github.com/tidwall/gjson"
    lnsocket "github.com/jb55/lnsocket/go"
)

// Print the node id of the CLN node given as input using
// commando plugin and lnsocket/go.
// Usage:
//
//    $ go run getinfo.go node_id hostname rune
//
// with for instance
//    node_id:  034fa9ed201192c7e865f0fc67001725620e79422347186f0ae4578aac08f4df3d
//    hostname: 127.0.0.1:7171
//    rune:     sxKlx_DW_LtN1kxbTEEfvJN4ytGLMNfyKH_8AjK9yx89MA==

func main() {
    nodeid := os.Args[1]
    hostname := os.Args[2]
    rune := os.Args[3]
    ln := lnsocket.LNSocket{}
    ln.GenKey()
    err := ln.ConnectAndInit(hostname, nodeid)
    if err != nil {
        panic(err)
    }
    body, err := ln.Rpc(rune, "getinfo", "[]")
    if err != nil {
        panic(err)
    }
    getinfoNodeid := gjson.Get(body, "result.id").String()
    fmt.Printf(getinfoNodeid)
}

README.md

# lnsocket test

We use `pyln-testing` python library to write the tests.

The Go program `getinfo.go` we use to test `lnsocket` depends on
`tidwall/gjson` library.

Before, we run the tests, we set up a virtual environment, install
`pyln-testing` Python library and `gjson` Go package:

    python -m venv .venv
    source .venv/bin/activate
    pip install pyln-testing
    go get github.com/tidwall/gjson

Now we can run the tests in `.venv` environment like this:

    pytest test_lnsocket.py

test_lnsocket.py

from pyln.testing.fixtures import *
import os

def test_getinfo(node_factory):
    node = node_factory.get_node()
    node_info = node.rpc.getinfo()
    node_id = node_info["id"]
    node_address = node_info["binding"][0]["address"]
    node_port = node_info["binding"][0]["port"]
    node_hostname = node_address + ":" + str(node_port)
    # when `commando-rune` deprecated, we'll use `createrune` instead
    # rune = node.rpc.createrune()["rune"]
    rune = node.rpc.commando_rune()["rune"]
    getinfo_cmd = f"go run getinfo.go {node_id} {node_hostname} {rune}"
    assert os.popen(getinfo_cmd).read() == node_id

Resources

Create and pay an invoice with CLN

Create and pay an invoice with CLN

LNROOM #1
November 08, 2022
Start a lightning node on regtest with CLN

Start a lightning node on regtest with CLN

LNROOM #2
November 22, 2022
Connect Lightning nodes on regtest with CLN

Connect Lightning nodes on regtest with CLN

LNROOM #3
November 25, 2022
Fund the wallet of a CLN Lightning node running on regtest

Fund the wallet of a CLN Lightning node running on regtest

LNROOM #4
November 29, 2022
Open a channel between two nodes running on regtest using CLN

Open a channel between two nodes running on regtest using CLN

LNROOM #5
December 02, 2022
Close payment channels of lightning nodes running on regtest with CLN

Close payment channels of lightning nodes running on regtest with CLN

LNROOM #6
December 06, 2022
List payments of a CLN lightning node greater than 20000sat

List payments of a CLN lightning node greater than 20000sat

LNROOM #7
December 09, 2022
A penalty transaction managed by Core Lightning

A penalty transaction managed by Core Lightning

LNROOM #8
December 23, 2022
Another penalty transaction on regtest with Core Lightning

Another penalty transaction on regtest with Core Lightning

LNROOM #9
December 27, 2022
Understand CLN Plugin mechanism with a Python example

Understand CLN Plugin mechanism with a Python example

LIVE #1
March 28, 2023
Register a JSON-RPC method to Core Lightning using pyln-client Python package

Register a JSON-RPC method to Core Lightning using pyln-client Python package

LIVE #2
April 13, 2023
Start writing Core Lightning plugins with pyln-client TODAY!

Start writing Core Lightning plugins with pyln-client TODAY!

LNROOM #10
April 21, 2023
Overview of pyln-client implementation - Plugin.run() - Part 1

Overview of pyln-client implementation - Plugin.run() - Part 1

LNROOM #11
April 25, 2023
How to write tests for CLN plugins

How to write tests for CLN plugins

LIVE #3
April 27, 2023
Overview of pyln-client implementation - @plugin.method() - Part 2

Overview of pyln-client implementation - @plugin.method() - Part 2

LNROOM #12
April 28, 2023
Overview of pyln-client implementation - LightningRpc - Part 3

Overview of pyln-client implementation - LightningRpc - Part 3

LNROOM #13
May 02, 2023
Understand CLN Plugin mechanism with a Bash example

Understand CLN Plugin mechanism with a Bash example

LNROOM #14
May 10, 2023
Learn how to subscribe to lightningd event notifications with CLN plugins

Learn how to subscribe to lightningd event notifications with CLN plugins

LIVE #4
May 11, 2023
Subscribe to lightningd notification topics with a Python plugin

Subscribe to lightningd notification topics with a Python plugin

LNROOM #15
May 12, 2023
Subscribe to connect notifications with pyln-client

Subscribe to connect notifications with pyln-client

LNROOM #16
May 16, 2023
How Core Lightning plugins can communicate with each other?

How Core Lightning plugins can communicate with each other?

LIVE #5
May 25, 2023
Core lightning rpc_command hook, pay command and BOLT11 invoice

Core lightning rpc_command hook, pay command and BOLT11 invoice

LIVE #6
June 08, 2023
How does Core Lightning communicate with the Bitcoin network?

How does Core Lightning communicate with the Bitcoin network?

LIVE #7
June 22, 2023
Core Lightning plugins in 2023

Core Lightning plugins in 2023

LIVE #8
July 06, 2023
Write a Core Lightning plugin in Javascript

Write a Core Lightning plugin in Javascript

LNROOM #17
July 12, 2023
Write a Core Lightning plugin in Go

Write a Core Lightning plugin in Go

LNROOM #18
July 14, 2023
Write a Core Lightning plugin in Rust

Write a Core Lightning plugin in Rust

LNROOM #19
July 17, 2023
Introduction to commando and commando-rune

Introduction to commando and commando-rune

LIVE #9
July 20, 2023
Simple CLN bookkeeper web app powered by lnsocket & Golang - part 1

Simple CLN bookkeeper web app powered by lnsocket & Golang - part 1

LIVE #10
August 03, 2023
Simple CLN bookkeeper web app powered by lnsocket & Golang - part 2

Simple CLN bookkeeper web app powered by lnsocket & Golang - part 2

LNROOM #20
August 05, 2023
Overview of lnmessage implementation

Overview of lnmessage implementation

LIVE #11
August 17, 2023
Create invoices with a Node.JS cli using lnmessage and commando

Create invoices with a Node.JS cli using lnmessage and commando

LNROOM #21
August 18, 2023
Core Lightning release v23.08 live exploration

Core Lightning release v23.08 live exploration

LIVE #12
August 31, 2023
Get started with Lightning Network Splicing on Core Lightning v23.08

Get started with Lightning Network Splicing on Core Lightning v23.08

LNROOM #22
September 09, 2023
Getting started with CLNRest plugin

Getting started with CLNRest plugin

LIVE #13
September 14, 2023
Learn how to test libraries/apps that interact with CLN nodes

Learn how to test libraries/apps that interact with CLN nodes

LIVE #14
September 28, 2023
Get started with cln-grpc plugin

Get started with cln-grpc plugin

LIVE #15
October 12, 2023
Remote control of Core Lightning Nodes in 2023

Remote control of Core Lightning Nodes in 2023

LIVE #16
October 26, 2023
Core Lightning implementation of BOLT #11 invoices - part 1

Core Lightning implementation of BOLT #11 invoices - part 1

LIVE #17
November 23, 2023
Core Lightning implementation of BOLT #11 invoices - part 2

Core Lightning implementation of BOLT #11 invoices - part 2

LIVE #18
December 07, 2023
Core Lightning implementation of BOLT #11 invoices - part 3

Core Lightning implementation of BOLT #11 invoices - part 3

LIVE #19
December 21, 2023
Core Lightning implementation of BOLT #11 invoices - part 4

Core Lightning implementation of BOLT #11 invoices - part 4

LIVE #20
January 04, 2024
Core Lightning implementation of BOLT #11 invoices - part 5

Core Lightning implementation of BOLT #11 invoices - part 5

LIVE #21
January 18, 2024
Core Lightning implementation of BOLT #11 invoices - part 6

Core Lightning implementation of BOLT #11 invoices - part 6

LIVE #22
February 15, 2024
Core Lightning implementation of BOLT #11 invoices - part 7

Core Lightning implementation of BOLT #11 invoices - part 7

LIVE #23
February 29, 2024
Core Lightning implementation of BOLT #11 invoices - part 8

Core Lightning implementation of BOLT #11 invoices - part 8

LIVE #24
March 14, 2024