Still high memory usage with v0.9.0

bota87 commented 4 years ago

Background

High memory usage, keep growing for 4/5 days until the system crash and reboot.

Memory usage: 36 MB before unlocking 580 MB after unlocking More than 2GB after few days

I have tried to disable watchdog and autopilot but doesn't help

Possible relation with #3073 and #3800

Your environment

version of lnd 0.9.0
which operating system Raspbian Buster
version of bitcoind 0.19.0.1
Raspberry 4 4GB
9 channels - 11 peers

Steps to reproduce

Start lnd service and wait

Expected behaviour

The memory should stay much more costant

Actual behaviour

The memory continuosly growing

wpaulino commented 4 years ago

@bota87 could you follow the steps in https://github.com/lightningnetwork/lnd/issues/3800#issuecomment-562253972 and report back?

bota87 commented 4 years ago

Here the profile before unlocking before

bota87 commented 4 years ago

Here the profile after unlocking. I will publish more on the next days after

bota87 commented 4 years ago

After 24 hours htop show 950M used after 24h

halseth commented 4 years ago

@bota87 Are you still connected to only ~11 peers when the RAM usage gets that high?

bota87 commented 4 years ago

@halseth After 38 hours htop show 1.300M, lncli getinfo show 9 peers with 9 active channel after 38h

bota87 commented 4 years ago

After 48 hours htop show 1.600M I have to restart the service now or the system crash after 48h

wpaulino commented 4 years ago

Do you see anything strange within your logs? It seems like you're being flooded with gossip, are you able to pinpoint which node it's coming from? You can also look at the bytes_recv values of each peer in the output of lncli listpeers.

bota87 commented 4 years ago

@wpaulino after 24h from the restart here the traffic data. htop say 994M usage

"bytes_sent": "959469",     "bytes_recv": "87528177",
"bytes_sent": "232463",     "bytes_recv": "23156207",
"bytes_sent": "443155",     "bytes_recv": "44624325",
"bytes_sent": "103845",     "bytes_recv": "3442862",
"bytes_sent": "534487",     "bytes_recv": "49606282",
"bytes_sent": "936142",     "bytes_recv": "66590136",
"bytes_sent": "256062",     "bytes_recv": "23202447",
"bytes_sent": "256927",     "bytes_recv": "24490878",
"bytes_sent": "705714",     "bytes_recv": "26314332",

I don't see anything strange in the logs

-- Logs begin at Thu 2019-02-14 11:12:01 CET. --
feb 14 00:23:03 serverpi4 lnd[25292]: 2020-02-14 00:23:03.725 [INF] CRTR: Processed channels=0 updates=2 nodes=0 in last 59.99995817s
feb 14 00:23:25 serverpi4 lnd[25292]: 2020-02-14 00:23:25.739 [INF] DISC: Broadcasting 15 new announcements in 2 sub batches
feb 14 00:24:03 serverpi4 lnd[25292]: 2020-02-14 00:24:03.725 [INF] CRTR: Processed channels=0 updates=16 nodes=0 in last 59.9995887s
feb 14 00:24:55 serverpi4 lnd[25292]: 2020-02-14 00:24:55.739 [INF] DISC: Broadcasting 24 new announcements in 3 sub batches
feb 14 00:25:03 serverpi4 lnd[25292]: 2020-02-14 00:25:03.725 [INF] CRTR: Processed channels=0 updates=15 nodes=3 in last 59.999912975s
feb 14 00:26:03 serverpi4 lnd[25292]: 2020-02-14 00:26:03.725 [INF] CRTR: Processed channels=0 updates=2 nodes=0 in last 59.999692506s
feb 14 00:26:25 serverpi4 lnd[25292]: 2020-02-14 00:26:25.739 [INF] DISC: Broadcasting 6 new announcements in 1 sub batches
feb 14 00:27:03 serverpi4 lnd[25292]: 2020-02-14 00:27:03.725 [INF] CRTR: Processed channels=0 updates=3 nodes=2 in last 59.999886051s
feb 14 00:27:55 serverpi4 lnd[25292]: 2020-02-14 00:27:55.739 [INF] DISC: Broadcasting 6 new announcements in 1 sub batches
feb 14 00:28:03 serverpi4 lnd[25292]: 2020-02-14 00:28:03.725 [INF] CRTR: Processed channels=0 updates=7 nodes=0 in last 59.999865622s

wpaulino commented 4 years ago

That's a lot of incoming traffic per peer for only 24H. You may be connected to faulty/outdated peers. Are you able to provide logs for the peer with the highest amount of bytes received starting from when the connection was established?

bota87 commented 4 years ago

How can I do that?

wpaulino commented 4 years ago

Take the public key of the node with the highest inbound traffic from listpeers and search your logs for the most recent instance of Finalizing connection to PUBLIC_KEY. That's your starting point. Then, search for any lines after this one that contain the same public key and paste the output here.

bota87 commented 4 years ago

After 2 days bytes_recv for this peer is 114152840 I have another node with a similar traffic

The log refers to one of the many LNBIG.com, I have seen they managed a lot of bitcoin I doubt they don't keep lnd updated and running well.

2020-02-13 12:57:30.524 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 12:57:35.938 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 12:57:40.814 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 394 new channels
2020-02-13 12:57:45.660 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): no more chans to query
2020-02-13 13:17:19.322 [INF] PEER: unable to read message from `PUBLIC_KEY`@`NODE_IP`: read tcp 127.0.0.1:34480->127.0.0.1:9050: i/o timeout
2020-02-13 13:17:19.323 [INF] PEER: Disconnecting `PUBLIC_KEY`@`NODE_IP`, reason: read handler closed
2020-02-13 13:17:19.524 [INF] DISC: Removing GossipSyncer for peer=`PUBLIC_KEY`
2020-02-13 13:17:21.699 [INF] SRVR: Established connection to: `PUBLIC_KEY`@`NODE_IP`
>>>>>>>>>> 2020-02-13 13:17:21.710 [INF] SRVR: Finalizing connection to `PUBLIC_KEY`@`NODE_IP`, inbound=false
2020-02-13 13:17:22.271 [INF] PEER: NodeKey(`PUBLIC_KEY`) loading ChannelPoint(0bc84e1a0e8d33264a09479d2aa6bd80cf184a2dfb77823450b88a43e3c9a5b0:1)
2020-02-13 13:17:22.301 [INF] SRVR: Negotiated chan series queries with `PUBLIC_KEY`
2020-02-13 13:17:22.302 [INF] DISC: Creating new GossipSyncer for peer=`PUBLIC_KEY`
2020-02-13 13:31:55.740 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-13 13:31:55.739991234 +0100 CET m=+49256.225919600, end=2156-03-21 20:00:10.739991234 +0100 CET m=+4295016551.225919600)
2020-02-13 13:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-13 15:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-13 15:11:55.739315401 +0100 CET m=+55256.225241990, end=2156-03-21 21:40:10.739315401 +0100 CET m=+4295022551.225241990)
2020-02-13 15:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-13 16:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-13 16:31:55.739278936 +0100 CET m=+60056.225205617, end=2156-03-21 23:00:10.739278936 +0100 CET m=+4295027351.225205617)
2020-02-13 17:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-13 17:51:55.740 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-13 17:51:55.740248965 +0100 CET m=+64856.226176646, end=2156-03-22 00:20:10.740248965 +0100 CET m=+4295032151.226176646)
2020-02-13 18:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-13 18:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-13 18:31:55.739279338 +0100 CET m=+67256.225206019, end=2156-03-22 01:00:10.739279338 +0100 CET m=+4295034551.225206019)
2020-02-13 18:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-13 19:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-13 19:11:55.739749622 +0100 CET m=+69656.225677618, end=2156-03-22 01:40:10.739749622 +0100 CET m=+4295036951.225677618)
2020-02-13 19:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-13 21:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-13 21:31:55.739271697 +0100 CET m=+78056.225198248, end=2156-03-22 04:00:10.739271697 +0100 CET m=+4295045351.225198248)
2020-02-13 22:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-13 22:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): requesting new chans from height=0 and 4294967295 blocks after
2020-02-13 22:51:56.248 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-13 22:51:56.354 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-13 22:51:56.927 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-13 22:51:57.365 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=7963
2020-02-13 22:51:57.365 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 31963 chans
2020-02-13 22:51:57.479 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26376 new chans
2020-02-13 22:51:57.479 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:00.875 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:03.738 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:06.627 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:09.578 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:12.310 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:14.978 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:17.934 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:21.150 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:23.763 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:26.389 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:29.021 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:31.793 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:35.336 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:37.807 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:40.489 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:43.084 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:45.646 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:48.371 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:50.977 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:52:53.633 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:02.583 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:06.304 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:09.073 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:14.752 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:18.236 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:23.177 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:29.294 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:33.162 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:38.140 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:43.257 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:48.641 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:53.517 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:53:58.170 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:03.107 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:08.491 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:13.213 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:18.239 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:23.146 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:28.140 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:33.172 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:39.070 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:43.215 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:48.334 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:53.360 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:54:58.109 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:55:03.592 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:55:08.192 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:55:13.156 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:55:18.160 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:55:23.172 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:55:28.214 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-13 22:55:33.212 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 376 new channels
2020-02-13 22:55:37.827 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): no more chans to query
2020-02-13 23:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-13 23:51:55.739420283 +0100 CET m=+86456.225346835, end=2156-03-22 06:20:10.739420283 +0100 CET m=+4295053751.225346835)
2020-02-14 00:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 01:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 01:31:55.739304727 +0100 CET m=+92456.225231390, end=2156-03-22 08:00:10.739304727 +0100 CET m=+4295059751.225231390)
2020-02-14 02:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 02:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 02:31:55.739526317 +0100 CET m=+96056.225454332, end=2156-03-22 09:00:10.739526317 +0100 CET m=+4295063351.225454332)
2020-02-14 02:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 03:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 03:31:55.739798856 +0100 CET m=+99656.225727037, end=2156-03-22 10:00:10.739798856 +0100 CET m=+4295066951.225727037)
2020-02-14 03:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 04:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 04:31:55.73945916 +0100 CET m=+103256.225385878, end=2156-03-22 11:00:10.73945916 +0100 CET m=+4295070551.225385878)
2020-02-14 04:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 05:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 05:31:55.739277872 +0100 CET m=+106856.225204497, end=2156-03-22 12:00:10.739277872 +0100 CET m=+4295074151.225204497)
2020-02-14 05:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): requesting new chans from height=0 and 4294967295 blocks after
2020-02-14 05:51:56.294 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 05:51:56.490 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 05:51:56.614 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 05:51:56.772 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 05:51:56.773 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=55
2020-02-14 05:51:56.773 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 32055 chans
2020-02-14 05:51:56.893 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26357 new chans
2020-02-14 05:51:56.893 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:51:59.846 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:02.368 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:05.115 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:07.920 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:10.640 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:13.238 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:15.879 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:18.568 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:21.259 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:23.813 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:26.482 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:29.206 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:31.844 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:34.520 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:39.119 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:41.759 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:44.411 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:46.944 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:49.577 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:53.156 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:52:58.230 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:03.190 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:08.245 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:13.192 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:18.343 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:23.382 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:28.162 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:33.292 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:38.312 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:43.244 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:48.355 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:53.512 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:53:59.274 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:03.256 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:08.261 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:13.384 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:18.254 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:23.583 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:28.250 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:33.249 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:38.373 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:43.219 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:48.519 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:53.391 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:54:58.524 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:55:03.460 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:55:08.478 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:55:13.378 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:55:18.225 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:55:23.266 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:55:29.877 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 05:55:33.449 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 357 new channels
2020-02-14 05:55:37.617 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): no more chans to query
2020-02-14 07:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 07:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 07:31:55.73949317 +0100 CET m=+114056.225420351, end=2156-03-22 14:00:10.73949317 +0100 CET m=+4295081351.225420351)
2020-02-14 07:51:55.740 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): requesting new chans from height=0 and 4294967295 blocks after
2020-02-14 07:51:56.303 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 07:51:56.425 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 07:51:57.031 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 07:51:57.833 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 07:51:57.833 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=51
2020-02-14 07:51:57.833 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 32051 chans
2020-02-14 07:51:57.993 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26352 new chans
2020-02-14 07:51:57.993 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:00.889 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:03.662 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:06.660 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:09.297 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:12.637 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:15.295 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:17.899 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:20.691 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:23.253 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:25.914 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:28.564 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:31.673 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:34.464 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:37.755 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:40.637 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:43.298 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:47.480 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:50.136 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:52.790 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:55.307 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:52:58.439 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:03.302 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:08.166 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:13.264 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:18.221 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:23.295 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:28.287 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:33.247 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:38.215 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:43.166 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:48.270 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:53.368 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:53:58.131 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:03.532 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:08.289 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:13.630 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:18.272 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:23.243 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:28.225 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:34.598 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:38.190 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:43.201 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:48.362 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:53.963 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:54:59.514 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:55:03.442 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:55:08.179 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:55:13.219 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:55:18.275 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:55:23.202 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:55:28.744 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 07:55:33.179 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 352 new channels
2020-02-14 07:55:38.165 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): no more chans to query
2020-02-14 08:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 09:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 09:31:55.739468893 +0100 CET m=+121256.225396093, end=2156-03-22 16:00:10.739468893 +0100 CET m=+4295088551.225396093)
2020-02-14 11:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): requesting new chans from height=0 and 4294967295 blocks after
2020-02-14 11:51:56.304 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 11:51:56.477 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 11:51:56.607 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 11:51:56.701 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 11:51:56.701 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=50
2020-02-14 11:51:56.701 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 32050 chans
2020-02-14 11:51:56.815 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26342 new chans
2020-02-14 11:51:56.816 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:51:59.384 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:01.942 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:04.594 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:07.201 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:09.969 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:12.537 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:15.480 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:18.840 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:22.561 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:25.094 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:27.933 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:30.557 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:33.111 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:35.647 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:38.196 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:40.840 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:43.428 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:46.104 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:48.640 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:53.176 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:52:58.290 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:03.219 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:08.248 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:13.565 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:18.386 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:23.315 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:28.431 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:33.631 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:38.294 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:44.776 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:48.182 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:53.091 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:53:58.173 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:03.232 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:08.141 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:13.134 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:18.183 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:23.252 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:28.194 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:33.224 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:38.197 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:43.432 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:48.156 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:53.223 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:54:58.148 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:55:03.536 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:55:08.156 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:55:13.181 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:55:18.234 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:55:23.171 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:55:28.941 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 11:55:33.191 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 342 new channels
2020-02-14 11:55:37.528 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): no more chans to query
2020-02-14 12:11:55.740 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 14:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 14:51:55.739324454 +0100 CET m=+140456.225251172, end=2156-03-22 21:20:10.739324454 +0100 CET m=+4295107751.225251172)
2020-02-14 18:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 18:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): requesting new chans from height=0 and 4294967295 blocks after
2020-02-14 18:51:56.449 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 18:51:56.635 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 18:51:56.817 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 18:51:56.936 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=8000
2020-02-14 18:51:56.936 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): buffering chan range reply of size=93
2020-02-14 18:51:56.936 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 32093 chans
2020-02-14 18:51:57.048 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26336 new chans
2020-02-14 18:51:57.048 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:51:59.662 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:02.301 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:04.815 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:07.520 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:10.270 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:12.913 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:15.890 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:18.563 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:21.247 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:24.386 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:28.704 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:31.529 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:34.191 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:36.846 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:39.424 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:42.214 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:44.937 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:47.661 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:50.419 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:53.452 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:52:58.332 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:03.313 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:08.413 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:13.299 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:18.364 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:23.464 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:28.519 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:33.340 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:38.565 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:43.354 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:48.537 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:53.425 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:53:58.338 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:03.384 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:08.462 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:14.634 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:18.698 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:23.362 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:29.435 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:33.341 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:38.340 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:43.336 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:48.313 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:53.337 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:54:59.054 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:55:03.789 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:55:08.390 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:55:13.523 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:55:18.356 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:55:23.443 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:55:28.345 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 500 new channels
2020-02-14 18:55:33.397 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): querying for 336 new channels
2020-02-14 18:55:37.610 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): no more chans to query
2020-02-14 19:31:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 19:31:55.739249952 +0100 CET m=+157256.225176707, end=2156-03-23 02:00:10.739249952 +0100 CET m=+4295124551.225176707)
2020-02-14 20:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2020-02-14 21:51:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=2020-02-14 21:51:55.739318102 +0100 CET m=+165656.225244672, end=2156-03-23 04:20:10.739318102 +0100 CET m=+4295132951.225244672)
2020-02-14 22:11:55.739 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)

wpaulino commented 4 years ago

lnd attempts to sync the full graph from a random peer every hour. In most cases, this isn't bandwidth intensive, as it'll only query for channels it doesn't know about. However, here it seems like the channels it queried for aren't being persisted for whatever reason, so when it tries another full sync, it queries for the same channels again.

2020-02-13 22:51:57.365 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 31963 chans
2020-02-13 22:51:57.479 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26376 new chans
2020-02-14 05:51:56.773 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 32055 chans
2020-02-14 05:51:56.893 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26357 new chans
2020-02-14 07:51:57.833 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 32051 chans
2020-02-14 07:51:57.993 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26352 new chans
2020-02-14 11:51:56.701 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): filtering through 32050 chans
2020-02-14 11:51:56.815 [INF] DISC: GossipSyncer(`PUBLIC_KEY`): starting query for 26342 new chans

What's the output of lncli getnetworkinfo? Was your node ever offline for more than 2 weeks straight?

bota87 commented 4 years ago

After a crash can stay offline for some hours, until I came back home and unlock the wallet

$ lncli getnetworkinfo
{
    "graph_diameter": 0,
    "avg_out_degree": 6.236186348862406,
    "max_out_degree": 313,
    "num_nodes": 1846,
    "num_channels": 5756,
    "total_network_capacity": "15479557292",
    "avg_channel_size": 2689290.703961084,
    "min_channel_size": "13744",
    "max_channel_size": "268435456",
    "median_channel_size_sat": "500000",
    "num_zombie_chans": "16"
}

wpaulino commented 4 years ago

The channels are being rejected for some reason then, so we'll need to bump up the log level. Could you restart lnd with the flag --debuglevel=DISC=trace,CRTR=trace, wait for the graph to sync, and check your logs for any [DBG], [TRC], and [ERR] messages for DISC and CRTR?

bota87 commented 4 years ago

I see a lot of Got ChannelUpdate for edge not found

2020-02-15 00:34:00.998 [TRC] CRTR: New channel update applied: (*channeldb.ChannelEdgePolicy)(0x34791f0)({
2020-02-15 00:34:02.728 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=663856533683306496), saving for reprocessing later
2020-02-15 00:34:05.790 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=620887619188162561), saving for reprocessing later
2020-02-15 00:34:07.723 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=656929610350067712), saving for reprocessing later
2020-02-15 00:34:07.723 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=589880291869196288), saving for reprocessing later
2020-02-15 00:34:10.768 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=655857586581929985), saving for reprocessing later
2020-02-15 00:34:20.720 [INF] CRTR: Processed channels=0 updates=8 nodes=0 in last 59.999707578s
2020-02-15 00:34:20.843 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=631032812998688769), saving for reprocessing later
2020-02-15 00:34:25.908 [TRC] CRTR: New channel update applied: (*channeldb.ChannelEdgePolicy)(0x40a2cb0)({
2020-02-15 00:34:30.984 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=618609431193583617), saving for reprocessing later
2020-02-15 00:34:30.984 [TRC] CRTR: New channel update applied: (*channeldb.ChannelEdgePolicy)(0x318d730)({

wpaulino commented 4 years ago

That's expected since you're receiving updates for channels you're not aware of. We can ignore those for now.

bota87 commented 4 years ago

What about this? Can be related to the issue? I'm running bitcoind pruned for safe same space...

2020-02-15 00:41:35.581 [TRC] CRTR: New channel update applied: (*channeldb.ChannelEdgePolicy)(0x34a84d0)({
2020-02-15 00:41:36.883 [TRC] DISC: Router rejected channel edge: unable to fetch funding tx for chan_id=660169871147139072: -1: Block not available (pruned data)
2020-02-15 00:41:36.884 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=660169871147139072), saving for reprocessing later
2020-02-15 00:41:36.889 [TRC] DISC: Router rejected channel edge: unable to fetch funding tx for chan_id=618147636224327680: -1: Block not available (pruned data)
2020-02-15 00:41:36.889 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=618147636224327680), saving for reprocessing later
2020-02-15 00:41:37.962 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=620964584991424513), saving for reprocessing later

wpaulino commented 4 years ago

There you go :)

Pruned nodes are not supported at the moment. To prevent issues, you may want to prune up to segwit's activation height.

bota87 commented 4 years ago

happy to have found the problem but... is there a way to prune up to segwit without resync the whole blockchain?

wpaulino commented 4 years ago

I don't think so since all those blocks have already been pruned. Feel free to track progress on pruned node support in https://github.com/lightningnetwork/lnd/issues/2997.

lightningnetwork / lnd