Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fundchannel fails with lnd node #4238

Closed
evd0kim opened this issue Dec 1, 2020 · 18 comments · Fixed by #4259
Closed

fundchannel fails with lnd node #4238

evd0kim opened this issue Dec 1, 2020 · 18 comments · Fixed by #4259
Assignees

Comments

@evd0kim
Copy link
Contributor

evd0kim commented Dec 1, 2020

Issue and Steps to Reproduce

I'm trying to open a channel with

fundchannel 029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05 all fast true 0 [TXID:N]

And I get an error which I do not understand.

lightning-cli: Incorrect 'id' in response: null

getinfo output

{
   "id": "ID",
   "alias": "test",
   "color": "ff0000",
   "num_peers": 10,
   "num_pending_channels": 1,
   "num_active_channels": 6,
   "num_inactive_channels": 1,
   "address": [
      {
         "type": "ipv4",
         "address": "46.101.127.98",
         "port": 51486
      }
   ],
   "binding": [
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 51486
      }
   ],
   "version": "v0.9.2",
   "blockheight": 659508,
   "network": "bitcoin",
   "msatoshi_fees_collected": 16029,
   "fees_collected_msat": "16029msat",
   "lightning-dir": "/home/lnadmin/.lightning/bitcoin"
}
@ZmnSCPxj
Copy link
Contributor

ZmnSCPxj commented Dec 1, 2020

Huh. This is an error which "should not" happen. Can you provide logs?

We use the term "urgent" rather than "fast" for feerates, so it seems likely to me that the problem is triggered by this. But it should lead to a -32602 parameter error, not a id null.

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 2, 2020

@ZmnSCPxj thank you for your response.

I tried

clg-cli fundchannel 029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05 all urgent true 0 [TXID:1]

with the result

lightning-cli: Incorrect 'id' in response: null

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 2, 2020

This is what i have in logs

2020-12-02T08:12:45.581Z DEBUG   029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05-connectd: Connected out, starting crypto
2020-12-02T08:12:45.632Z DEBUG   029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05-connectd: Connect OUT
2020-12-02T08:12:45.632Z DEBUG   029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05-connectd: peer_out WIRE_INIT
2020-12-02T08:12:45.676Z DEBUG   029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05-connectd: peer_in WIRE_INIT
2020-12-02T08:12:45.676Z DEBUG   029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05-gossipd: seeker: disabling gossip
2020-12-02T08:12:45.679Z DEBUG   029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05-openingd-chan#4078: pid 8328, msgfd 59
2020-12-02T08:12:45.694Z DEBUG   029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05-openingd-chan#4078: Handed peer, entering loop
2020-12-02T08:12:45.695Z DEBUG   029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05-openingd-chan#4078: peer_out WIRE_GOSSIP_TIMESTAMP_FILTER

getlog is pretty silent about tried node.

@ZmnSCPxj
Copy link
Contributor

ZmnSCPxj commented Dec 2, 2020

Can you enable --log-level=debug:spenderp and show logs from plugin-spenderp?

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 2, 2020

@ZmnSCPxj I will look into this plugin and I will try to do that.

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 2, 2020

Does it help you @ZmnSCPxj ?

2020-11-30T15:40:25.683Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered
2020-11-30T17:30:42.186Z DEBUG   plugin-spenderp: mfc 467: multiconnect.
2020-11-30T17:30:42.186Z DEBUG   plugin-spenderp: mfc 467, dest 0: connect 029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05.
2020-11-30T17:30:42.338Z DEBUG   plugin-spenderp: mfc 467, dest 0: connect done.
2020-11-30T17:30:42.338Z DEBUG   plugin-spenderp: mfc 467: multiconnect done.
2020-11-30T17:30:42.338Z DEBUG   plugin-spenderp: mfc 467: utxopsbt.
2020-11-30T17:30:42.339Z DEBUG   plugin-spenderp: mfc 467: forwarding error, about to cleanup.
2020-11-30T17:30:42.339Z DEBUG   plugin-spenderp: mfc 467: cleanup!
2020-11-30T17:30:42.339Z DEBUG   plugin-spenderp: mfc 467: cleanup done, failing raw.
2020-11-30T17:34:57.873Z DEBUG   plugin-spenderp: mfc 486: multiconnect.
2020-11-30T17:34:57.873Z DEBUG   plugin-spenderp: mfc 486, dest 0: connect 029dd81c32e3ea839b4b2f8edcc9bea227c40fa2c6509878034401a8ce2a8bac05.
2020-11-30T17:34:57.873Z DEBUG   plugin-spenderp: mfc 486, dest 0: connect done.
2020-11-30T17:34:57.873Z DEBUG   plugin-spenderp: mfc 486: multiconnect done.
2020-11-30T17:34:57.873Z DEBUG   plugin-spenderp: mfc 486: utxopsbt.
2020-11-30T17:34:57.873Z DEBUG   plugin-spenderp: mfc 486: forwarding error, about to cleanup.
2020-11-30T17:34:57.873Z DEBUG   plugin-spenderp: mfc 486: cleanup!
2020-11-30T17:34:57.873Z DEBUG   plugin-spenderp: mfc 486: cleanup done, failing raw.
2020-12-01T17:19:35.531Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered
2020-12-02T14:13:48.796Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered
2020-12-02T14:14:00.726Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered
2020-12-02T14:14:11.543Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered
2020-12-02T14:14:22.252Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered
2020-12-02T14:14:33.012Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered
2020-12-02T14:14:44.515Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered
2020-12-02T16:10:25.215Z INFO    plugin-spenderp: Killing plugin: Could not register method "multiwithdraw", a method with that name is already registered

@ZmnSCPxj
Copy link
Contributor

ZmnSCPxj commented Dec 3, 2020

There is something fairly strange with your setup, with multiple spenderp apparently getting run.

On the other hand, id of null should basically never happen normally. What exactly is clg-cli, and what does it expand to?

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 3, 2020

@ZmnSCPxj that's an alias

lightning-cli --lightning-dir /home/lnadmin/.lightning/

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 3, 2020

Your suggestion reminded me to check my setup and I indeed have specified plugin dir in config.
But for a strange reason systems service accepts only the default path. I tried it multiple times. I will try to remove path from config.

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 3, 2020

@ZmnSCPxj Ok. I figured that out that lightning always load "important" plugins from
/usr/local/libexec/c-lightning/ while some optional user plugins loaded from additional plugin dir. I always thought there is only a single place for plugins. Now it makes sense that Fiatjaf once noticed that /usr/local/libexec/c-lightning/plugins must be cleaned.

Now, plugin-spenderp is working. Maybe all bugs magically disappear then.

@ZmnSCPxj
Copy link
Contributor

ZmnSCPxj commented Dec 3, 2020

No more issues with fundchannel?

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 3, 2020

I've not tested it yet. If you know a recipe for how to abandon not opened channel I can test it faster. There is an important for me peer with which I can't open a channel. The transaction failed to broadcast, and I ended up with this AWAITING_UNILATERAL state for days.

{
   "code": -1,
   "message": "Channel is in state AWAITING_UNILATERAL"
}

@ZmnSCPxj
Copy link
Contributor

ZmnSCPxj commented Dec 3, 2020

Ideally, we should really double-spend the funding transaction and force the outputs it spent to be re-spent on an urgent transaction to pay to ourselves. I am uncertain about the coin reservation logic, try checking with @niftynei or @rustyrussell first.

If you are sure that nobody else has a copy of the funding/unilteral-close transaction (a random wog could just keep a copy and broadcast it later during a low-fee period, this is always a risk with onchain, which is why you should really avoid slow feerate unless you have provision for later CPFP at higher than urgent), and you configured with ./configure --enable-developer, then a dev-forget-channel command exists. This is dangerous and only do this if you are 100% definitely sure the funding/unilateral-close transaction never left your device (you probably are not).

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 3, 2020

It looks like it is exactly what I need. Thank you very much @ZmnSCPxj, you are a legend. I will come back with the results later.

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 3, 2020

@ZmnSCPxj thank you for the hint. The channel disappeared from my DB finally.
But I can't create a new channel anyway. I see again lightning-cli: Incorrect 'id' in response: null.
Please, ask about io dump Christian.

@ZmnSCPxj
Copy link
Contributor

ZmnSCPxj commented Dec 3, 2020

Only occurs for fundchannel? How about listpays? The plugin-spenderp logs show the same result?

@evd0kim
Copy link
Contributor Author

evd0kim commented Dec 4, 2020

@ZmnSCPxj listpays works fine. I stopped io log dump since it hurts VPS can't say anything about plugin.

I've tried to track problem with "non-matching" cli as suggested by Christian and pointed alias to build directory but the results are the same. By the way can you provide me with example of fundchannel command with UTXO selection which is works for you 1000%?

@cdecker cdecker self-assigned this Dec 4, 2020
cdecker added a commit to cdecker/lightning that referenced this issue Dec 4, 2020
In a couple of places we accept arrays of strings and don't validate
them. If we forward them, e.g., call a JSON-RPC method from the
plugin, we end up embedding the unverified string in the JSON-RPC
call without escaping, which then leads to invalid JSON being passed
on.

This at least partially causes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 4, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 4, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
cdecker added a commit to cdecker/lightning that referenced this issue Dec 4, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 4, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
@cdecker
Copy link
Member

cdecker commented Dec 4, 2020

Turns out it was a malformed parameter from the shell being inserted verbatim into the JSON-RPC request, and thus failing the parser in lightningd. Not being able to parse the request, lightningd cannot return an error since it doesn't have the id. As indicated by the JSON-RPC spec we returned an error with id=null, which then resulted in lightning-cli being unable to associate it with the request.

See #4259 for a fix: we now parse the request in lightning-cli before sending it to lightningd to make sure the construction doesn't result in malformed JSON messages.

cdecker added a commit to cdecker/lightning that referenced this issue Dec 5, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 5, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
In a couple of places we accept arrays of strings and don't validate
them. If we forward them, e.g., call a JSON-RPC method from the
plugin, we end up embedding the unverified string in the JSON-RPC
call without escaping, which then leads to invalid JSON being passed
on.

This at least partially causes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
In a couple of places we accept arrays of strings and don't validate
them. If we forward them, e.g., call a JSON-RPC method from the
plugin, we end up embedding the unverified string in the JSON-RPC
call without escaping, which then leads to invalid JSON being passed
on.

This at least partially causes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
In a couple of places we accept arrays of strings and don't validate
them. If we forward them, e.g., call a JSON-RPC method from the
plugin, we end up embedding the unverified string in the JSON-RPC
call without escaping, which then leads to invalid JSON being passed
on.

This at least partially causes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 7, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
cdecker added a commit to cdecker/lightning that referenced this issue Dec 8, 2020
In a couple of places we accept arrays of strings and don't validate
them. If we forward them, e.g., call a JSON-RPC method from the
plugin, we end up embedding the unverified string in the JSON-RPC
call without escaping, which then leads to invalid JSON being passed
on.

This at least partially causes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 8, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
cdecker added a commit to cdecker/lightning that referenced this issue Dec 8, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
rustyrussell pushed a commit that referenced this issue Dec 8, 2020
In a couple of places we accept arrays of strings and don't validate
them. If we forward them, e.g., call a JSON-RPC method from the
plugin, we end up embedding the unverified string in the JSON-RPC
call without escaping, which then leads to invalid JSON being passed
on.

This at least partially causes #4238
rustyrussell pushed a commit that referenced this issue Dec 8, 2020
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes #4238
rustyrussell pushed a commit that referenced this issue Dec 8, 2020
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes #4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
vibhaa pushed a commit to spider-pcn/lightning that referenced this issue Mar 24, 2021
In a couple of places we accept arrays of strings and don't validate
them. If we forward them, e.g., call a JSON-RPC method from the
plugin, we end up embedding the unverified string in the JSON-RPC
call without escaping, which then leads to invalid JSON being passed
on.

This at least partially causes ElementsProject#4238
vibhaa pushed a commit to spider-pcn/lightning that referenced this issue Mar 24, 2021
We were masquerading errors when parsing the request by reporting only
a bogus malformed `id` field in the response, when the real issue was
that we were unable to parse the request in the first place (which
caused the null-id error to be returned).

Fixes ElementsProject#4238
vibhaa pushed a commit to spider-pcn/lightning that referenced this issue Mar 24, 2021
If some parameter is malformed on the command line we could end up
with a malformed JSON-RPC request, which would then result in very
unhelpful error messages.

Fixes ElementsProject#4238
Changelog-Changed: cli: `lightning-cli` now performs better sanity checks on the JSON-RPC requests it sends.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants