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

gossipd: gossip_store: get delete entry offset #7320

Closed
vincenzopalazzo opened this issue May 17, 2024 · 2 comments · Fixed by #7368
Closed

gossipd: gossip_store: get delete entry offset #7320

vincenzopalazzo opened this issue May 17, 2024 · 2 comments · Fixed by #7368

Comments

@vincenzopalazzo
Copy link
Collaborator

Issue and Steps to Reproduce

2024-05-17T02:56:12.701Z DEBUG   0296b2db342fcf87ea94d981757fdf4d3e545bd5cef4919f58b5d38dfdd73bf5c9-gossipd: Bad gossip order: Unknown channel 824349x1837x0
2024-05-17T02:56:12.701Z DEBUG   0296b2db342fcf87ea94d981757fdf4d3e545bd5cef4919f58b5d38dfdd73bf5c9-gossipd: Bad gossip order: Unknown channel 824353x1419x1
2024-05-17T02:56:12.701Z **BROKEN** gossipd: gossip_store: get delete entry offset 554921761/585584347 (version v24.02.1-151-g6e2ab02-modded)
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: common/daemon.c:38 (send_backtrace) 0x55b4c962518b
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: common/status.c:221 (status_failed) 0x55b4c962e83e
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:466 (gossip_store_get_with_hdr) 0x55b4c961b6e3
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:491 (check_msg_type) 0x55b4c961b75d
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:509 (gossip_store_set_flag) 0x55b4c961b8e0
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:561 (gossip_store_del) 0x55b4c961bb26
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:913 (process_node_announcement) 0x55b4c961c472
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:1111 (reprocess_queued_msgs) 0x55b4c961d6a6
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:670 (gossmap_manage_handle_get_txout_reply) 0x55b4c961d840
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: gossipd/gossipd.c:585 (recv_req) 0x55b4c9619e6a
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: common/daemon_conn.c:35 (handle_read) 0x55b4c9625436
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x55b4c96b8506
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:407 (do_plan) 0x55b4c96b898d
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:417 (io_ready) 0x55b4c96b8a26
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/poll.c:453 (io_loop) 0x55b4c96ba315
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: gossipd/gossipd.c:683 (main) 0x55b4c961a84c
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ../csu/libc-start.c:308 (__libc_start_main) 0x7f3931a3dd09
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: (null):0 ((null)) 0x55b4c9616d39
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: (null):0 ((null)) 0xffffffffffffffff
2024-05-17T02:56:12.702Z **BROKEN** gossipd: STATUS_FAIL_INTERNAL_ERROR: gossip_store: get delete entry offset 554921761/585584347

Working on commit 153567d

@ksedgwic
Copy link
Collaborator

ksedgwic commented Jun 1, 2024

Just reported a fresh case, unsure which issue is the correct place:

#7249 (comment)

@vincenzopalazzo vincenzopalazzo added bug component::gossipd and removed in diagnostic issue under diagnostic labels Jun 4, 2024
@vincenzopalazzo vincenzopalazzo added this to the v24.05 milestone Jun 4, 2024
rustyrussell added a commit to rustyrussell/lightning that referenced this issue Jun 4, 2024
When we process pending channel updates, it can cause the node_announcement
to be moved.  Then, we process a new node_announcement and go to delete
the old one, but it's already moved!

Do the obvious thing, and refresh gossmap if necessary each time around
the loop.

```
2024-05-17T02:56:12.701Z **BROKEN** gossipd: gossip_store: get delete entry offset 554921761/585584347 (version v24.02.1-151-g6e2ab02-modded)
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: common/daemon.c:38 (send_backtrace) 0x55b4c962518b
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: common/status.c:221 (status_failed) 0x55b4c962e83e
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:466 (gossip_store_get_with_hdr) 0x55b4c961b6e3
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:491 (check_msg_type) 0x55b4c961b75d
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:509 (gossip_store_set_flag) 0x55b4c961b8e0
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:561 (gossip_store_del) 0x55b4c961bb26
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:913 (process_node_announcement) 0x55b4c961c472
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:1111 (reprocess_queued_msgs) 0x55b4c961d6a6
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:670 (gossmap_manage_handle_get_txout_reply) 0x55b4c961d840
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: gossipd/gossipd.c:585 (recv_req) 0x55b4c9619e6a
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: common/daemon_conn.c:35 (handle_read) 0x55b4c9625436
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x55b4c96b8506
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:407 (do_plan) 0x55b4c96b898d
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:417 (io_ready) 0x55b4c96b8a26
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/poll.c:453 (io_loop) 0x55b4c96ba315
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: gossipd/gossipd.c:683 (main) 0x55b4c961a84c
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ../csu/libc-start.c:308 (__libc_start_main) 0x7f3931a3dd09
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: (null):0 ((null)) 0x55b4c9616d39
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: (null):0 ((null)) 0xffffffffffffffff
2024-05-17T02:56:12.702Z **BROKEN** gossipd: STATUS_FAIL_INTERNAL_ERROR: gossip_store: get delete entry offset 554921761/585584347
```

Reported-by: Vincenzo Palazzo
Fixes: ElementsProject#7320
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
@rustyrussell
Copy link
Contributor

Ah, this looked familiar, it's like one I already fixed (1018b54), but a different path. Same problem though (stale gossmap) so fix was easy...

rustyrussell added a commit to rustyrussell/lightning that referenced this issue Jun 4, 2024
When we process pending channel updates, it can cause the node_announcement
to be moved.  Then, we process a new node_announcement and go to delete
the old one, but it's already moved!

Do the obvious thing, and refresh gossmap if necessary each time around
the loop.

```
2024-05-17T02:56:12.701Z **BROKEN** gossipd: gossip_store: get delete entry offset 554921761/585584347 (version v24.02.1-151-g6e2ab02-modded)
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: common/daemon.c:38 (send_backtrace) 0x55b4c962518b
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: common/status.c:221 (status_failed) 0x55b4c962e83e
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:466 (gossip_store_get_with_hdr) 0x55b4c961b6e3
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:491 (check_msg_type) 0x55b4c961b75d
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:509 (gossip_store_set_flag) 0x55b4c961b8e0
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:561 (gossip_store_del) 0x55b4c961bb26
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:913 (process_node_announcement) 0x55b4c961c472
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:1111 (reprocess_queued_msgs) 0x55b4c961d6a6
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:670 (gossmap_manage_handle_get_txout_reply) 0x55b4c961d840
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: gossipd/gossipd.c:585 (recv_req) 0x55b4c9619e6a
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: common/daemon_conn.c:35 (handle_read) 0x55b4c9625436
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x55b4c96b8506
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:407 (do_plan) 0x55b4c96b898d
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:417 (io_ready) 0x55b4c96b8a26
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/poll.c:453 (io_loop) 0x55b4c96ba315
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: gossipd/gossipd.c:683 (main) 0x55b4c961a84c
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ../csu/libc-start.c:308 (__libc_start_main) 0x7f3931a3dd09
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: (null):0 ((null)) 0x55b4c9616d39
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: (null):0 ((null)) 0xffffffffffffffff
2024-05-17T02:56:12.702Z **BROKEN** gossipd: STATUS_FAIL_INTERNAL_ERROR: gossip_store: get delete entry offset 554921761/585584347
```

Reported-by: Vincenzo Palazzo
Fixes: ElementsProject#7320
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
endothermicdev pushed a commit that referenced this issue Jun 4, 2024
When we process pending channel updates, it can cause the node_announcement
to be moved.  Then, we process a new node_announcement and go to delete
the old one, but it's already moved!

Do the obvious thing, and refresh gossmap if necessary each time around
the loop.

```
2024-05-17T02:56:12.701Z **BROKEN** gossipd: gossip_store: get delete entry offset 554921761/585584347 (version v24.02.1-151-g6e2ab02-modded)
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: common/daemon.c:38 (send_backtrace) 0x55b4c962518b
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: common/status.c:221 (status_failed) 0x55b4c962e83e
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:466 (gossip_store_get_with_hdr) 0x55b4c961b6e3
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:491 (check_msg_type) 0x55b4c961b75d
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:509 (gossip_store_set_flag) 0x55b4c961b8e0
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossip_store.c:561 (gossip_store_del) 0x55b4c961bb26
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:913 (process_node_announcement) 0x55b4c961c472
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:1111 (reprocess_queued_msgs) 0x55b4c961d6a6
2024-05-17T02:56:12.701Z **BROKEN** gossipd: backtrace: gossipd/gossmap_manage.c:670 (gossmap_manage_handle_get_txout_reply) 0x55b4c961d840
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: gossipd/gossipd.c:585 (recv_req) 0x55b4c9619e6a
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: common/daemon_conn.c:35 (handle_read) 0x55b4c9625436
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x55b4c96b8506
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:407 (do_plan) 0x55b4c96b898d
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/io.c:417 (io_ready) 0x55b4c96b8a26
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ccan/ccan/io/poll.c:453 (io_loop) 0x55b4c96ba315
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: gossipd/gossipd.c:683 (main) 0x55b4c961a84c
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: ../csu/libc-start.c:308 (__libc_start_main) 0x7f3931a3dd09
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: (null):0 ((null)) 0x55b4c9616d39
2024-05-17T02:56:12.702Z **BROKEN** gossipd: backtrace: (null):0 ((null)) 0xffffffffffffffff
2024-05-17T02:56:12.702Z **BROKEN** gossipd: STATUS_FAIL_INTERNAL_ERROR: gossip_store: get delete entry offset 554921761/585584347
```

Reported-by: Vincenzo Palazzo
Fixes: #7320
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants