Skip to content

DNS error after chain reorg #2701

Closed
Closed
DNS error after chain reorg#2701
@stridentbean

Description

@stridentbean
stridentbean
opened on Feb 25, 2019

Background

Been persistently slow and crashing from time to time. Looks like there is a whole mess of errors going on. By examining the logs, the error starts after a chain reorg. Any guidence on what might be going on would be helpful.

Your environment

  • version of lnd
    0.5.1-beta commit=v0.5.1-beta
  • which operating system (uname -a on *Nix)
    Linux lnd 4.14.70-v7+ Fixing some README typos #2 SMP Wed Sep 19 07:49:26 UTC 2018 armv7l Linux
  • version of btcd, bitcoind, or other backend
    bitcoind: 0.17.0
  • any other relevant environment details
    bitcoind and lnd are running in docker containers
    raspberry pi 3b+

Steps to reproduce

Just by unlocking lnd all there errors start poping up in the logs.

Expected behaviour

Lnd should boot up and not have any errors.

remarkable logs

Initial errors from chain reorg

2019-02-03T05:04:00Z lnd UNKNOWN[5723] 2019-02-03 05:03:56.316 [ERR] LNWL: Unable to process chain reorg: Post http://127.0.0.1:8332: http: server closed idle connection
2019-02-03T06:46:19Z lnd UNKNOWN[5723] Post http://127.0.0.1:8332: EOF
2019-02-03T11:45:10Z lnd UNKNOWN[8930] 2019-02-03 11:45:10.052 [ERR] LNWL: Failed to process consensus server notification (name: `blockconnected`, detail: `failed to store sync information 0000000000000000001c6a6aed9c7ddfc42d32d08df614c63db63989aa319583: failed to fetch block hash for height 561349: block not found`)
2019-02-03T11:48:43Z lnd UNKNOWN[8930] 2019-02-03 11:48:43.609 [ERR] LNWL: Failed to process consensus server notification (name: `blockconnected`, detail: `failed to store sync information 00000000000000000011232739925d985d9cc7da3b49a76e2a4293e3222b54b4: failed to fetch block hash for height 561350: block not found`)
2019-02-03T11:55:38Z lnd UNKNOWN[8930] 2019-02-03 11:55:38.521 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: server misbehaving
2019-02-03T11:55:38Z lnd UNKNOWN[8930] 2019-02-03 11:55:38.538 [ERR] SRVR: Unable to connect to 0298359004b6887cef47b7505df97f877afc0488ec3ad2a33f0a8e3290a1a5a604@107.201.58.73:9735: dial tcp 107.201.58.73:9735: connect: connection refused
2019-02-03T11:55:38Z lnd UNKNOWN[8930] 2019-02-03 11:55:38.538 [ERR] SRVR: Unable to connect to 0298359004b6887cef47b7505df97f877afc0488ec3ad2a33f0a8e3290a1a5a604@107.201.58.73:9735: dial tcp 107.201.58.73:9735: connect: connection refused
2019-02-03T11:55:48Z lnd UNKNOWN[8930] 2019-02-03 11:55:48.565 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: server misbehaving
2019-02-03T11:55:48Z lnd UNKNOWN[8930] 2019-02-03 11:55:48.570 [ERR] SRVR: Unable to retrieve initial bootstrap peers: no addresses found
2019-02-03T11:55:53Z lnd UNKNOWN[8930] 2019-02-03 11:55:53.608 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: server misbehaving
2019-02-03T11:55:53Z lnd UNKNOWN[8930] 2019-02-03 11:55:53.608 [ERR] SRVR: Unable to retrieve initial bootstrap peers: no addresses found
2019-02-03T11:55:58Z lnd UNKNOWN[8930] 2019-02-03 11:55:58.643 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: read udp 192.168.13.26:37807->192.168.13.13:53: i/o timeout
2019-02-03T11:55:58Z lnd UNKNOWN[8930] 2019-02-03 11:55:58.661 [ERR] SRVR: Unable to retrieve initial bootstrap peers: no addresses found
2019-02-03T11:56:08Z lnd UNKNOWN[8930] 2019-02-03 11:56:08.691 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: server misbehaving
2019-02-03T11:56:08Z lnd UNKNOWN[8930] 2019-02-03 11:56:08.698 [ERR] SRVR: Unable to retrieve initial bootstrap peers: no addresses found
2019-02-03T11:56:13Z lnd UNKNOWN[8930] 2019-02-03 11:56:13.733 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: server misbehaving

Switches to failing to connect to

2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.371 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: server misbehaving
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.419 [ERR] DISC: unable to reply to peer query: unknown message: *lnwire.ReplyChannelRange
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.450 [ERR] SRVR: Unable to connect to 02eae56f155bae8a8eaab82ddc6fef04d5a79a6b0b0d7bcdd0b60d52f3015af031@173.63.90.141:9735: dial tcp 173.63.90.141:9735: connect: connection refused
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.450 [ERR] SRVR: Unable to connect to 02eae56f155bae8a8eaab82ddc6fef04d5a79a6b0b0d7bcdd0b60d52f3015af031@173.63.90.141:9735: dial tcp 173.63.90.141:9735: connect: connection refused
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.462 [WRN] SRVR: Established outbound connection to peer 024bd94f0425590434538fd21d4e58982f7e9cfd8f339205a73deb9c0e0341f5bd, but already connected, dropping conn
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.470 [ERR] SRVR: Unable to connect to 028aa5a991a2acf33da91674fe062219b640e5e57d77a48de6df3c0d30be22b05b@159.89.196.140:9735: dial tcp 159.89.196.140:9735: connect: connection refused
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.470 [WRN] ATPL: Unable to connect to 028aa5a991a2acf33da91674fe062219b640e5e57d77a48de6df3c0d30be22b05b: exhausted all advertised addresses
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.522 [ERR] DISC: unable to reply to peer query: unknown message: *lnwire.ReplyChannelRange
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.721 [ERR] SRVR: Unable to connect to 028aa5a991a2acf33da91674fe062219b640e5e57d77a48de6df3c0d30be22b05b@159.89.196.140:9735: dial tcp 159.89.196.140:9735: connect: connection refused
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.721 [ERR] SRVR: Unable to connect to 028aa5a991a2acf33da91674fe062219b640e5e57d77a48de6df3c0d30be22b05b@159.89.196.140:9735: dial tcp 159.89.196.140:9735: connect: connection refused
2019-02-03T16:45:49Z lnd UNKNOWN[10400] 2019-02-03 16:45:49.763 [WRN] ATPL: Unable to open channel to 03fab7f8655169ea77d9691d4bd359e97782cb6177a6f76383994ed9c262af97a5 of 0.003 BTC: not enough witness outputs to create funding transaction, need 0.003 BTC only have 0 BTC  available
2019-02-03T16:46:09Z lnd UNKNOWN[10400] 2019-02-03 16:46:09.755 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: read udp 192.168.13.26:50734->192.168.13.13:53: i/o timeout
2019-02-03T16:46:29Z lnd UNKNOWN[10400] 2019-02-03 16:46:29.748 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: read udp 192.168.13.26:34353->192.168.13.13:53: i/o timeout
2019-02-03T16:46:29Z lnd UNKNOWN[10400] 2019-02-03 16:46:29.752 [ERR] SRVR: Unable to connect to 027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c@[2001:470:5f:5f::232]:9735: dial tcp [2001:470:5f:5f::232]:9735: connect: network is unreachable
2019-02-03T16:46:29Z lnd UNKNOWN[10400] 2019-02-03 16:46:29.752 [ERR] SRVR: Unable to connect to 027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c@[2001:470:5f:5f::232]:9735: dial tcp [2001:470:5f:5f::232]:9735: connect: network is unreachable
2019-02-03T16:46:34Z lnd UNKNOWN[10400] 2019-02-03 16:46:34.985 [ERR] SRVR: Unable to connect to 02a3d830cbd960b17ac55208ab9642a77d6bc3c24007e72d39994829b2d5471053@88.99.36.224:9735: EOF
2019-02-03T16:46:34Z lnd UNKNOWN[10400] 2019-02-03 16:46:34.985 [ERR] SRVR: Unable to connect to 02a3d830cbd960b17ac55208ab9642a77d6bc3c24007e72d39994829b2d5471053@88.99.36.224:9735: EOF
2019-02-03T16:46:54Z lnd UNKNOWN[10400] 2019-02-03 16:46:54.752 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: read udp 192.168.13.26:38790->192.168.13.13:53: i/o timeout
2019-02-03T16:46:54Z lnd UNKNOWN[10400] 2019-02-03 16:46:54.763 [ERR] SRVR: Unable to connect to 02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b@[2604:a880:800:a1::1375:5001]:9735: dial tcp [2604:a880:800:a1::1375:5001]:9735: connect: network is unreachable
2019-02-03T16:46:54Z lnd UNKNOWN[10400] 2019-02-03 16:46:54.764 [ERR] SRVR: Unable to connect to 02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b@[2604:a880:800:a1::1375:5001]:9735: dial tcp [2604:a880:800:a1::1375:5001]:9735: connect: network is unreachable
2019-02-03T16:47:48Z lnd UNKNOWN[10400] 2019-02-03 16:47:48.327 [ERR] RPCS: unable to open channel to NodeKey(&{1353420 17890e3aad8d35bc054f43acc00084b25229ecff0ab68debd82883ad65ee8266 ba04ce746a70320a83281f438177838ad729c60ce29aa2631ab79b7d2053376e}): not enough witness outputs to create funding transaction, need 0.001 BTC only have 0 BTC  available
2019-02-03T16:48:04Z lnd UNKNOWN[10400] 2019-02-03 16:48:04.859 [ERR] DISC: Unable to query bootstrapper BOLT-0010 DNS Seed: [[nodes.lightning.directory soa.nodes.lightning.directory]]: lookup soa.nodes.lightning.directory on 192.168.13.13:53: server misbehaving
2019-02-03T16:48:22Z lnd UNKNOWN[10400] 2019-02-03 16:48:22.582 [ERR] SRVR: Unable to connect to 029eda74de66b675354054af719ba9e8f3f8954f88e2a8bcd0be8d7d191e9a11c1@173.71.149.66:9735: dial tcp 173.71.149.66:9735: connect: connection timed out
2019-02-03T16:48:22Z lnd UNKNOWN[10400] 2019-02-03 16:48:22.582 [ERR] SRVR: Unable to connect to 029eda74de66b675354054af719ba9e8f3f8954f88e2a8bcd0be8d7d191e9a11c1@173.71.149.66:9735: dial tcp 173.71.149.66:9735: connect: connection timed out
2019-02-03T16:48:22Z lnd UNKNOWN[10400] 2019-02-03 16:48:22.582 [ERR] SRVR: Unable to connect to 0265fae305778b7cb157365f70cf3a2047d2cad5c1ccc5f550c6d8a033084a8ea5@37.205.8.78:9735: dial tcp 37.205.8.78:9735: connect: connection timed out
2019-02-03T16:48:22Z lnd UNKNOWN[10400] 2019-02-03 16:48:22.583 [ERR] SRVR: Unable to connect to 0265fae305778b7cb157365f70cf3a2047d2cad5c1ccc5f550c6d8a033084a8ea5@37.205.8.78:9735: dial tcp 37.205.8.78:9735: connect: connection timed out

Eventually hits an out of memory error (i think)

2019-02-05T02:07:11Z lnd UNKNOWN[10400] 2019-02-05 02:07:09.561 [ERR] HSWC: ChannelLink(561385:1443:0) link failed, exiting htlcManager
2019-02-05T02:08:47Z lnd UNKNOWN[10400] 2019-02-05 02:08:42.730 [ERR] HSWC: ChannelLink(561386:3217:0) Failing link: ChannelPoint(d66d91f7b18c9eef136a33902991f8b487ef9d7d11440098dccc3e7d5aa120c0:0): received error from peer: sync error
2019-02-05T02:08:47Z lnd UNKNOWN[10400] 2019-02-05 02:08:43.477 [ERR] HSWC: ChannelLink(561386:3217:0) link failed, exiting htlcManager
2019-02-05T02:27:49Z lnd UNKNOWN[10400] runtime: pointer 0x2b30402 to unallocated span span.base()=0x2b30000 span.limit=0x2b31fe0 span.state=0
2019-02-05T02:27:49Z lnd UNKNOWN[10400] fatal error: found bad pointer in Go heap (incorrect use of unsafe or cgo?)
2019-02-05T02:27:52Z lnd UNKNOWN[10400] 
2019-02-05T02:27:52Z lnd UNKNOWN[10400] runtime stack:
2019-02-05T02:27:53Z lnd UNKNOWN[10400] runtime.throw(0x9e0473, 0x3e)
2019-02-05T02:27:53Z lnd UNKNOWN[10400] #011/usr/local/go/src/runtime/panic.go:608 +0x5c fp=0x7edb3a64 sp=0x7edb3a50 pc=0x3df58
2019-02-05T02:27:53Z lnd UNKNOWN[10400] runtime.findObject(0x2b30402, 0x0, 0x0, 0x2542d90, 0x76ea3924, 0x1f)
2019-02-05T02:27:53Z lnd UNKNOWN[10400] #011/usr/local/go/src/runtime/mbitmap.go:399 +0x324 fp=0x7edb3a88 sp=0x7edb3a64 pc=0x24268
2019-02-05T02:27:53Z lnd UNKNOWN[10400] runtime.wbBufFlush1(0x2432000)
2019-02-05T02:27:53Z lnd UNKNOWN[10400] #011/usr/local/go/src/runtime/mwbbuf.go:252 +0xb0 fp=0x7edb3ac0 sp=0x7edb3a88 pc=0x39e54
2019-02-05T02:27:53Z lnd UNKNOWN[10400] runtime.wbBufFlush.func1()
2019-02-05T02:27:53Z lnd UNKNOWN[10400] #011/usr/local/go/src/runtime/mwbbuf.go:195 +0x20 fp=0x7edb3ac8 sp=0x7edb3ac0 pc=0x68900
2019-02-05T02:27:53Z lnd UNKNOWN[10400] runtime.systemstack(0x6a294)
2019-02-05T02:27:53Z lnd UNKNOWN[10400] #011/usr/local/go/src/runtime/asm_arm.s:354 +0x84 fp=0x7edb3acc sp=0x7edb3ac8 pc=0x6a428
2019-02-05T02:27:53Z lnd UNKNOWN[10400] runtime.mstart()
2019-02-05T02:27:53Z lnd UNKNOWN[10400] #0

Then goes into whatever this is.

06T11:17:32Z lnd UNKNOWN[10400] 2019-02-06 11:17:27.555 [WRN] DISC: no channel updates found for short_chan_id=518813:1551:0
2019-02-06T11:17:32Z lnd UNKNOWN[10400] 2019-02-06 11:17:27.611 [WRN] DISC: no channel updates found for short_chan_id=519526:931:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.003 [WRN] DISC: no channel updates found for short_chan_id=518674:151:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.003 [WRN] DISC: no channel updates found for short_chan_id=519526:927:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.003 [WRN] DISC: no channel updates found for short_chan_id=519122:991:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.003 [WRN] DISC: no channel updates found for short_chan_id=518813:1566:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.004 [WRN] DISC: no channel updates found for short_chan_id=518960:2496:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.004 [WRN] DISC: no channel updates found for short_chan_id=518226:943:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.004 [WRN] DISC: no channel updates found for short_chan_id=519471:1113:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.004 [WRN] DISC: no channel updates found for short_chan_id=518954:440:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.004 [WRN] DISC: no channel updates found for short_chan_id=519526:926:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.004 [WRN] DISC: no channel updates found for short_chan_id=519526:920:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.004 [WRN] DISC: no channel updates found for short_chan_id=518512:1962:1
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.005 [WRN] DISC: no channel updates found for short_chan_id=519121:1231:1
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.008 [WRN] DISC: no channel updates found for short_chan_id=518813:1551:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.008 [WRN] DISC: no channel updates found for short_chan_id=519526:931:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.008 [WRN] DISC: no channel updates found for short_chan_id=518674:151:0
2019-02-06T11:17:33Z lnd UNKNOWN[10400] 2019-02-06 11:17:28.008 [WRN] DISC: no channel updates found for short_chan_id=519526:927:0

Then hits an out of mem error and restarts the no channel updates found again.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions