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

Bootstrap fails due to inconsistent schema after group0 catch up when table was recreated in the past #16683

Closed
brushek opened this issue Jan 8, 2024 · 38 comments · Fixed by #17072 or #17123
Assignees
Labels
area/raft area/schema changes Field-Tier1 Urgent issues as per FieldEngineering request P1 Urgent
Milestone

Comments

@brushek
Copy link

brushek commented Jan 8, 2024

This is Scylla's bug tracker, to be used for reporting bugs only.
If you have a question about Scylla, and not a bug, please ask it in
our mailing-list at scylladb-dev@googlegroups.com or in our slack channel.

  • [] I have read the disclaimer above, and I am reporting a suspected malfunction in Scylla.

Installation details
Scylla version (or git commit hash): 5.2.1-0.20230508.f1c45553bc29
Cluster size: 3
OS (AWS AMI): ami-03c1d4115f146edc4

UUID in upload.scylladb.com: 7c269cc2-4bbf-477f-813a-23b0e3bc647b

instance type: i3.large

one of node in 3-node cluster was shutdown by aws (maintenance). When I was trying to add thrid node I get in logs of existing nodes:

Jan 08 12:19:53 ip-10-192-3-246 scylla[225499]:  [shard 0] raft_group_registry - Raft server id 12bcc5e9-e857-46fe-bb89-2f1760e70024 cannot be translated to an IP address.
Jan 08 12:19:54 ip-10-192-3-246 scylla[225499]:  [shard 0] gossip - InetAddress 10.192.23.23 is now UP, status = UNKNOWN
Jan 08 12:19:54 ip-10-192-3-246 scylla[225499]:  [shard 0] raft_group_registry - marking Raft server 12bcc5e9-e857-46fe-bb89-2f1760e70024 as alive for raft groups
Jan 08 12:19:57 ip-10-192-3-246 scylla[225499]:  [shard 0] raft_group_registry - marking Raft server 12bcc5e9-e857-46fe-bb89-2f1760e70024 as dead for raft groups
Jan 08 12:20:02 ip-10-192-3-246 scylla[225499]:  [shard 1] raft_group_registry - (rate limiting dropped 2996 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 12:20:02 ip-10-192-3-246 scylla[225499]:  [shard 1] raft_group_registry - (rate limiting dropped 2996 similar messages) Raft server id 9bb69622-ef18-4db7-ae3b-b8ba414cc449 cannot be translated to an IP address.
Jan 08 12:20:02 ip-10-192-3-246 scylla[225499]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id e97227b6-9e67-4e7b-840a-4a26cbc852bc cannot be translated to an IP address.
Jan 08 12:20:02 ip-10-192-3-246 scylla[225499]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 38128d64-688f-4088-a160-c6b900e7d8ed cannot be translated to an IP address.
Jan 08 12:20:19 ip-10-192-3-246 scylla[225499]:  [shard 1] gossip - failure_detector_loop: Send echo to node 10.192.23.23, status = failed: seastar::rpc::timeout_error (rpc call timed out)
Jan 08 12:20:19 ip-10-192-3-246 scylla[225499]:  [shard 1] gossip - failure_detector_loop: Mark node 10.192.23.23 as DOWN
Jan 08 12:20:19 ip-10-192-3-246 scylla[225499]:  [shard 0] gossip - InetAddress 10.192.23.23 is now DOWN, status = UNKNOWN
Jan 08 12:20:26 ip-10-192-3-246 scylla[225499]:  [shard 0] gossip - FatClient 10.192.23.23 has been silent for 30000ms, removing from gossip
Jan 08 12:21:26 ip-10-192-3-246 scylla[225499]:  [shard 0] gossip - 60000 ms elapsed, 10.192.23.23 gossip quarantine over
Jan 08 12:22:41 ip-10-192-3-246 scylla[225499]:  [shard 0] rpc - client 10.192.23.23:7000: client connection dropped: recv: Connection reset by peer
Jan 08 12:22:41 ip-10-192-3-246 scylla[225499]:  [shard 0] rpc - client 10.192.23.23:7000: client connection dropped: recv: Connection reset by peer

and on new node:

Jan 08 12:25:12 ip-10-192-23-23 systemd[1]: scylla-server.service: Main process exited, code=dumped, status=6/ABRT
Jan 08 12:25:12 ip-10-192-23-23 systemd[1]: scylla-server.service: Failed with result 'core-dump'.
Jan 08 12:25:12 ip-10-192-23-23 systemd[1]: Failed to start Scylla Server.
Jan 08 12:25:12 ip-10-192-23-23 systemd[1]: scylla-server.service: Consumed 1min 33.532s CPU time.
Jan 08 12:25:12 ip-10-192-23-23 systemd[1]: scylla-server.service: Scheduled restart job, restart counter is at 2.
Jan 08 12:25:12 ip-10-192-23-23 systemd[1]: Stopped Scylla Server.
Jan 08 12:25:12 ip-10-192-23-23 systemd[1]: scylla-server.service: Consumed 1min 33.532s CPU time.
Jan 08 12:25:12 ip-10-192-23-23 systemd[1]: Starting Scylla Server...
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: irqbalance is not running
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: No non-NVMe disks to tune
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting NVMe disks: nvme0n1...
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting mask 00000001 in /proc/irq/63/smp_affinity
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting mask 00000002 in /proc/irq/64/smp_affinity
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Writing 'none' to /sys/devices/pci0000:00/0000:00:1e.0/nvme/nvme0/nvme0n1/queue/scheduler
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Writing '2' to /sys/devices/pci0000:00/0000:00:1e.0/nvme/nvme0/nvme0n1/queue/nomerges
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting a physical interface eth0...
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Executing: ethtool -L eth0 rx 2
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Executing: ethtool -L eth0 combined 2
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Distributing IRQs handling Rx and Tx for first 2 channels:
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting mask 00000001 in /proc/irq/79/smp_affinity
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting mask 00000002 in /proc/irq/80/smp_affinity
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Distributing the rest of IRQs
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting mask 00000003 in /sys/class/net/eth0/queues/rx-1/rps_cpus
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting mask 00000003 in /sys/class/net/eth0/queues/rx-0/rps_cpus
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting net.core.rps_sock_flow_entries to 32768
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting limit 16384 in /sys/class/net/eth0/queues/rx-1/rps_flow_cnt
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting limit 16384 in /sys/class/net/eth0/queues/rx-0/rps_flow_cnt
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Trying to disable ntuple filtering HW offload for eth0...ok
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting mask 00000001 in /sys/class/net/eth0/queues/tx-0/xps_cpus
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting mask 00000002 in /sys/class/net/eth0/queues/tx-1/xps_cpus
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Writing '4096' to /proc/sys/net/core/somaxconn
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Writing '4096' to /proc/sys/net/ipv4/tcp_max_syn_backlog
Jan 08 12:25:13 ip-10-192-23-23 scylla_prepare[3960]: Setting clocksource to tsc
Jan 08 12:25:13 ip-10-192-23-23 scylla[3997]: Scylla version 5.2.1-0.20230508.f1c45553bc29 with build-id 88ac66b1719cc7c5b7e982aa34ba5dc95909b84a starting ...
Jan 08 12:25:13 ip-10-192-23-23 scylla[3997]: command used: "/usr/bin/scylla --log-to-syslog 1 --log-to-stdout 0 --default-log-level info --network-stack posix --io-properties-file=/etc/scylla.d/io_properties.yaml --cpuset 0-1 --lock-memory=1"
Jan 08 12:25:13 ip-10-192-23-23 scylla[3997]: parsed command line options: [log-to-syslog, (positional) 1, log-to-stdout, (positional) 0, default-log-level, (positional) info, network-stack, (positional) posix, io-properties-file: /etc/scylla.d/io_properties.yaml, cpuset, (positional) 0-1, lock-memory: 1]
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  seastar - Reactor backend: linux-aio
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - Creation of perf_event based stall detector failed, falling back to posix timer: std::system_error (error system:13, perf_event_open() failed: Permission denied)
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - Created fair group io-queue-66304, capacity rate 14208:163481, limit 12582912, rate 16777216 (factor 1), threshold 164282
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - IO queue uses 0.75ms latency goal for device 66304
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - Created io group dev(66304), length limit 262144:131072, rate 14208000:163481270
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - Created io queue dev(66304) capacities: 512:164282:495721 1024:177418:535642 2048:203690:615484 4096:256233:775168 8192:361321:1094537 16384:571497:1733274 32768:991849:3010748 65536:1832552:5565697 131072:3513957:10675595
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - Created fair group io-queue-0, capacity rate 2147483:2147483, limit 12582912, rate 16777216 (factor 1), threshold 2000
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - IO queue uses 0.75ms latency goal for device 0
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - Created io group dev(0), length limit 4194304:4194304, rate 2147483647:2147483647
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - Created io queue dev(0) capacities: 512:2000:2000 1024:3000:3000 2048:5000:5000 4096:9000:9000 8192:17000:17000 16384:33000:33000 32768:65000:65000 65536:129000:129000 131072:257000:257000
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] seastar - Creation of perf_event based stall detector failed, falling back to posix timer: std::system_error (error system:13, perf_event_open() failed: Permission denied)
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] seastar - updated: blocked-reactor-notify-ms=1000000
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] seastar - updated: blocked-reactor-notify-ms=1000000
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - installing SIGHUP handler
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - Scylla version 5.2.1-0.20230508.f1c45553bc29 with build-id 88ac66b1719cc7c5b7e982aa34ba5dc95909b84a starting ...
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting prometheus API server
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - creating snitch
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] snitch_logger - Ec2Snitch using region: ap-southeast-2, zone: 2c.
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting tokens manager
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting effective_replication_map factory
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting migration manager notifier
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting lifecycle notifier
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - creating tracing
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting API server
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - Scylla API server listening on 127.0.0.1:10000 ...
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] service_level_controller - update_from_distributed_data: starting configuration polling loop
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting system keyspace
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting gossiper
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - seeds={10.192.3.246}, listen_address=10.192.23.23, broadcast_address=10.192.23.23
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting Raft address map
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting direct failure detector pinger service
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting direct failure detector service
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - initializing storage service
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] storage_service - Started node_ops_abort_thread
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] storage_service - Started node_ops_abort_thread
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting per-shard database core
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - creating and verifying directories
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting compaction_manager
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting database
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Set unlimited compaction bandwidth
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: SchemaLog-2-198241.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: SchemaLog-2-198242.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] commitlog - Cannot parse the version of the file: SchemaLog-2-198241.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] commitlog - Cannot parse the version of the file: SchemaLog-2-198242.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - loading system sstables
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Populating Keyspace system
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF cluster_status id=fb70ea0a-1bf9-3772-a5ad-26960611b035 version=67d729c6-31a8-3b49-8c7f-600590c0189c
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF versions id=8b5611ad-b90c-3883-855a-bcc6ddc54f33 version=6af1527e-249e-3bd1-9346-00886d88df34
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF snapshots id=4a9392ae-1937-39f6-a263-01568fd6a3f6 version=24ef45f6-e8d5-3506-897b-66f102ea0cd2
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF config id=3e9372bc-f440-3892-899e-7377c6584b44 version=1c654a28-fa53-3446-bfb4-99803d604b46
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF schema_functions id=d1b675fe-2b50-3ca4-8e49-c0f81989dcad version=a50959dd-2be0-3e4e-8bb5-cf40796e256a
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF token_ring id=33211d19-46b4-3e9c-a90a-6a9f87f1e3d0 version=876a85ee-f7f9-3f44-a78e-9b1d4e11b023
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF schema_triggers id=0359bc71-7123-3ee1-9a4a-b9dfb11fc125 version=75e4ec4c-76da-3f59-984e-66810ba0c62b
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF schema_columns id=296e9c04-9bec-3085-827d-c17d3df2122a version=53cfbb66-ee0d-37be-97bb-b2afb3746f85
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF schema_columnfamilies id=45f5b360-24bc-3f83-a363-1034ea4fa697 version=7f7a5fea-07b7-304d-a6f8-f7aec72cabdb
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF large_partitions id=8a7fe624-96b0-34b1-b90e-f71bddcdd2d3 version=04fa9920-9369-3a96-be39-6dd9fdc816b6
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF scylla_table_schema_history id=0191a53e-40f0-31d4-9171-b0d19ffb17b4 version=2cc890b8-9ade-3afc-ab63-043c8017608e
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF compaction_history id=b4dbb7b4-dc49-3fb5-b3bf-ce6e434832ca version=25cae56a-8d75-39f3-a146-3756ab4981c7
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF runtime_info id=c999823b-87bc-36d9-a378-a90ffab08f00 version=367546c6-8904-3783-84e5-f31c1f00bbe0
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF batchlog id=0290003c-977e-397c-ac3e-fdfdc01d626b version=e2a2e804-49e4-3597-9f16-39fd9475835c
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF schema_usertypes id=3aa75225-4f82-350b-8d5c-430fa221fa0a version=3c53e6bb-56d5-3618-a0b2-4ff5f18127d7
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF large_rows id=40550f66-0858-39a0-9430-f27fc08034e9 version=aee3acb0-7926-317b-848e-db7bc3721695
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF peers id=37f71aca-7dc2-383b-a706-72528af04d4f version=f6f6871f-8c86-3eca-ac0b-2a2e848e395d
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF scylla_local id=2972ec7f-fb20-38dd-aac1-d876f2e3fcbd version=5f0b407d-eedf-3845-a48e-dbb9673d10e1
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF schema_aggregates id=a5fc57fc-9d6c-3bfd-a3fc-01ad54686fea version=d06c934f-9a69-374c-86f1-523ab26fb05c
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF paxos id=b7b7f0c2-fd0a-3410-8c05-3ef614bb7c2d version=6dd372de-72fb-3e1b-9b8c-f97738a67fe9
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF range_xfers id=55d76438-4e55-3f8b-9f6e-676d4af3976d version=dd15a078-409b-350d-9bef-c5f3520832d8
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF size_estimates id=618f817b-005f-3678-b8a4-53f3930b8e86 version=6d4dbcff-f05b-3dc3-95ad-f79f7b10504d
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF protocol_servers id=9504b32b-a121-32b5-bc2d-fee5bc149f15 version=7d629a33-3ae5-38c2-9985-3d34de772679
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF compactions_in_progress id=55080ab0-5d9c-3886-90a4-acb25fe1f77b version=540263f1-40db-3869-8a38-3baadedc222d
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF local id=7ad54392-bcdd-35a6-8417-4e047860b377 version=7fa82c2e-5b67-37dd-8e5e-2079e18f1536
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF hints id=2666e205-73ef-38b3-90fe-fecf96e8f0c7 version=0b74fdd1-e96d-309e-a14e-a5bcd7ac885d
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF raft_state id=92b4e363-0578-33ea-9bca-e9fcb9dd98bb version=6fcecce8-f2ff-393c-9862-e95a81c68465
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF sstable_activity id=5a1ff267-ace0-3f12-8563-cfae6103c65e version=bdec57a3-b234-334b-be9c-7b1f33113995
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF IndexInfo id=9f5c6374-d485-3229-9a0a-5094af9ad1e3 version=bbb3743b-351f-3023-b4fc-09a9be37d529
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF repair_history id=8e097009-c753-3518-a0ec-217f75f5dffa version=042dd699-0b97-31f0-b1b9-e3a79ae2826e
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF views_builds_in_progress id=b7f2c108-78cd-3c80-9cd5-d609b2bd149c version=b905cce5-1474-3085-819a-7592453e2fb9
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Keyspace system: Reading CF built_views id=4b3c50a9-ea87-3d76-9101-6dbc9c38494a version=a28aa0b3-6def-30a7-9fbe-ce78b3f3c9b9
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.indexes, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.indexes
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.view_virtual_columns, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.view_virtual_columns
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.computed_columns, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.computed_columns
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.views, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.views
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.keyspaces, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.keyspaces
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.aggregates, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.aggregates
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.triggers, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.triggers
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.functions, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.functions
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.dropped_columns, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.dropped_columns
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.scylla_tables, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.scylla_tables
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.scylla_keyspaces, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.scylla_keyspaces
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.scylla_aggregates, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.scylla_aggregates
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.types, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.types
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.tables, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.tables
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.indexes, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.indexes
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.view_virtual_columns, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.view_virtual_columns
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.computed_columns, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.computed_columns
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.views, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.views
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.keyspaces, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.keyspaces
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.aggregates, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.aggregates
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.triggers, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.triggers
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.functions, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.functions
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.dropped_columns, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.dropped_columns
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.scylla_tables, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.scylla_tables
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.scylla_keyspaces, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.scylla_keyspaces
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.scylla_aggregates, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.scylla_aggregates
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.types, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.types
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.tables, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.tables
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Starting off-strategy compaction for system_schema.columns, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] compaction_manager - Done with off-strategy compaction for system_schema.columns
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Starting off-strategy compaction for system_schema.columns, 0 candidates were found
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 1] compaction_manager - Done with off-strategy compaction for system_schema.columns
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] legacy_schema_migrator - Moving 0 keyspaces from legacy schema tables to the new schema keyspace (system_schema)
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] legacy_schema_migrator - Dropping legacy schema tables
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Dropping system.schema_aggregates without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Dropping system.schema_functions without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Dropping system.schema_usertypes without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Dropping system.schema_columns without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Dropping system.schema_triggers without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Dropping system.schema_columnfamilies without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Dropping system.schema_keyspaces without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Truncating system.schema_aggregates without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Truncating system.schema_functions without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Truncating system.schema_usertypes without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Truncating system.schema_columns without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Truncating system.schema_triggers without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Truncating system.schema_columnfamilies without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] database - Truncating system.schema_keyspaces without snapshot
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] legacy_schema_migrator - Completed migration of legacy schema tables
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - setting up system keyspace
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - starting schema commit log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-25739.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509507724.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-25740.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509507725.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-25741.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-198241.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509680226.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-198242.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509680227.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-348517.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509830502.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-348518.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509830503.log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] init - replaying schema commit log
Jan 08 12:25:14 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog_replayer - Replaying /var/lib/scylla/commitlog/SchemaLog-2-198241.log, /var/lib/scylla/commitlog/SchemaLog-2-198242.log
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:  [shard 0] commitlog_replayer - Log replay complete, 344 replayed mutations (0 invalid, 0 skipped)
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:  [shard 0] init - replaying schema commit log - flushing memtables
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:  [shard 0] init - replaying schema commit log - removing old commitlog segments
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:  [shard 0] schema_tables - Schema version changed to b4ebcc64-bd51-3ba4-93f3-af81a7253c03
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:  [shard 0] init - loading non-system sstables
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]: scylla: schema.cc:368: schema::schema(schema::private_tag, const schema::raw_schema &, std::optional<raw_view_info>): Assertion `!def.id || def.id == id - column_offset(def.kind)' failed.
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]: Aborting on shard 0.
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]: Backtrace:
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x4fddd98
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x50101d2
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   /opt/scylladb/libreloc/libc.so.6+0x3cb1f
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   /opt/scylladb/libreloc/libc.so.6+0x8ce5b
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   /opt/scylladb/libreloc/libc.so.6+0x3ca75
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   /opt/scylladb/libreloc/libc.so.6+0x267fb
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   /opt/scylladb/libreloc/libc.so.6+0x2671a
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   /opt/scylladb/libreloc/libc.so.6+0x35655
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x1af043b
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x1af3804
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x3168373
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x32381b5
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x31911fa
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x4fee614
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x4fef897
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x4feebd9
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x4f95695
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x4f94808
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x1145734
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x1147240
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x1143e6a
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   /opt/scylladb/libreloc/libc.so.6+0x2750f
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   /opt/scylladb/libreloc/libc.so.6+0x275c8
Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:   0x1142024

and there is no new node joing into cluster.

@mykaul
Copy link
Contributor

mykaul commented Jan 9, 2024

Decoded:

Jan 08 12:25:15 ip-10-192-23-23 scylla[3997]:
[Backtrace #0]
void seastar::backtrace<seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}>(seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}&&) at ./build/release/seastar/./seastar/include/seastar/util/backtrace.hh:59
 (inlined by) seastar::backtrace_buffer::append_backtrace() at ./build/release/seastar/./seastar/src/core/reactor.cc:783
 (inlined by) seastar::print_with_backtrace(seastar::backtrace_buffer&, bool) at ./build/release/seastar/./seastar/src/core/reactor.cc:813
seastar::print_with_backtrace(char const*, bool) at ./build/release/seastar/./seastar/src/core/reactor.cc:825
 (inlined by) seastar::sigabrt_action() at ./build/release/seastar/./seastar/src/core/reactor.cc:3864
 (inlined by) operator() at ./build/release/seastar/./seastar/src/core/reactor.cc:3840
 (inlined by) __invoke at ./build/release/seastar/./seastar/src/core/reactor.cc:3836
/data/scylla-s3-reloc.cache/by-build-id/88ac66b1719cc7c5b7e982aa34ba5dc95909b84a/extracted/scylla/libreloc/libc.so.6: ELF 64-bit LSB shared object, x86-64, version 1 (GNU/Linux), dynamically linked, interpreter /lib64/ld-linux-x86-64.so.2, BuildID[sha1]=81daba31ee66dbd63efdc4252a872949d874d136, for GNU/Linux 3.2.0, not stripped

__GI___sigaction at :?
__pthread_kill_implementation at ??:?
__GI_raise at :?
__GI_abort at :?
__assert_fail_base.cold at ??:?
__GI___assert_fail at :?
schema at ./schema.cc:368
seastar::lw_shared_ptr<schema> seastar::lw_shared_ptr<schema>::make<schema::private_tag, schema::raw_schema&, std::optional<raw_view_info>&>(schema::private_tag&&, schema::raw_schema&, std::optional<raw_view_info>&) at ././seastar/include/seastar/core/shared_ptr.hh:274
 (inlined by) seastar::lw_shared_ptr<schema> seastar::make_lw_shared<schema, schema::private_tag, schema::raw_schema&, std::optional<raw_view_info>&>(schema::private_tag&&, schema::raw_schema&, std::optional<raw_view_info>&) at ././seastar/include/seastar/core/shared_ptr.hh:434
 (inlined by) schema_builder::build() at ./schema.cc:1325
db::schema_tables::create_table_from_mutations(db::schema_ctxt const&, schema_mutations, std::optional<utils::tagged_uuid<table_schema_version_tag> >) at ./db/schema_tables.cc:2986
db::schema_tables::create_table_from_name(seastar::sharded<service::storage_proxy>&, seastar::basic_sstring<char, unsigned int, 15u, true> const&, seastar::basic_sstring<char, unsigned int, 15u, true> const&) at ./db/schema_tables.cc:2717
std::__n4861::coroutine_handle<seastar::internal::coroutine_traits_base<seastar::lw_shared_ptr<schema const> >::promise_type>::resume() const at /usr/bin/../lib/gcc/x86_64-redhat-linux/12/../../../../include/c++/12/coroutine:244
 (inlined by) seastar::internal::coroutine_traits_base<seastar::lw_shared_ptr<schema const> >::promise_type::run_and_dispose() at ././seastar/include/seastar/core/coroutine.hh:78
seastar::reactor::run_tasks(seastar::reactor::task_queue&) at ./build/release/seastar/./seastar/src/core/reactor.cc:2509
 (inlined by) seastar::reactor::run_some_tasks() at ./build/release/seastar/./seastar/src/core/reactor.cc:2946
seastar::reactor::do_run() at ./build/release/seastar/./seastar/src/core/reactor.cc:3115
seastar::reactor::run() at ./build/release/seastar/./seastar/src/core/reactor.cc:2998
seastar::app_template::run_deprecated(int, char**, std::function<void ()>&&) at ./build/release/seastar/./seastar/src/core/app-template.cc:266
seastar::app_template::run(int, char**, std::function<seastar::future<int> ()>&&) at ./build/release/seastar/./seastar/src/core/app-template.cc:157
scylla_main(int, char**) at ./main.cc:546
std::function<int (int, char**)>::operator()(int, char**) const at /usr/bin/../lib/gcc/x86_64-redhat-linux/12/../../../../include/c++/12/bits/std_function.h:591
main at ./main.cc:1810
__libc_start_call_main at ??:?
__libc_start_main_alias_2 at :?
_start at ??:?

May I suggest, before we take another look into this, that you try the latest 5.2.x? See https://forum.scylladb.com/t/release-scylladb-5-2-13/1177 - we've fixed many bugs since 5.2.1.

@mykaul
Copy link
Contributor

mykaul commented Jan 9, 2024

#9774 (comment) ?

@brushek
Copy link
Author

brushek commented Jan 9, 2024

of course, I can try to upgrade to the latest - but as far as I can see the AWS AMI which I used to create the cluster (in the time I was running the cluster on May 2023 this AMI was current) is using unstable apt source (it was part of the AMI - I didn't change it):

deb [arch=amd64,arm64 signed-by=/etc/apt/keyrings/scylladb.gpg] https://downloads.scylladb.com/unstable/scylla/branch-5.2/deb/unified/2023-05-08T22:34:03Z/scylladb-5.2 stable main

can I use:

deb [arch=amd64,arm64 signed-by=/etc/apt/keyrings/scylladb.gpg] https://downloads.scylladb.com/downloads/scylla/deb/debian-ubuntu/scylladb-5.2 stable main

instead of unstable deb ?
And is there any other/proper procedure to upgrade AWS AMI baked scylla cluster then this one:
https://opensource.docs.scylladb.com/stable/upgrade/upgrade-opensource/upgrade-guide-from-5.x.y-to-5.x.z/upgrade-guide-from-5.x.y-to-5.x.z-ubuntu.html

??

@mykaul
Copy link
Contributor

mykaul commented Jan 9, 2024

@yaronkaikov?

@yaronkaikov
Copy link
Contributor

of course, I can try to upgrade to the latest - but as far as I can see the AWS AMI which I used to create the cluster (in the time I was running the cluster on May 2023 this AMI was current) is using unstable apt source (it was part of the AMI - I didn't change it):

deb [arch=amd64,arm64 signed-by=/etc/apt/keyrings/scylladb.gpg] https://downloads.scylladb.com/unstable/scylla/branch-5.2/deb/unified/2023-05-08T22:34:03Z/scylladb-5.2 stable main

can I use:

deb [arch=amd64,arm64 signed-by=/etc/apt/keyrings/scylladb.gpg] https://downloads.scylladb.com/downloads/scylla/deb/debian-ubuntu/scylladb-5.2 stable main

Yes you can

instead of unstable deb ? And is there any other/proper procedure to upgrade AWS AMI baked scylla cluster then this one: https://opensource.docs.scylladb.com/stable/upgrade/upgrade-opensource/upgrade-guide-from-5.x.y-to-5.x.z/upgrade-guide-from-5.x.y-to-5.x.z-ubuntu.html

??

Or follow this procedure

@brushek
Copy link
Author

brushek commented Jan 9, 2024

Thank You @yaronkaikov and @mykaul - I did upgrade to version 5.2.13, but still there is problem with adding third node. Cluster is working on two nodes.
I gathered data from one of working node in cluster, UUID: 295aa462-60bc-4f16-bc8a-30ac53cb152c
and from node which was provisioned to connect to cluster, UUID: 4d11e07e-2d6a-430f-a370-7ee4ef47e19e

all three servers are using version 5.2.13-0.20240103.c57a0a7a46c6-1

Error on wanabe-joining node (last lines):

Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] legacy_schema_migrator - Moving 0 keyspaces from legacy schema tables to the new schema keyspace (system_schema)
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] legacy_schema_migrator - Dropping legacy schema tables
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Dropping system.schema_aggregates without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Dropping system.schema_functions without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Dropping system.schema_usertypes without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Dropping system.schema_columns without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Dropping system.schema_triggers without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Dropping system.schema_columnfamilies without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Dropping system.schema_keyspaces without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Truncating system.schema_aggregates without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Truncating system.schema_functions without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Truncating system.schema_usertypes without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Truncating system.schema_columns without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Truncating system.schema_triggers without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Truncating system.schema_columnfamilies without snapshot
Jan 09 21:23:17 ip-10-192-22-26 scylla[4654]:  [shard 0] database - Truncating system.schema_keyspaces without snapshot
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] legacy_schema_migrator - Completed migration of legacy schema tables
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] init - setting up system keyspace
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] init - starting schema commit log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-73691.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509555676.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-73692.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509555677.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-73693.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-260461.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509742446.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509742447.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-260462.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509742448.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-260463.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-411751.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509893736.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509893737.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-411752.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398509893738.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-411753.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-562528.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510044513.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510044514.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510044515.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-562529.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-562530.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-713333.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510195318.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510195319.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510195320.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-713334.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-713335.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-864320.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510346305.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510346306.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-18014398510346307.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog - Cannot parse the version of the file: CommitLog-2-864321.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] init - replaying schema commit log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog_replayer - Replaying /var/lib/scylla/commitlog/SchemaLog-2-713333.log, /var/lib/scylla/commitlog/SchemaLog-2-713334.log
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] commitlog_replayer - Log replay complete, 344 replayed mutations (0 invalid, 0 skipped)
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] init - replaying schema commit log - flushing memtables
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] init - replaying schema commit log - removing old commitlog segments
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] schema_tables - Schema version changed to b4ebcc64-bd51-3ba4-93f3-af81a7253c03
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:  [shard 0] init - loading non-system sstables
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]: scylla: schema.cc:368: schema::schema(schema::private_tag, const schema::raw_schema &, std::optional<raw_view_info>): Assertion `!def.id || def.id == id - column_offset(def.kind)' failed.
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]: Aborting on shard 0.
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]: Backtrace:
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x50c94c8
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x50fb802
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   /opt/scylladb/libreloc/libc.so.6+0x3cb5f
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   /opt/scylladb/libreloc/libc.so.6+0x8cecb
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   /opt/scylladb/libreloc/libc.so.6+0x3cab5
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   /opt/scylladb/libreloc/libc.so.6+0x267fb
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   /opt/scylladb/libreloc/libc.so.6+0x2671a
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   /opt/scylladb/libreloc/libc.so.6+0x35695
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x1b221cb
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x1b25594
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x31add33
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x327edaf
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x31d6c3a
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x50d9d44
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x50dafc7
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x50da309
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x5080d35
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x507fe98
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x1171754
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x1173260
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x116feaa
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   /opt/scylladb/libreloc/libc.so.6+0x2754f
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   /opt/scylladb/libreloc/libc.so.6+0x27608
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:   0x116e064```

@mykaul
Copy link
Contributor

mykaul commented Jan 10, 2024

Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]: scylla: schema.cc:368: schema::schema(schema::private_tag, const schema::raw_schema &, std::optional<raw_view_info>): Assertion `!def.id || def.id == id - column_offset(def.kind)' failed.
Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]: Aborting on shard 0.

Decoded backtrace still similar to the above:

Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]: Backtrace:Jan 09 21:23:18 ip-10-192-22-26 scylla[4654]:
[Backtrace #0]
void seastar::backtrace<seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}>(seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}&&) at ./build/release/seastar/./seastar/include/seastar/util/backtrace.hh:59
 (inlined by) seastar::backtrace_buffer::append_backtrace() at ./build/release/seastar/./seastar/src/core/reactor.cc:783
 (inlined by) seastar::print_with_backtrace(seastar::backtrace_buffer&, bool) at ./build/release/seastar/./seastar/src/core/reactor.cc:813
seastar::print_with_backtrace(char const*, bool) at ./build/release/seastar/./seastar/src/core/reactor.cc:825
 (inlined by) seastar::sigabrt_action() at ./build/release/seastar/./seastar/src/core/reactor.cc:3864
 (inlined by) operator() at ./build/release/seastar/./seastar/src/core/reactor.cc:3840
 (inlined by) __invoke at ./build/release/seastar/./seastar/src/core/reactor.cc:3836
/data/scylla-s3-reloc.cache/by-build-id/315a01c51465f3304f5dfa743e62ff51f3650ffe/extracted/scylla/libreloc/libc.so.6: ELF 64-bit LSB shared object, x86-64, version 1 (GNU/Linux), dynamically linked, interpreter /lib64/ld-linux-x86-64.so.2, BuildID[sha1]=0dc6d3e329f8bf5e8c1de63c4c9d560fb9953ade, for GNU/Linux 3.2.0, not stripped

__GI___sigaction at :?
__pthread_kill_implementation at ??:?
__GI_raise at :?
__GI_abort at :?
__assert_fail_base.cold at ??:?
__GI___assert_fail at :?
schema at ./schema.cc:368
seastar::lw_shared_ptr<schema> seastar::lw_shared_ptr<schema>::make<schema::private_tag, schema::raw_schema&, std::optional<raw_view_info>&>(schema::private_tag&&, schema::raw_schema&, std::optional<raw_view_info>&) at ././seastar/include/seastar/core/shared_ptr.hh:274
 (inlined by) seastar::lw_shared_ptr<schema> seastar::make_lw_shared<schema, schema::private_tag, schema::raw_schema&, std::optional<raw_view_info>&>(schema::private_tag&&, schema::raw_schema&, std::optional<raw_view_info>&) at ././seastar/include/seastar/core/shared_ptr.hh:434
 (inlined by) schema_builder::build() at ./schema.cc:1325
db::schema_tables::create_table_from_mutations(db::schema_ctxt const&, schema_mutations, std::optional<utils::tagged_uuid<table_schema_version_tag> >) at ./db/schema_tables.cc:3002
db::schema_tables::create_table_from_name(seastar::sharded<service::storage_proxy>&, seastar::basic_sstring<char, unsigned int, 15u, true> const&, seastar::basic_sstring<char, unsigned int, 15u, true> const&) at ./db/schema_tables.cc:2733
std::__n4861::coroutine_handle<seastar::internal::coroutine_traits_base<seastar::lw_shared_ptr<schema const> >::promise_type>::resume() const at /usr/bin/../lib/gcc/x86_64-redhat-linux/12/../../../../include/c++/12/coroutine:244
 (inlined by) seastar::internal::coroutine_traits_base<seastar::lw_shared_ptr<schema const> >::promise_type::run_and_dispose() at ././seastar/include/seastar/core/coroutine.hh:78
seastar::reactor::run_tasks(seastar::reactor::task_queue&) at ./build/release/seastar/./seastar/src/core/reactor.cc:2509
 (inlined by) seastar::reactor::run_some_tasks() at ./build/release/seastar/./seastar/src/core/reactor.cc:2946
seastar::reactor::do_run() at ./build/release/seastar/./seastar/src/core/reactor.cc:3115
seastar::reactor::run() at ./build/release/seastar/./seastar/src/core/reactor.cc:2998
seastar::app_template::run_deprecated(int, char**, std::function<void ()>&&) at ./build/release/seastar/./seastar/src/core/app-template.cc:266
seastar::app_template::run(int, char**, std::function<seastar::future<int> ()>&&) at ./build/release/seastar/./seastar/src/core/app-template.cc:157
scylla_main(int, char**) at ./main.cc:546
std::function<int (int, char**)>::operator()(int, char**) const at /usr/bin/../lib/gcc/x86_64-redhat-linux/12/../../../../include/c++/12/bits/std_function.h:591
main at ./main.cc:1816
__libc_start_call_main at ??:?
__libc_start_main_alias_2 at :?

@mykaul
Copy link
Contributor

mykaul commented Jan 10, 2024

@tgrabiec - is the above #11396 ? What's the workaround (it's seem to be fixed in 5.2, but what if the user is already suffering from it and IS using 5.2?)

@tgrabiec
Copy link
Contributor

@tgrabiec - is the above #11396 ?

There is not enough information to determine this. I need the sstables of system_schema keyspace from the node which is failing, and from one of the old nodes.

@tgrabiec
Copy link
Contributor

@kostja @kbr-scylla Logs are spammed with messages like this, seem to repeat every 5 min:

Jan 08 21:59:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 21:59:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 38128d64-688f-4088-a160-c6b900e7d8ed cannot be translated to an IP address.
Jan 08 21:59:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id e97227b6-9e67-4e7b-840a-4a26cbc852bc cannot be translated to an IP address.
Jan 08 22:04:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2996 similar messages) Raft server id 9bb69622-ef18-4db7-ae3b-b8ba414cc449 cannot be translated to an IP address.
Jan 08 22:04:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2996 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 22:04:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2996 similar messages) Raft server id 38128d64-688f-4088-a160-c6b900e7d8ed cannot be translated to an IP address.
Jan 08 22:04:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2996 similar messages) Raft server id e97227b6-9e67-4e7b-840a-4a26cbc852bc cannot be translated to an IP address.
Jan 08 22:09:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 9bb69622-ef18-4db7-ae3b-b8ba414cc449 cannot be translated to an IP address.
Jan 08 22:09:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 22:09:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 38128d64-688f-4088-a160-c6b900e7d8ed cannot be translated to an IP address.
Jan 08 22:09:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id e97227b6-9e67-4e7b-840a-4a26cbc852bc cannot be translated to an IP address.
Jan 08 22:14:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 9bb69622-ef18-4db7-ae3b-b8ba414cc449 cannot be translated to an IP address.
Jan 08 22:14:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 22:14:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 38128d64-688f-4088-a160-c6b900e7d8ed cannot be translated to an IP address.
Jan 08 22:14:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id e97227b6-9e67-4e7b-840a-4a26cbc852bc cannot be translated to an IP address.
Jan 08 22:19:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 22:19:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 9bb69622-ef18-4db7-ae3b-b8ba414cc449 cannot be translated to an IP address.
Jan 08 22:19:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 38128d64-688f-4088-a160-c6b900e7d8ed cannot be translated to an IP address.
Jan 08 22:19:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id e97227b6-9e67-4e7b-840a-4a26cbc852bc cannot be translated to an IP address.
Jan 08 22:24:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 22:24:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 9bb69622-ef18-4db7-ae3b-b8ba414cc449 cannot be translated to an IP address.
Jan 08 22:24:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 38128d64-688f-4088-a160-c6b900e7d8ed cannot be translated to an IP address.
Jan 08 22:24:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id e97227b6-9e67-4e7b-840a-4a26cbc852bc cannot be translated to an IP address.
Jan 08 22:29:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 22:29:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 9bb69622-ef18-4db7-ae3b-b8ba414cc449 cannot be translated to an IP address.
Jan 08 22:29:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 38128d64-688f-4088-a160-c6b900e7d8ed cannot be translated to an IP address.
Jan 08 22:29:03 ip-10-192-12-166 scylla[284647]:  [shard 1] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id e97227b6-9e67-4e7b-840a-4a26cbc852bc cannot be translated to an IP address.
Jan 08 22:34:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 438d1cff-ac7b-4d30-afa9-be395561a3ef cannot be translated to an IP address.
Jan 08 22:34:02 ip-10-192-12-166 scylla[284647]:  [shard 0] raft_group_registry - (rate limiting dropped 2997 similar messages) Raft server id 9bb69622-ef18-4db7-ae3b-b8ba414cc449 cannot be translated to an IP address.

@tgrabiec
Copy link
Contributor

@tgrabiec - is the above #11396 ?

There is not enough information to determine this. I need the sstables of system_schema keyspace from the node which is failing, and from one of the old nodes.

@brushek Please also add "system" keyspace to the mix.

@tgrabiec
Copy link
Contributor

The first failure is here, which looks like raft log catch up:

Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to c416b434-d47c-3dd1-b844-2337c1ae09f2
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to c416b434-d47c-3dd1-b844-2337c1ae09f2
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to c416b434-d47c-3dd1-b844-2337c1ae09f2
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to c416b434-d47c-3dd1-b844-2337c1ae09f2
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to 831afac6-de35-3d40-8fb9-b430304f496e
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to 831afac6-de35-3d40-8fb9-b430304f496e
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to ea0f31ee-e77e-3788-90ad-72cbb61bba9b
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to ea0f31ee-e77e-3788-90ad-72cbb61bba9b
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to 5ba8d0e2-a18d-3fe8-9322-25e9420415fe
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to 5ba8d0e2-a18d-3fe8-9322-25e9420415fe
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Altering scylla_manager.scheduler_task id=8275c0f0-043f-11ee-914a-4f5b86ec011f version=cbbab501-ce27-38f3-b9c3-23c69f2bae81
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] query_processor - Column definitions for scylla_manager.scheduler_task changed, invalidating related prepared statements
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 1] query_processor - Column definitions for scylla_manager.scheduler_task changed, invalidating related prepared statements
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to b8872422-b241-3680-8eb2-1033c767a575
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to b8872422-b241-3680-8eb2-1033c767a575
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Creating scylla_manager.repair_unit id=83a6c6e0-043f-11ee-914a-4f5b86ec011f version=c7e9f305-899a-3566-9e81-e3bf6746ee6d
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to cf6c3581-6fb5-3333-aa07-d03d34617fd1
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Creating scylla_manager.repair_config id=84306940-043f-11ee-914a-4f5b86ec011f version=1bf9dd79-63a9-3eee-87cb-75df57b6c5c1
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to 2e81c4aa-6456-3eb6-a3ca-ac7182496e67
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Altering scylla_manager.repair_run id=9ddfe190-043f-11ee-914a-4f5b86ec011f version=d90efaf2-c827-3d9a-aab2-128c5188fdd7
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] query_processor - Column definitions for scylla_manager.repair_run changed, invalidating related prepared statements
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 1] query_processor - Column definitions for scylla_manager.repair_run changed, invalidating related prepared statements
Jan 09 21:10:13 ip-10-192-22-26 scylla[3701]:  [shard 0] schema_tables - Schema version changed to 7c416c2b-c8be-33ea-91e7-a949b87882db
Jan 09 21:10:14 ip-10-192-22-26 scylla[3701]: scylla: schema.cc:368: schema::schema(schema::private_tag, const schema::raw_schema &, std::optional<raw_view_info>): Assertion `!def.id || def.id == id - column_offset(def.kind)' failed.

@tgrabiec
Copy link
Contributor

Here's a hypothesis.

Schema change history:

  1. Create table x with pk A
  2. Drop table x
  3. Create table x with pk B

Also:

  1. all those entries are in the raft log.
  2. tombstones from step 2 already expired

When the new node pulls the raft group0 snapshot, it ends up with "table x with pk B". But since the drop from step 2 is expired, we no longer have the tombstones which would cover "Create" from step 1. So when we apply entry from step 1, it's not shadowed, and schema merge sees this an alter of table x which tries to add "pk A", and we hit the assertion because we have both "pk A" and "pk B".

Does that sound plausible @gleb-cloudius @kbr-scylla?

@brushek Did you make such schema changes?

@tgrabiec
Copy link
Contributor

Refs #15607

@brushek
Copy link
Author

brushek commented Jan 10, 2024

@tgrabiec - is the above #11396 ?

There is not enough information to determine this. I need the sstables of system_schema keyspace from the node which is failing, and from one of the old nodes.

@tgrabiec I'm not sure what exactly You need, do I need to upload to upload.scylla.com all files from this directory or similar:

/var/lib/scylla/data/system_schema/scylla_tables-5d912ff1f7593665b2c88042ab5103dd/

?

or simple put: can You write how to do this properly without sending You bunch of unneeded stuff ?

Here's a hypothesis.

Schema change history:

  1. Create table x with pk A
  2. Drop table x
  3. Create table x with pk B

Also:

  1. all those entries are in the raft log.
  2. tombstones from step 2 already expired

When the new node pulls the raft group0 snapshot, it ends up with "table x with pk B". But since the drop from step 2 is expired, we no longer have the tombstones which would cover "Create" from step 1. So when we apply entry from step 1, it's not shadowed, and schema merge sees this an alter of table x which tries to add "pk A", and we hit the assertion because we have both "pk A" and "pk B".

Does that sound plausible @gleb-cloudius @kbr-scylla?

@brushek Did you make such schema changes?

I will ask developers, I'm not using this database, I'm trying to fix it.

@tgrabiec
Copy link
Contributor

@tgrabiec - is the above #11396 ?

There is not enough information to determine this. I need the sstables of system_schema keyspace from the node which is failing, and from one of the old nodes.

@tgrabiec I'm not sure what exactly You need, do I need to upload to upload.scylla.com all files from this directory or similar:

/var/lib/scylla/data/system_schema/scylla_tables-5d912ff1f7593665b2c88042ab5103dd/

?

Yes:

tar czvf system.tgz /var/lib/scylla/data/system_schema/ /var/lib/scylla/data/system

@brushek
Copy link
Author

brushek commented Jan 10, 2024

Yes:

tar czvf system.tgz /var/lib/scylla/data/system_schema/ /var/lib/scylla/data/system

OK.

here is UUID on upload.scyll.com from the server which I tried to connect to cluster: 879bfad3-fba6-4f8d-a7b0-d9d5b948d262
and here is UUID from one of running node in the cluster: 94fac0ac-b0ec-4d41-b64f-b4c9f6349554

@tgrabiec
Copy link
Contributor

tgrabiec commented Jan 10, 2024

The offending table is scylla_manager.repair_run_progress:

 keyspace_name  | table_name                   | column_name | clustering_order | column_name_bytes      | kind          | position | type
----------------+------------------------------+-------------+------------------+------------------------+---------------+----------+------

 scylla_manager |          repair_run_progress |     task_id |             NONE |       0x7461736b5f6964 | partition_key |        1 | uuid
 scylla_manager |          repair_run_progress |     unit_id |             NONE |       0x756e69745f6964 | partition_key |        1 | uuid

@brushek
Copy link
Author

brushek commented Jan 10, 2024

Can I drop this table or alter it somehow to fix the problem ?

@tgrabiec
Copy link
Contributor

On the old node, it looks good (we have task_id, not unit_id):

 scylla_manager |  repair_run_progress |    cluster_id |             NONE |       0x636c75737465725f6964 | partition_key |        0 | uuid
 scylla_manager |  repair_run_progress |        run_id |             NONE |               0x72756e5f6964 | partition_key |        2 | uuid
 scylla_manager |  repair_run_progress |       task_id |             NONE |             0x7461736b5f6964 | partition_key |        1 | uuid

@brushek
Copy link
Author

brushek commented Jan 10, 2024

I'm creating new node with user data (during creation of aws instance) where there is cluster_name and seed ip configured:

scylla_yaml:
  cluster_name: cluster-9d2fc057-9c1b-b112-dca1-fe41d66e8406
  experimental: false
  seed_provider:
    - class_name: org.apache.cassandra.locator.SimpleSeedProvider
      parameters:
        - seeds: 10.192.3.246
start_scylla_on_first_boot: true

there is no chance to have some left overs or some other initial data on new node (based on my understanding of running and adding new node into existing cluster). So how it is possible that brand new node has offending table ?

@tgrabiec
Copy link
Contributor

@brushek Can you please also send the sstables from the other old node?

@tgrabiec
Copy link
Contributor

tgrabiec commented Jan 11, 2024

I checked scylla manager code, and they indeed have:

in 002-init_repair.cql:

CREATE TABLE IF NOT EXISTS repair_run_progress (
    cluster_id uuid,
    unit_id uuid,
    run_id uuid,
    host text,
    shard int,
    segment_count int,
    segment_success int,
    segment_error int,
    last_start_token bigint,
    last_start_time timestamp,
    last_command_id int,
    PRIMARY KEY((cluster_id, unit_id, run_id), host, shard)
) WITH default_time_to_live = 360000;

in v2.2.0.cql:

DROP TABLE repair_run_progress;
CREATE TABLE repair_run_progress (
    cluster_id uuid,
    task_id uuid,
    run_id uuid,
    host text,
    keyspace_name text,
    table_name text,
    token_ranges bigint,
    success bigint,
    error bigint,
    PRIMARY KEY ((cluster_id, task_id, run_id), host, keyspace_name, table_name)
) WITH default_time_to_live = 15552000;

Which fits with the hypothesis of raft log replay.

@brushek
Copy link
Author

brushek commented Jan 11, 2024

@brushek Can you please also send the sstables from the other old node?

Of course, here it is: 90058d97-d2ab-4900-be0f-eddff08e4100

@gleb-cloudius
Copy link
Contributor

Here's a hypothesis.

Schema change history:

1. Create table x with pk A

2. Drop table x

3. Create table x with pk B

Also:

1. all those entries are in the raft log.

2. tombstones from step 2 already expired

What is the TTL for the tombstone? It is not user controllable, right?

When the new node pulls the raft group0 snapshot, it ends up with "table x with pk B". But since the drop from step 2 is expired, we no longer have the tombstones which would cover "Create" from step 1. So when we apply entry from step 1, it's not shadowed, and schema merge sees this an alter of table x which tries to add "pk A", and we hit the assertion because we have both "pk A" and "pk B".

Does that sound plausible @gleb-cloudius @kbr-scylla?

Yes.

@brushek Did you make such schema changes?

@tgrabiec
Copy link
Contributor

What is the TTL for the tombstone? It is not user controllable, right?

It's hard-coded to 7 days. The only correct value would be +inf, otherwise it will always eventually expire.

I think those schema changes come from scylla manager setup scripts, so all the changes were done when the database was set up. Raft log has 18 entries and no snapshot.

Can you think of a way to safely recover from this? Truncating the log would do it so that replay comes only from the snapshot.

@tgrabiec tgrabiec changed the title Problem with adding node to cluster (scylla 5.2.1) Bootstrap fails due to inconsistent schema after group0 catch up when table was recreated in the past Jan 11, 2024
@kbr-scylla
Copy link
Contributor

kbr-scylla commented Jan 11, 2024

The "snapshot" that was transferred here was actually a migration_manager schema pull. Then Raft tried to transfer the log -- not a snapshot.

With ff386e7, which ended up only in 5.4, this would not happen. Instead of applying log entries, a snapshot would be transferred.

Unfortunately, upgrading to 5.4 wouldn't help here, because the decision is made when Raft storage is initialized.

@brushek is the cluster currently still a 3-node cluster (i.e. third node is dead)? Or did you remove the third (dead) node and now it's a 2-node cluster?

You can run the Raft recovery procedure https://opensource.docs.scylladb.com/branch-5.2/architecture/raft.html#raft-manual-recovery-procedure, this will truncate the Raft log as @tgrabiec suggested -- but note that if you're doing QUORUM ops with RF=3, you'll introduce temporary unavailability when restarting the nodes.


Besides, we need to come up with a general fix for 5.2 and for upgraded clusters. ff386e7 only works in cases when group 0 was created with ff386e7 already applied. If I understand correctly, every user and customer (2023 enterprise as well) is affected by this, it's enough to introduce a tombstone inside schema (e.g. drop a table), wait 7 days, then add a node, and you will get a table resurrection or worse.

cc @gleb-cloudius @kostja

@tgrabiec
Copy link
Contributor

The "snapshot" that was transferred here was actually a migration_manager schema pull. Then Raft tried to transfer the log -- not a snapshot.

With ff386e7, which ended up only in 5.4, this would not happen. Instead of applying log entries, a snapshot would be transferred.

I don't see why it wouldn't happen. Isn't snapshot transfer equivalent to migration_manager schema pull? We will still send the current schema and then replay raft log on top of it.

@kbr-scylla
Copy link
Contributor

migration_manager schema pull doesn't transfer system.group0_history. Raft snapshot transfer does. This prevents replaying Raft log from doing anything (commands will be turned to no-ops due to state_id check).

Maybe that's the fix we're looking for -- transfer group0_history (if it exists / if Raft is enabled) during migration_manager pulls...

@mykaul mykaul added backport/5.2 Issues that should be backported to 5.2 branch once they'll be fixed backport/5.4 Issues that should be backported to 5.4 branch once they'll be fixed labels Jan 31, 2024
@mykaul mykaul modified the milestones: 5.4.2, 6.0 Jan 31, 2024
kbr-scylla added a commit to kbr-scylla/scylladb that referenced this issue Jan 31, 2024
When we upgrade a cluster to use Raft, or perform manual Raft recovery
procedure (which also creates a fresh group 0 cluster, using the same
algorithm as during upgrade), we start with a non-empty group 0 state
machine; in particular, the schema tables are non-empty.

In this case we need to ensure that nodes which join group 0 receive the
group 0 state. Right now this is not the case. In previous releases,
where group 0 consisted only of schema, and schema pulls were also done
outside Raft, those nodes received schema through this outside
mechanism. In 91f609d we disabled
schema pulls outside Raft; we're also extending group 0 with other
things, like topology-specific state.

To solve this, we force snapshot transfers by setting the initial
snapshot index on the first group 0 server to `1` instead of `0`. During
replication, Raft will see that the joining servers are behind,
triggering snapshot transfer and forcing them to pull group 0 state.

It's unnecessary to do this for cluster which bootstraps with Raft
enabled right away but it also doesn't hurt, so we keep the logic simple
and don't introduce branches based on that.

Extend Raft upgrade tests with a node bootstrap step at the end to
prevent regressions (without this patch, the step would hang - node
would never join, waiting for schema).

Fixes: scylladb#14066

Closes scylladb#14336

(cherry picked from commit ff386e7)

Backport note: contrary to the claims above, it turns out that it is
actually necessary to create snapshots in clusters which bootstrap with
Raft, because of tombstones in current schema state expire hence
applying schema mutations from old Raft log entries is not really
idempotent. Snapshot transfer, which transfers group 0 history and
state_ids, prevents old entries from applying schema mutations over
latest schema state.

Ref: scylladb#16683
kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Jan 31, 2024
This allows the user of `raft::server` to cause it to create a snapshot
and truncate the Raft log (leaving no trailing entries; in the future we
may extend the API to specify number of trailing entries left if
needed). In a later commit we'll add a REST endpoint to Scylla to
trigger group 0 snapshots.

One use case for this API is to create group 0 snapshots in Scylla
deployments which upgraded to Raft in version 5.2 and started with an
empty Raft log with no snapshot at the beginning. This causes problems,
e.g. when a new node bootstraps to the cluster, it will not receive a
snapshot that would contain both schema and group 0 history, which would
then lead to inconsistent schema state and trigger assertion failures as
observed in scylladb#16683.

In 5.4 the logic of initial group 0 setup was changed to start the Raft
log with a snapshot at index 1 (ff386e7)
but a problem remains with these existing deployments coming from 5.2,
we need a way to trigger a snapshot in them (other than performing 1000
arbitrary schema changes).

Another potential use case in the future would be to trigger snapshots
based on external memory pressure in tablet Raft groups (for strongly
consistent tables).

The PR adds the API to `raft::server` and a HTTP endpoint that uses it.

In a follow-up PR, we plan to modify group 0 server startup logic to automatically
call this API if it sees that no snapshot is present yet (to automatically
fix the aforementioned 5.2 deployments once they upgrade.)

Closes scylladb#16816

* github.com:scylladb/scylladb:
  raft: remove `empty()` from `fsm_output`
  test: add test for manual triggering of Raft snapshots
  api: add HTTP endpoint to trigger Raft snapshots
  raft: server: add `trigger_snapshot` API
  raft: server: track last persisted snapshot descriptor index
  raft: server: framework for handling server requests
  raft: server: inline `poll_fsm_output`
  raft: server: fix indentation
  raft: server: move `io_fiber`'s processing of `batch` to a separate function
  raft: move `poll_output()` from `fsm` to `server`
  raft: move `_sm_events` from `fsm` to `server`
  raft: fsm: remove constructor used only in tests
  raft: fsm: move trace message from `poll_output` to `has_output`
  raft: fsm: extract `has_output()`
  raft: pass `max_trailing_entries` through `fsm_output` to `store_snapshot_descriptor`
  raft: server: pass `*_aborted` to `set_exception` call

(cherry picked from commit d202d32)

Backport notes:
- `has_output()` has a smaller condition in the backported version
  (because the condition was smaller in `poll_output()`)
- `process_fsm_output` has a smaller body (because `io_fiber` had a
  smaller body) in the backported version
kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Jan 31, 2024
… from Kamil Braun

The persisted snapshot index may be 0 if the snapshot was created in
older version of Scylla, which means snapshot transfer won't be
triggered to a bootstrapping node. Commands present in the log may not
cover all schema changes --- group 0 might have been created through the
upgrade upgrade procedure, on a cluster with existing schema. So a
deployment with index=0 snapshot is broken and we need to fix it. We can
use the new `raft::server::trigger_snapshot` API for that.

Also add a test.

Fixes scylladb#16683

Closes scylladb#17072

* github.com:scylladb/scylladb:
  test: add test for fixing a broken group 0 snapshot
  raft_group0: trigger snapshot if existing snapshot index is 0

(cherry picked from commit 181f68f)
kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Jan 31, 2024
This allows the user of `raft::server` to cause it to create a snapshot
and truncate the Raft log (leaving no trailing entries; in the future we
may extend the API to specify number of trailing entries left if
needed). In a later commit we'll add a REST endpoint to Scylla to
trigger group 0 snapshots.

One use case for this API is to create group 0 snapshots in Scylla
deployments which upgraded to Raft in version 5.2 and started with an
empty Raft log with no snapshot at the beginning. This causes problems,
e.g. when a new node bootstraps to the cluster, it will not receive a
snapshot that would contain both schema and group 0 history, which would
then lead to inconsistent schema state and trigger assertion failures as
observed in scylladb#16683.

In 5.4 the logic of initial group 0 setup was changed to start the Raft
log with a snapshot at index 1 (ff386e7)
but a problem remains with these existing deployments coming from 5.2,
we need a way to trigger a snapshot in them (other than performing 1000
arbitrary schema changes).

Another potential use case in the future would be to trigger snapshots
based on external memory pressure in tablet Raft groups (for strongly
consistent tables).

The PR adds the API to `raft::server` and a HTTP endpoint that uses it.

In a follow-up PR, we plan to modify group 0 server startup logic to automatically
call this API if it sees that no snapshot is present yet (to automatically
fix the aforementioned 5.2 deployments once they upgrade.)

Closes scylladb#16816

* github.com:scylladb/scylladb:
  raft: remove `empty()` from `fsm_output`
  test: add test for manual triggering of Raft snapshots
  api: add HTTP endpoint to trigger Raft snapshots
  raft: server: add `trigger_snapshot` API
  raft: server: track last persisted snapshot descriptor index
  raft: server: framework for handling server requests
  raft: server: inline `poll_fsm_output`
  raft: server: fix indentation
  raft: server: move `io_fiber`'s processing of `batch` to a separate function
  raft: move `poll_output()` from `fsm` to `server`
  raft: move `_sm_events` from `fsm` to `server`
  raft: fsm: remove constructor used only in tests
  raft: fsm: move trace message from `poll_output` to `has_output`
  raft: fsm: extract `has_output()`
  raft: pass `max_trailing_entries` through `fsm_output` to `store_snapshot_descriptor`
  raft: server: pass `*_aborted` to `set_exception` call

(cherry picked from commit d202d32)

Backport notes:
- `has_output()` has a smaller condition in the backported version
  (because the condition was smaller in `poll_output()`)
- `process_fsm_output` has a smaller body (because `io_fiber` had a
  smaller body) in the backported version
kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Jan 31, 2024
… from Kamil Braun

The persisted snapshot index may be 0 if the snapshot was created in
older version of Scylla, which means snapshot transfer won't be
triggered to a bootstrapping node. Commands present in the log may not
cover all schema changes --- group 0 might have been created through the
upgrade upgrade procedure, on a cluster with existing schema. So a
deployment with index=0 snapshot is broken and we need to fix it. We can
use the new `raft::server::trigger_snapshot` API for that.

Also add a test.

Fixes scylladb#16683

Closes scylladb#17072

* github.com:scylladb/scylladb:
  test: add test for fixing a broken group 0 snapshot
  raft_group0: trigger snapshot if existing snapshot index is 0

(cherry picked from commit 181f68f)

Backport node: test_raft_fix_broken_snapshot had to be removed because
the "error injections enabled at startup" feature does not yet exist in
5.2.
@mykaul
Copy link
Contributor

mykaul commented Feb 1, 2024

Is there an issue I can track the 5.4 backport effort for this?

@kbr-scylla
Copy link
Contributor

I'll open a PR as soon as c911bf1 gets into master. (It's already queued, I need to include it in the backport)

kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Feb 2, 2024
This allows the user of `raft::server` to cause it to create a snapshot
and truncate the Raft log (leaving no trailing entries; in the future we
may extend the API to specify number of trailing entries left if
needed). In a later commit we'll add a REST endpoint to Scylla to
trigger group 0 snapshots.

One use case for this API is to create group 0 snapshots in Scylla
deployments which upgraded to Raft in version 5.2 and started with an
empty Raft log with no snapshot at the beginning. This causes problems,
e.g. when a new node bootstraps to the cluster, it will not receive a
snapshot that would contain both schema and group 0 history, which would
then lead to inconsistent schema state and trigger assertion failures as
observed in scylladb#16683.

In 5.4 the logic of initial group 0 setup was changed to start the Raft
log with a snapshot at index 1 (ff386e7)
but a problem remains with these existing deployments coming from 5.2,
we need a way to trigger a snapshot in them (other than performing 1000
arbitrary schema changes).

Another potential use case in the future would be to trigger snapshots
based on external memory pressure in tablet Raft groups (for strongly
consistent tables).

The PR adds the API to `raft::server` and a HTTP endpoint that uses it.

In a follow-up PR, we plan to modify group 0 server startup logic to automatically
call this API if it sees that no snapshot is present yet (to automatically
fix the aforementioned 5.2 deployments once they upgrade.)

Closes scylladb#16816

* github.com:scylladb/scylladb:
  raft: remove `empty()` from `fsm_output`
  test: add test for manual triggering of Raft snapshots
  api: add HTTP endpoint to trigger Raft snapshots
  raft: server: add `trigger_snapshot` API
  raft: server: track last persisted snapshot descriptor index
  raft: server: framework for handling server requests
  raft: server: inline `poll_fsm_output`
  raft: server: fix indentation
  raft: server: move `io_fiber`'s processing of `batch` to a separate function
  raft: move `poll_output()` from `fsm` to `server`
  raft: move `_sm_events` from `fsm` to `server`
  raft: fsm: remove constructor used only in tests
  raft: fsm: move trace message from `poll_output` to `has_output`
  raft: fsm: extract `has_output()`
  raft: pass `max_trailing_entries` through `fsm_output` to `store_snapshot_descriptor`
  raft: server: pass `*_aborted` to `set_exception` call

(cherry picked from commit d202d32)

Backport notes:
- `has_output()` has a smaller condition in the backported version
  (because the condition was smaller in `poll_output()`)
- `process_fsm_output` has a smaller body (because `io_fiber` had a
  smaller body) in the backported version
- the HTTP API is only started if `raft_group_registry` is started
kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Feb 2, 2024
… from Kamil Braun

The persisted snapshot index may be 0 if the snapshot was created in
older version of Scylla, which means snapshot transfer won't be
triggered to a bootstrapping node. Commands present in the log may not
cover all schema changes --- group 0 might have been created through the
upgrade upgrade procedure, on a cluster with existing schema. So a
deployment with index=0 snapshot is broken and we need to fix it. We can
use the new `raft::server::trigger_snapshot` API for that.

Also add a test.

Fixes scylladb#16683

Closes scylladb#17072

* github.com:scylladb/scylladb:
  test: add test for fixing a broken group 0 snapshot
  raft_group0: trigger snapshot if existing snapshot index is 0

(cherry picked from commit 181f68f)

Backport note: test_raft_fix_broken_snapshot had to be removed because
the "error injections enabled at startup" feature does not yet exist in
5.2.
kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Feb 2, 2024
This allows the user of `raft::server` to cause it to create a snapshot
and truncate the Raft log (leaving no trailing entries; in the future we
may extend the API to specify number of trailing entries left if
needed). In a later commit we'll add a REST endpoint to Scylla to
trigger group 0 snapshots.

One use case for this API is to create group 0 snapshots in Scylla
deployments which upgraded to Raft in version 5.2 and started with an
empty Raft log with no snapshot at the beginning. This causes problems,
e.g. when a new node bootstraps to the cluster, it will not receive a
snapshot that would contain both schema and group 0 history, which would
then lead to inconsistent schema state and trigger assertion failures as
observed in scylladb#16683.

In 5.4 the logic of initial group 0 setup was changed to start the Raft
log with a snapshot at index 1 (ff386e7)
but a problem remains with these existing deployments coming from 5.2,
we need a way to trigger a snapshot in them (other than performing 1000
arbitrary schema changes).

Another potential use case in the future would be to trigger snapshots
based on external memory pressure in tablet Raft groups (for strongly
consistent tables).

The PR adds the API to `raft::server` and a HTTP endpoint that uses it.

In a follow-up PR, we plan to modify group 0 server startup logic to automatically
call this API if it sees that no snapshot is present yet (to automatically
fix the aforementioned 5.2 deployments once they upgrade.)

Closes scylladb#16816

* github.com:scylladb/scylladb:
  raft: remove `empty()` from `fsm_output`
  test: add test for manual triggering of Raft snapshots
  api: add HTTP endpoint to trigger Raft snapshots
  raft: server: add `trigger_snapshot` API
  raft: server: track last persisted snapshot descriptor index
  raft: server: framework for handling server requests
  raft: server: inline `poll_fsm_output`
  raft: server: fix indentation
  raft: server: move `io_fiber`'s processing of `batch` to a separate function
  raft: move `poll_output()` from `fsm` to `server`
  raft: move `_sm_events` from `fsm` to `server`
  raft: fsm: remove constructor used only in tests
  raft: fsm: move trace message from `poll_output` to `has_output`
  raft: fsm: extract `has_output()`
  raft: pass `max_trailing_entries` through `fsm_output` to `store_snapshot_descriptor`
  raft: server: pass `*_aborted` to `set_exception` call

(cherry picked from commit d202d32)

Backport note: the HTTP API is only started if raft_group_registry is
started.
kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Feb 2, 2024
… from Kamil Braun

The persisted snapshot index may be 0 if the snapshot was created in
older version of Scylla, which means snapshot transfer won't be
triggered to a bootstrapping node. Commands present in the log may not
cover all schema changes --- group 0 might have been created through the
upgrade upgrade procedure, on a cluster with existing schema. So a
deployment with index=0 snapshot is broken and we need to fix it. We can
use the new `raft::server::trigger_snapshot` API for that.

Also add a test.

Fixes scylladb#16683

Closes scylladb#17072

* github.com:scylladb/scylladb:
  test: add test for fixing a broken group 0 snapshot
  raft_group0: trigger snapshot if existing snapshot index is 0

(cherry picked from commit 181f68f)
@kbr-scylla
Copy link
Contributor

#17123

kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Feb 2, 2024
This allows the user of `raft::server` to cause it to create a snapshot
and truncate the Raft log (leaving no trailing entries; in the future we
may extend the API to specify number of trailing entries left if
needed). In a later commit we'll add a REST endpoint to Scylla to
trigger group 0 snapshots.

One use case for this API is to create group 0 snapshots in Scylla
deployments which upgraded to Raft in version 5.2 and started with an
empty Raft log with no snapshot at the beginning. This causes problems,
e.g. when a new node bootstraps to the cluster, it will not receive a
snapshot that would contain both schema and group 0 history, which would
then lead to inconsistent schema state and trigger assertion failures as
observed in scylladb#16683.

In 5.4 the logic of initial group 0 setup was changed to start the Raft
log with a snapshot at index 1 (ff386e7)
but a problem remains with these existing deployments coming from 5.2,
we need a way to trigger a snapshot in them (other than performing 1000
arbitrary schema changes).

Another potential use case in the future would be to trigger snapshots
based on external memory pressure in tablet Raft groups (for strongly
consistent tables).

The PR adds the API to `raft::server` and a HTTP endpoint that uses it.

In a follow-up PR, we plan to modify group 0 server startup logic to automatically
call this API if it sees that no snapshot is present yet (to automatically
fix the aforementioned 5.2 deployments once they upgrade.)

Closes scylladb#16816

* github.com:scylladb/scylladb:
  raft: remove `empty()` from `fsm_output`
  test: add test for manual triggering of Raft snapshots
  api: add HTTP endpoint to trigger Raft snapshots
  raft: server: add `trigger_snapshot` API
  raft: server: track last persisted snapshot descriptor index
  raft: server: framework for handling server requests
  raft: server: inline `poll_fsm_output`
  raft: server: fix indentation
  raft: server: move `io_fiber`'s processing of `batch` to a separate function
  raft: move `poll_output()` from `fsm` to `server`
  raft: move `_sm_events` from `fsm` to `server`
  raft: fsm: remove constructor used only in tests
  raft: fsm: move trace message from `poll_output` to `has_output`
  raft: fsm: extract `has_output()`
  raft: pass `max_trailing_entries` through `fsm_output` to `store_snapshot_descriptor`
  raft: server: pass `*_aborted` to `set_exception` call

(cherry picked from commit d202d32)

Backport note: the HTTP API is only started if raft_group_registry is
started.
kbr-scylla pushed a commit to kbr-scylla/scylladb that referenced this issue Feb 2, 2024
… from Kamil Braun

The persisted snapshot index may be 0 if the snapshot was created in
older version of Scylla, which means snapshot transfer won't be
triggered to a bootstrapping node. Commands present in the log may not
cover all schema changes --- group 0 might have been created through the
upgrade upgrade procedure, on a cluster with existing schema. So a
deployment with index=0 snapshot is broken and we need to fix it. We can
use the new `raft::server::trigger_snapshot` API for that.

Also add a test.

Fixes scylladb#16683

Closes scylladb#17072

* github.com:scylladb/scylladb:
  test: add test for fixing a broken group 0 snapshot
  raft_group0: trigger snapshot if existing snapshot index is 0

(cherry picked from commit 181f68f)
denesb added a commit that referenced this issue Feb 7, 2024
Backports required to fix #16683 in 5.4:
- add an API to trigger Raft snapshot
- use the API when we restart and see that the existing snapshot is at index 0, to trigger a new one --- in order to fix broken deployments that already bootstrapped with index-0 snapshot (we may get such deployments by upgrading from 5.2)

Closes #17123

* github.com:scylladb/scylladb:
  test_raft_snapshot_request: fix flakiness (again)
  test_raft_snapshot_request: fix flakiness
  Merge 'raft_group0: trigger snapshot if existing snapshot index is 0' from Kamil Braun
  Merge 'Add an API to trigger snapshot in Raft servers' from Kamil Braun
denesb added a commit that referenced this issue Feb 7, 2024
Backports required to fix #16683 in 5.2:
- when creating first group 0 server, create a snapshot with non-empty ID, and start it at index 1 instead of 0 to force snapshot transfer to servers that join group 0
- add an API to trigger Raft snapshot
- use the API when we restart and see that the existing snapshot is at index 0, to trigger a new one --- in order to fix broken deployments that already bootstrapped with index-0 snapshot.

Closes #17087

* github.com:scylladb/scylladb:
  test_raft_snapshot_request: fix flakiness (again)
  test_raft_snapshot_request: fix flakiness
  Merge 'raft_group0: trigger snapshot if existing snapshot index is 0' from Kamil Braun
  Merge 'Add an API to trigger snapshot in Raft servers' from Kamil Braun
  raft: server: add workaround for #12972
  raft: Store snapshot update and truncate log atomically
  service: raft: force initial snapshot transfer in new cluster
  raft_sys_table_storage: give initial snapshot a non zero value
@mykaul mykaul removed Backport candidate backport/5.2 Issues that should be backported to 5.2 branch once they'll be fixed backport/5.4 Issues that should be backported to 5.4 branch once they'll be fixed labels Feb 7, 2024
dgarcia360 pushed a commit to dgarcia360/scylla that referenced this issue Apr 30, 2024
This allows the user of `raft::server` to ask it to create a snapshot
and truncate the Raft log. In a later commit we'll add a REST endpoint
to Scylla to trigger group 0 snapshots.

One use case for this API is to create group 0 snapshots in Scylla
deployments which upgraded to Raft in version 5.2 and started with an
empty Raft log with no snapshot at the beginning. This causes problems,
e.g. when a new node bootstraps to the cluster, it will not receive a
snapshot that would contain both schema and group 0 history, which would
then lead to inconsistent schema state and trigger assertion failures as
observed in scylladb#16683.

In 5.4 the logic of initial group 0 setup was changed to start the Raft
log with a snapshot at index 1 (ff386e7)
but a problem remains with these existing deployments coming from 5.2,
we need a way to trigger a snapshot in them (other than performing 1000
arbitrary schema changes).

Another potential use case in the future would be to trigger snapshots
based on external memory pressure in tablet Raft groups (for strongly
consistent tables).
dgarcia360 pushed a commit to dgarcia360/scylla that referenced this issue Apr 30, 2024
This uses the `trigger_snapshot()` API added in previous commit on a
server running for the given Raft group.

It can be used for example in tests or in the context of disaster
recovery (ref scylladb#16683).
dgarcia360 pushed a commit to dgarcia360/scylla that referenced this issue Apr 30, 2024
The persisted snapshot index may be 0 if the snapshot was created in
older version of Scylla, which means snapshot transfer won't be
triggered to a bootstrapping node. Commands present in the log may not
cover all schema changes --- group 0 might have been created through the
upgrade upgrade procedure, on a cluster with existing schema. So a
deployment with index=0 snapshot is broken and we need to fix it. We can
use the new `raft::server::trigger_snapshot` API for that.

Fixes scylladb#16683
dgarcia360 pushed a commit to dgarcia360/scylla that referenced this issue Apr 30, 2024
In a cluster with group 0 with snapshot at index 0 (such group 0 might
be established in a 5.2 cluster, then preserved once it upgrades to 5.4
or later), no snapshot transfer will be triggered when a node is
bootstrapped. This way to new node might not obtain full schema, or
obtain incorrect schema, like in scylladb#16683.

Simulate this scenario in a test case using the RECOVERY mode and error
injections. Check that the newly added logic for creating a new snapshot
if such situation is detected helps in this case.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/raft area/schema changes Field-Tier1 Urgent issues as per FieldEngineering request P1 Urgent
Projects
None yet
8 participants