[
https://issues.apache.org/jira/browse/CASSANDRA-17411?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17511481#comment-17511481
]
Brandon Williams commented on CASSANDRA-17411:
----------------------------------------------
Following these steps, I received:
{noformat}
2022-03-23 20:36:12,259 - target-dc3 - __main__ - INFO - Got 0/552 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:36:12,265 - target-dc1 - __main__ - INFO - Got 0/553 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:36:12,348 - target-dc2 - __main__ - INFO - Got 0/552 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:37:12,276 - target-dc3 - __main__ - INFO - Got 0/569 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:37:12,337 - target-dc1 - __main__ - INFO - Got 0/569 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:37:12,432 - target-dc2 - __main__ - INFO - Got 0/569 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:38:12,282 - target-dc3 - __main__ - INFO - Got 0/575 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:38:12,415 - target-dc1 - __main__ - INFO - Got 0/575 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:38:12,456 - target-dc2 - __main__ - INFO - Got 0/575 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:39:12,373 - target-dc3 - __main__ - INFO - Got 0/577 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:39:12,556 - target-dc2 - __main__ - INFO - Got 0/578 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:39:16,284 - target-dc1 - __main__ - INFO - Got 1/565 (0.176991)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:39:42,083 - target-dc3 - cassandra.connection - WARNING -
Heartbeat failed for connection (139909259222464) to 127.0.0.1:9042
2022-03-23 20:39:42,106 - target-dc1 - cassandra.connection - WARNING -
Heartbeat failed for connection (139909259218800) to 127.0.0.1:9042
2022-03-23 20:39:42,149 - target-dc2 - cassandra.connection - WARNING -
Heartbeat failed for connection (139909259222224) to 127.0.0.1:9042
2022-03-23 20:39:47,113 - target-dc1 - cassandra.cluster - WARNING - [control
connection] Error connecting to 127.0.0.1:9042:
Traceback (most recent call last):
File
"/home/drift/cassandra-dtest/venv/src/cassandra-driver/cassandra/cluster.py",
line 3522, in _reconnect_internal
return self._try_connect(host)
File
"/home/drift/cassandra-dtest/venv/src/cassandra-driver/cassandra/cluster.py",
line 3544, in _try_connect
connection = self._cluster.connection_factory(host.endpoint,
is_control_connection=True)
File
"/home/drift/cassandra-dtest/venv/src/cassandra-driver/cassandra/cluster.py",
line 1620, in connection_factory
return self.connection_class.factory(endpoint, self.connect_timeout, *args,
**kwargs)
File
"/home/drift/cassandra-dtest/venv/src/cassandra-driver/cassandra/connection.py",
line 831, in factory
conn = cls(endpoint, *args, **kwargs)
File
"/home/drift/cassandra-dtest/venv/src/cassandra-driver/cassandra/io/asyncorereactor.py",
line 344, in __init__
self._connect_socket()
File
"/home/drift/cassandra-dtest/venv/src/cassandra-driver/cassandra/connection.py",
line 898, in _connect_socket
raise socket.error(sockerr.errno, "Tried connecting to %s. Last error: %s" %
OSError: [Errno None] Tried connecting to [('127.0.0.1', 9042)]. Last error:
timed out
2022-03-23 20:40:12,117 - target-dc1 - cassandra.connection - WARNING -
Heartbeat failed for connection (139909241902704) to 127.0.0.1:9042
2022-03-23 20:40:12,117 - target-dc1 - cassandra.cluster - WARNING - Host
127.0.0.1:9042 has been marked down
2022-03-23 20:40:12,381 - target-dc3 - __main__ - INFO - Got 0/574 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:40:12,594 - target-dc2 - __main__ - INFO - Got 0/574 (0.000000)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:40:17,316 - target-dc1 - __main__ - INFO - Got 7/9 (77.777778)
timeouts/total_rqs in the last 1 minute
2022-03-23 20:40:18,326 - target-dc1 - cassandra.pool - WARNING - Error
attempting to reconnect to 127.0.0.1:9042, scheduling retry in 2.28 seconds:
[Errno None] Tried connecting to [('127.0.0.1', 9042)]. Last error: timed out
2022-03-23 20:40:25,636 - target-dc1 - cassandra.pool - WARNING - Error
attempting to reconnect to 127.0.0.1:9042, scheduling retry in 4.2 seconds:
[Errno None] Tried connecting to [('127.0.0.1', 9042)]. Last error: timed out
2022-03-23 20:40:34,850 - target-dc1 - cassandra.pool - WARNING - Error
attempting to reconnect to 127.0.0.1:9042, scheduling retry in 8.08 seconds:
[Errno None] Tried connecting to [('127.0.0.1', 9042)]. Last error: timed out
2022-03-23 20:40:47,976 - target-dc1 - cassandra.pool - WARNING - Error
attempting to reconnect to 127.0.0.1:9042, scheduling retry in 16.32 seconds:
[Errno None] Tried connecting to [('127.0.0.1', 9042)]. Last error: timed out
{noformat}
Which seems correct?
> Network partition causes write ONE timeouts when using counters in Cassandra 4
> ------------------------------------------------------------------------------
>
> Key: CASSANDRA-17411
> URL: https://issues.apache.org/jira/browse/CASSANDRA-17411
> Project: Cassandra
> Issue Type: Bug
> Components: Consistency/Coordination
> Reporter: Pere Balaguer
> Priority: Normal
> Fix For: 4.0.x
>
> Attachments: app.py
>
>
> h5. Affected versions:
> * 4.x
> h5. Observed behavior:
> When executing CL=ONE writes on a table with a counter column, if one of the
> nodes is network partitioned from the others, clients keep sending requests
> to it.
> Even though this may be a "driver" problem, I've been able to reproduce it
> with both java and python datastax drivers using their latest available
> versions and given the behavior only changes depending on the Cassandra
> version, well, here I am.
> h5. Expected behavior:
> In Cassandra 3 after all inflight requests fail (expected), no new requests
> are sent to the partitioned node. The expectation is that Cassandra 4 behaves
> the same way.
> h5. How to reproduce:
> {noformat}
> # Create a cluster with the desired version, will go with 4.x for this example
> ccm create bug-report -v 4.0.3
> ccm populate -n 2:2:2
> ccm start
> # Create schemas and so on
> CQL=$(cat <<END
> CONSISTENCY ALL;
> DROP KEYSPACE IF EXISTS demo;
> CREATE KEYSPACE demo WITH REPLICATION = {'class': 'NetworkTopologyStrategy',
> 'dc1': 2, 'dc2': 2, 'dc3': 2};
> CREATE TABLE demo.demo (pk uuid PRIMARY KEY, count counter) WITH compaction =
> {'class': 'LeveledCompactionStrategy'};
> END
> )
> ccm node1 cqlsh --verbose --exec="${CQL}"
> # Launch the attached app.py
> # requires cassandra-driver
> python3 app.py "127.0.0.1" "9042"
> # Wait a bit for the app to settle, proceed to next step once you see 3
> messages in stdout like:
> # 2022-03-01 15:41:51,557 - target-dc2 - __main__ - INFO - Got 0/572
> (0.000000) timeouts/total_rqs in the last 1 minute
> # Partition one node with iptables
> iptables -A INPUT -p tcp --destination 127.0.0.1 --destination-port 7000 -j
> DROP; iptables -A INPUT -p tcp --destination 127.0.0.1 --destination-port
> 9042 -j DROP
> {noformat}
> Some time after executing the iptables command in cassandra-3 the output
> should be similar to:
> {noformat}
> 2022-03-01 15:41:51,557 - target-dc2 - __main__ - INFO - Got 0/572 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:41:51,576 - target-dc3 - __main__ - INFO - Got 0/572 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:41:58,032 - target-dc1 - __main__ - INFO - Got 6/252 (2.380952)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:42:51,560 - target-dc2 - __main__ - INFO - Got 0/570 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:42:51,620 - target-dc3 - __main__ - INFO - Got 0/570 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:42:58,101 - target-dc1 - __main__ - INFO - Got 2/354 (0.564972)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:43:51,602 - target-dc2 - __main__ - INFO - Got 0/571 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:43:51,672 - target-dc3 - __main__ - INFO - Got 0/571 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:43:58,153 - target-dc1 - __main__ - INFO - Got 0/572 (0.000000)
> timeouts/total_rqs in the last 1 minute
> {noformat}
> as the timeouts/rqs shows, in about 2 minutes the partitioned node stops
> receiving traffic
> while as in cassandra-4
> {noformat}
> 2022-03-01 15:49:39,068 - target-dc3 - __main__ - INFO - Got 0/566 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:49:39,107 - target-dc2 - __main__ - INFO - Got 0/566 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:49:41,206 - target-dc1 - __main__ - INFO - Got 2/444 (0.450450)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:50:39,095 - target-dc3 - __main__ - INFO - Got 0/569 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:50:39,148 - target-dc2 - __main__ - INFO - Got 0/569 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:50:42,589 - target-dc1 - __main__ - INFO - Got 7/13 (53.846154)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:51:39,125 - target-dc3 - __main__ - INFO - Got 0/567 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:51:39,159 - target-dc2 - __main__ - INFO - Got 0/567 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:51:44,902 - target-dc1 - __main__ - INFO - Got 12/22
> (54.545455) timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:52:39,188 - target-dc2 - __main__ - INFO - Got 0/567 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:52:39,202 - target-dc3 - __main__ - INFO - Got 0/568 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:52:46,994 - target-dc1 - __main__ - INFO - Got 12/20
> (60.000000) timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:53:39,202 - target-dc2 - __main__ - INFO - Got 0/568 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:53:39,238 - target-dc3 - __main__ - INFO - Got 0/568 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:53:48,765 - target-dc1 - __main__ - INFO - Got 12/17
> (70.588235) timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:54:39,203 - target-dc2 - __main__ - INFO - Got 0/568 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:54:39,291 - target-dc3 - __main__ - INFO - Got 0/568 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:54:51,291 - target-dc1 - __main__ - INFO - Got 12/24
> (50.000000) timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:55:39,258 - target-dc2 - __main__ - INFO - Got 0/570 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:55:39,327 - target-dc3 - __main__ - INFO - Got 0/570 (0.000000)
> timeouts/total_rqs in the last 1 minute
> 2022-03-01 15:55:53,365 - target-dc1 - __main__ - INFO - Got 12/20
> (60.000000) timeouts/total_rqs in the last 1 minute
> {noformat}
> as the timeouts/rqs shows, the partitioned node keeps receving traffic until
> the iptables rules are removed
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
