scylla-cluster-tests icon indicating copy to clipboard operation
scylla-cluster-tests copied to clipboard

Published 20 hours ago • verified publisher icon scylladb

`tier1/longevity-schema-topology-changes-12h-test` CI job may get quorum failures for 10 minutes

Open vponomaryov opened this issue 1 year ago • 1 comments

Issue description

  • [ ] This issue is a regression.
  • [ ] It is unknown if this issue is a regression.

Running the scylla-master/tier1/longevity-schema-topology-changes-12h-test#2 we had 2 nemesis threads.

There are 2 distinct time ranges of about ~10 minutes when scylla-bench starts failing, reaches 30 retries failure and finishes failures. FIrst:

2024/02/26 00:00:44 BATCH >>> [query statement="INSERT INTO scylla_bench.test (pk, ck, v) VALUES (?, ?, ?)" pk=16 cks=400..449 avgValueSize=2530 consistency=QUORUM] || retry: attempt №0, sleep for 409.332987ms
    ...
14h9m35.7s     216   10800      0 40ms   40ms   4.4ms  3.8ms  3.3ms  2.5ms  2.7ms  
2024/02/26 00:02:37 BATCH >>> [query statement="INSERT INTO scylla_bench.test (pk, ck, v) VALUES (?, ?, ?)" pk=12 cks=50..99 avgValueSize=2473 consistency=QUORUM] || ERROR: 30 attempts applied: abort requested
    ...
2024/02/26 00:10:57 BATCH >>> [query statement="INSERT INTO scylla_bench.test (pk, ck, v) VALUES (?, ?, ?)" pk=36 cks=200..249 avgValueSize=2627 consistency=QUORUM] || retry: attempt №4, sleep for 1s

And second:

2024/02/26 08:48:38 BATCH >>> [query statement="INSERT INTO scylla_bench.test (pk, ck, v) VALUES (?, ?, ?)" pk=33 cks=550..599 avgValueSize=2378 consistency=QUORUM] || retry: attempt №0, sleep for 64.08249ms
    ...
2024/02/26 08:50:58 BATCH >>> [query statement="INSERT INTO scylla_bench.test (pk, ck, v) VALUES (?, ?, ?)" pk=28 cks=850..899 avgValueSize=2669 consistency=QUORUM] || ERROR: 30 attempts applied: Operation timed out for scylla_bench.test - received only 2 responses from 3 CL=QUORUM.
    ...
2024/02/26 08:59:50 BATCH >>> [query statement="INSERT INTO scylla_bench.test (pk, ck, v) VALUES (?, ?, ?)" pk=40 cks=0..49 avgValueSize=2702 consistency=QUORUM] || retry: attempt №0, sleep for 334.208577ms

Both cases are 100% identical. At that time we have 2 specific nemesis running at the same time - disrupt_terminate_and_replace_node and disrupt_add_drop_column. The first nemesis after start of the replace step, de-facto, changes quorum nodes number from 3 to 4 and the second nemesis changes schema for 10 minutes in a row. Logs:

node-25
2024-02-25T23:58:41.107+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] raft_group0 - setup_group0: joining group 0...
...
2024-02-25T23:58:41.107+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] raft_group0 - setup_group0: successfully joined group 0.
...
2024-02-25T23:58:42.188+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25  !WARNING | scylla[6067]:  [shard 0:main] seastar_memory - oversized allocation: 1048576 bytes. This is non-fatal, but could lead to latency and/or fragmentation issues. Please report: at 0x623517e 0x6235790 0x6235a78 0x5cd9ef8 0x5cdcd15 0x3e699a2 0x3e637f2 0x3e6b426 0x3e68f21 0x370c96f 0x376e482 0x3768714 0x3752785 0x37d5497 0x13fb49a 0x5d3190f 0x5d32bf7 0x5d31f58 0x5cc0f47 0x5cc00fc 0x138c1f9 0x138dc50 0x138a87c /opt/scylladb/libreloc/libc.so.6+0x27b89 /opt/scylladb/libreloc/libc.so.6+0x27c4a 0x1388124
    + long traces
...
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] storage_service - replace[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: Added replacing_node=10.4.10.241/fd33a9fe-29fc-4eb2-a2e7-62953a15e46ato replace existing_node=10.4.9.30/412b063a-f37b-42bf-a6c9-248a081bc045, coordinator=10.4.10.241/fd33a9fe-29fc-4eb2-a2e7-62953a15e46a
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] token_metadata - Added node fd33a9fe-29fc-4eb2-a2e7-62953a15e46a as pending replacing endpoint which replaces existing node 412b063a-f37b-42bf-a6c9-248a081bc045
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] node_ops - replace[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: Finished replace_prepare[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: ignore_nodes={}, leaving_nodes={}, replace_nodes={{10.4.9.30 -> 10.4.10.241}}, bootstrap_nodes={}, repair_tables={}
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] storage_service - replace[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: Allow nodes={10.4.10.241, 10.4.10.90, 10.4.11.177, 10.4.9.97, 10.4.8.203} to mark replacing node=10.4.10.241 as alive
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] node_ops - replace[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: Started replace_prepare_mark_alive[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: ignore_nodes={}, leaving_nodes={}, replace_nodes={{10.4.9.30 -> 10.4.10.241}}, bootstrap_nodes={}, repair_tables={}
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] node_ops - replace[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: Finished replace_prepare_mark_alive[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: ignore_nodes={}, leaving_nodes={}, replace_nodes={{10.4.9.30 -> 10.4.10.241}}, bootstrap_nodes={}, repair_tables={}
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] node_ops - replace[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: Started replace_prepare_pending_ranges[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: ignore_nodes={}, leaving_nodes={}, replace_nodes={{10.4.9.30 -> 10.4.10.241}}, bootstrap_nodes={}, repair_tables={}
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] node_ops - replace[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: Finished replace_prepare_pending_ranges[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: ignore_nodes={}, leaving_nodes={}, replace_nodes={{10.4.9.30 -> 10.4.10.241}}, bootstrap_nodes={}, repair_tables={}
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] storage_service - enable_repair_based_node_ops=true, allowed_repair_based_node_ops={decommission ,bootstrap ,rebuild ,removenode ,replace}
2024-02-26T00:00:33.215+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] storage_service - replace[1b5ff6f5-c7d7-4a16-a85d-fbf3ad9554e6]: Using repair based node ops to sync data
...
2024-02-26T00:00:42.403+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] schema_tables - Altering scylla_bench.test id=1968b500-d3c3-11ee-833b-e744f9240cc4 version=143874e0-d43a-11ee-8ecf-8232600b8818
2024-02-26T00:00:42.403+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]: Reactor stalled for 405 ms on shard 0. Backtrace: 0x5d1fc6a 0x5d1f075 0x5d2042f 0x3dbaf 0x2f200c2 0x2f1fefe 0x2a012d9 0x2a0126c 0x2a01345 0x2a01204 0x37e4367 0x370ce12 0x2031eb2 0x2026e7b 0x2025adb 0x202a899 0x3768dda 0x3752785 0x37d5497 0x13fb49a 0x5d3190f 0x5d32bf7 0x5d31f58 0x5cc0f47 0x5cc00fc 0x138c1f9 0x138dc50 0x138a87c 0x27b89 0x27c4a 0x1388124
...
2024-02-26T00:10:55.582+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 4:strm] query_processor - Column definitions for scylla_bench.test changed, invalidating related prepared statements
2024-02-26T00:10:55.582+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] migration_manager - Gossiping my schema version 7a70da1c-d43b-11ee-b206-bcc06a1656b9
2024-02-26T00:10:55.582+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 0:strm] schema_tables - Schema version changed to 7a70da1c-d43b-11ee-b206-bcc06a1656b9
2024-02-26T00:10:55.582+00:00 longevity-parallel-topology-schema--db-node-b3392b32-25     !INFO | scylla[6067]:  [shard 5:strm] migration_manager - Schema merge with 10.4.9.97:0 completed

So, we get only 2 answers from 3 expected (quorum of 4 nodes) because we have only 2 stabily working nodes, one removed and one in the process of replacement with constant schema changes caused by the second nemesis. It is indicated with the following kind of DB messages:

query_processor - Column definitions for scylla_bench.test changed, invalidating related prepared statements

So, possible fix is usage of the RF=4 (instead of the RF=3) where addition of one more node won't cause quorum nodes number bump.

Steps to Reproduce

  1. Run 2 nemesis threads where disrupt_terminate_and_replace_node and disrupt_add_drop_column run at the same time.
  2. See quorum errors from scylla-bench

Expected behavior: We should not have quorum errors like above.

Actual behavior: We have quorum errors.

Impact

SCT makes itself to fail.

How frequently does it reproduce?

Observed first time.

Installation details

SCT Version: master Scylla version (or git commit hash): master (5.5)

Logs

vponomaryov avatar Mar 04 '24 12:03 vponomaryov

happens again this week run,

disrupt_add_drop_column is happening first, and then disrupt_terminate_and_replace_node, but doesn't seem like they are running at the same time...

regardless lots of nemesis are being skipped, which in turn make those two be run multiple times (and next to each other, not clear why, maybe they are part of a very small set left...)

Packages

Scylla version: 5.5.0~dev-20240301.94cd23588832 with build-id d010caa35e3ede60b884b4c94bcc945bfd3ccd4b

Kernel Version: 5.15.0-1055-aws

Installation details

Cluster size: 5 nodes (i4i.2xlarge)

Scylla Nodes used in this run:

  • longevity-parallel-topology-schema--db-node-e0c2c48e-9 (18.201.133.54 | 10.4.10.13) (shards: -1)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-8 (18.203.187.76 | 10.4.11.65) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-7 (3.249.105.49 | 10.4.10.50) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-6 (54.171.178.149 | 10.4.8.12) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-5 (3.253.69.228 | 10.4.10.111) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-4 (3.255.251.142 | 10.4.8.106) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-36 (3.254.199.190 | 10.4.8.75) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-35 (3.254.106.128 | 10.4.11.141) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-34 (3.255.226.137 | 10.4.8.39) (shards: -1)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-33 (18.203.154.48 | 10.4.8.221) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-32 (34.242.120.54 | 10.4.9.133) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-31 (54.74.219.205 | 10.4.9.160) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-30 (18.201.192.255 | 10.4.9.243) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-3 (54.78.142.232 | 10.4.8.7) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-29 (34.244.237.129 | 10.4.8.120) (shards: -1)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-28 (18.201.228.186 | 10.4.11.14) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-27 (52.214.146.234 | 10.4.10.10) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-26 (3.250.89.138 | 10.4.8.230) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-25 (54.154.163.137 | 10.4.8.53) (shards: -1)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-24 (3.255.168.227 | 10.4.11.121) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-23 (54.171.165.149 | 10.4.10.236) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-22 (54.217.151.53 | 10.4.10.114) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-21 (54.217.133.215 | 10.4.10.129) (shards: -1)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-20 (54.73.159.153 | 10.4.11.190) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-2 (54.77.170.179 | 10.4.9.161) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-19 (63.35.178.143 | 10.4.9.82) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-18 (34.253.180.231 | 10.4.9.93) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-17 (3.252.144.137 | 10.4.10.68) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-16 (34.242.155.71 | 10.4.9.94) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-15 (18.201.32.157 | 10.4.10.195) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-14 (3.250.46.29 | 10.4.10.41) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-13 (18.201.211.46 | 10.4.10.137) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-12 (54.76.16.168 | 10.4.9.162) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-11 (34.245.213.59 | 10.4.9.192) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-10 (3.255.124.100 | 10.4.8.43) (shards: 7)
  • longevity-parallel-topology-schema--db-node-e0c2c48e-1 (3.252.82.229 | 10.4.8.189) (shards: 7)

OS / Image: ami-01715fc6d97a1e044 (aws: undefined_region)

Test: longevity-schema-topology-changes-12h-test Test id: e0c2c48e-fa11-405b-a284-846e7f201122 Test name: scylla-master/tier1/longevity-schema-topology-changes-12h-test Test config file(s):

Logs and commands
  • Restore Monitor Stack command: $ hydra investigate show-monitor e0c2c48e-fa11-405b-a284-846e7f201122
  • Restore monitor on AWS instance using Jenkins job
  • Show all stored logs command: $ hydra investigate show-logs e0c2c48e-fa11-405b-a284-846e7f201122

Logs:

Jenkins job URL Argus

fruch avatar Mar 05 '24 10:03 fruch

@roy have a PR that should be addressing this

fruch avatar May 27 '24 21:05 fruch

@roy have a PR that should be addressing this

Do I? Maybe you mixed it with another PR I have for the 200k rows?

roydahan avatar May 29 '24 15:05 roydahan

@roy have a PR that should be addressing this

Do I? Maybe you mixed it with another PR I have for the 200k rows?

my mistake I was seen the s-b related part, and I thought it was antheor manifest of the case you were working.

anyhow this one kind of not really clear, I don't see how we get into only 2 nodes working in this case.

fruch avatar May 29 '24 15:05 fruch

@vponomaryov

this sound like a scylla issue, not SCT

schema and topology changes are not supposed to be affecting each other, nor the load like that. SCT isn't doing something wrong in this situation.

fruch avatar May 29 '24 15:05 fruch

@vponomaryov

please raise a core issue for this one, schema changes should be forcing out to pick higher RF. if it does it's a regression.

fruch avatar Jun 17 '24 06:06 fruch

@vponomaryov

please raise a core issue for this one, schema changes should be forcing out to pick higher RF. if it does it's a regression.

I looked at the lots of recent builds of the same CI job. And there are no such failures for 3 months so far.

So, I am not sure it worth re-filing the bug with such an old scylla build, especially knowing that the last appearance of the problem was before the active phase of bugfixes for the 6.0

So, I am leaning to close this one as cannot reproduce.

@roydahan @fruch agree?

vponomaryov avatar Jun 21 '24 16:06 vponomaryov

Fine by me.

roydahan avatar Jun 24 '24 00:06 roydahan

Not reproduced for quite some time

fruch avatar Jun 24 '24 04:06 fruch