You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Edmond Lau (JIRA)" <ji...@apache.org> on 2009/09/28 23:30:02 UTC
[jira] Created: (CASSANDRA-462) Read repair happens on every quorum
read
Read repair happens on every quorum read
----------------------------------------
Key: CASSANDRA-462
URL: https://issues.apache.org/jira/browse/CASSANDRA-462
Project: Cassandra
Issue Type: Bug
Components: Core
Reporter: Edmond Lau
I have a 3 node cluster with a replication factor of 2, running on 0.4
RC1. I've set both my read and write consistency levels to use a
quorum.
I'm observing that quorum reads keep invoking read repair and log
DigestMismatchExceptions from the StorageProxy. In the absence of any
additional inserts, I'd expect that read repair would happen at most
once before the 2 nodes responsible for the data both have fresh views
of the data.
Here's what I see in my debug log for one machine on two consecutive
quorum reads for the data. I get similar messages when querying any
of the 3 nodes. Similar messages are logged on subsequent queries for
the exact same row/column. The issue happens when reading both
supercolumns or columns. Restarting the cluster has no effect.
DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,317 CassandraServer.java
(line 305) multiget
DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,360 StorageProxy.java
(line 375) strongread reading data for
SliceByNamesReadCommand(table='Analytics', key='test',
columnParent='QueryPath(columnFamilyName='Domain',
superColumnName='null', co\
lumnName='null')', columns=[www.ooyala.com,]) from 17@172.16.130.130:7000
DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,365 StorageProxy.java
(line 382) strongread reading digest for
SliceByNamesReadCommand(table='Analytics', key='test',
columnParent='QueryPath(columnFamilyName='Domain',
superColumnName='null', \
columnName='null')', columns=[www.ooyala.com,]) from 18@172.16.130.131:7000
DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:26:20,380 ReadVerbHandler.java
(line 100) Read key test; sending response to
EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:26:20,387
ResponseVerbHandler.java (line 34) Processing response on a callback
from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:26:20,449
ResponseVerbHandler.java (line 34) Processing response on a callback
from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.131:7000
DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
ReadResponseResolver.java (line 84) Response deserialization time : 0
ms.
DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
ReadResponseResolver.java (line 84) Response deserialization time : 0
ms.
INFO [pool-1-thread-1] 2009-09-26 00:26:20,475 StorageProxy.java
(line 411) DigestMismatchException: test
DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:26:20,477 ReadVerbHandler.java
(line 100) Read key test; sending response to 19@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:26:20,478
ResponseVerbHandler.java (line 34) Processing response on a callback
from 19@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:26:20,480
ResponseVerbHandler.java (line 34) Processing response on a callback
from 19@172.16.130.131:7000
DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
ReadResponseResolver.java (line 84) Response deserialization time : 0
ms.
DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
ReadResponseResolver.java (line 84) Response deserialization time : 0
ms.
INFO [pool-1-thread-1] 2009-09-26 00:26:20,482
ReadResponseResolver.java (line 148) resolve: 1 ms.
DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,099 CassandraServer.java
(line 305) multiget
DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
(line 375) strongread reading data for
SliceByNamesReadCommand(table='Analytics', key='test',
columnParent='QueryPath(columnFamilyName='Domain',
superColumnName='null', co\
lumnName='null')', columns=[www.ooyala.com,]) from 224@172.16.130.130:7000
DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
(line 382) strongread reading digest for
SliceByNamesReadCommand(table='Analytics', key='test',
columnParent='QueryPath(columnFamilyName='Domain',
superColumnName='null', \
columnName='null')', columns=[www.ooyala.com,]) from 225@172.16.130.131:7000
DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:27:22,103 ReadVerbHandler.java
(line 100) Read key test; sending response to
CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:27:22,103
ResponseVerbHandler.java (line 34) Processing response on a callback
from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:27:22,107
ResponseVerbHandler.java (line 34) Processing response on a callback
from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.131:7000
DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
ReadResponseResolver.java (line 84) Response deserialization time : 1
ms.
DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
ReadResponseResolver.java (line 84) Response deserialization time : 0
ms.
INFO [pool-1-thread-2] 2009-09-26 00:27:22,109 StorageProxy.java
(line 411) DigestMismatchException: test
DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:27:22,114 ReadVerbHandler.java
(line 100) Read key test; sending response to 226@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:27:22,114
ResponseVerbHandler.java (line 34) Processing response on a callback
from 226@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:27:22,205
ResponseVerbHandler.java (line 34) Processing response on a callback
from 226@172.16.130.131:7000
DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
ReadResponseResolver.java (line 84) Response deserialization time : 0
ms.
DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
ReadResponseResolver.java (line 84) Response deserialization time : 0
ms.
INFO [pool-1-thread-2] 2009-09-26 00:27:22,207
ReadResponseResolver.java (line 148) resolve: 1 ms.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (CASSANDRA-462) Read repair happens on every quorum
read
Posted by "Jonathan Ellis (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/CASSANDRA-462?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jonathan Ellis updated CASSANDRA-462:
-------------------------------------
Attachment: 462-0-4.patch
version of 03 that applies to 0.4 branch. please test this one if you are using 0.4
> Read repair happens on every quorum read
> ----------------------------------------
>
> Key: CASSANDRA-462
> URL: https://issues.apache.org/jira/browse/CASSANDRA-462
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Affects Versions: 0.4
> Reporter: Edmond Lau
> Assignee: Jonathan Ellis
> Fix For: 0.4
>
> Attachments: 0001-CASSANDRA-462-formatting-cleanup.txt, 0002-logging.txt, 0003-compute-digest-correctly-using-byte-contents-instea.txt, 462-0-4.patch
>
>
> I have a 3 node cluster with a replication factor of 2, running on 0.4
> RC1. I've set both my read and write consistency levels to use a
> quorum.
> I'm observing that quorum reads keep invoking read repair and log
> DigestMismatchExceptions from the StorageProxy. In the absence of any
> additional inserts, I'd expect that read repair would happen at most
> once before the 2 nodes responsible for the data both have fresh views
> of the data.
> Here's what I see in my debug log for one machine on two consecutive
> quorum reads for the data. I get similar messages when querying any
> of the 3 nodes. Similar messages are logged on subsequent queries for
> the exact same row/column. The issue happens when reading both
> supercolumns or columns. Restarting the cluster has no effect.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,317 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,360 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 17@172.16.130.130:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,365 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 18@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:26:20,380 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:26:20,387
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:26:20,449
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,475 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:26:20,477 ReadVerbHandler.java
> (line 100) Read key test; sending response to 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:26:20,478
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:26:20,480
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,482
> ReadResponseResolver.java (line 148) resolve: 1 ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,099 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 224@172.16.130.130:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 225@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:27:22,103 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:27:22,103
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:27:22,107
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 1
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,109 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:27:22,114 ReadVerbHandler.java
> (line 100) Read key test; sending response to 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:27:22,114
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:27:22,205
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,207
> ReadResponseResolver.java (line 148) resolve: 1 ms.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (CASSANDRA-462) Read repair happens on every quorum
read
Posted by "Jonathan Ellis (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/CASSANDRA-462?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jonathan Ellis updated CASSANDRA-462:
-------------------------------------
Attachment: 0003-compute-digest-correctly-using-byte-contents-instea.txt
0002-logging.txt
0001-CASSANDRA-462-formatting-cleanup.txt
> Read repair happens on every quorum read
> ----------------------------------------
>
> Key: CASSANDRA-462
> URL: https://issues.apache.org/jira/browse/CASSANDRA-462
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Reporter: Edmond Lau
> Attachments: 0001-CASSANDRA-462-formatting-cleanup.txt, 0002-logging.txt, 0003-compute-digest-correctly-using-byte-contents-instea.txt
>
>
> I have a 3 node cluster with a replication factor of 2, running on 0.4
> RC1. I've set both my read and write consistency levels to use a
> quorum.
> I'm observing that quorum reads keep invoking read repair and log
> DigestMismatchExceptions from the StorageProxy. In the absence of any
> additional inserts, I'd expect that read repair would happen at most
> once before the 2 nodes responsible for the data both have fresh views
> of the data.
> Here's what I see in my debug log for one machine on two consecutive
> quorum reads for the data. I get similar messages when querying any
> of the 3 nodes. Similar messages are logged on subsequent queries for
> the exact same row/column. The issue happens when reading both
> supercolumns or columns. Restarting the cluster has no effect.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,317 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,360 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 17@172.16.130.130:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,365 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 18@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:26:20,380 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:26:20,387
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:26:20,449
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,475 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:26:20,477 ReadVerbHandler.java
> (line 100) Read key test; sending response to 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:26:20,478
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:26:20,480
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,482
> ReadResponseResolver.java (line 148) resolve: 1 ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,099 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 224@172.16.130.130:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 225@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:27:22,103 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:27:22,103
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:27:22,107
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 1
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,109 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:27:22,114 ReadVerbHandler.java
> (line 100) Read key test; sending response to 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:27:22,114
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:27:22,205
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,207
> ReadResponseResolver.java (line 148) resolve: 1 ms.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (CASSANDRA-462) Read repair happens on every
quorum read
Posted by "Jonathan Ellis (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/CASSANDRA-462?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12760732#action_12760732 ]
Jonathan Ellis commented on CASSANDRA-462:
------------------------------------------
I can reproduce on my test cluster (5 nodes, 3 replicas).
> Read repair happens on every quorum read
> ----------------------------------------
>
> Key: CASSANDRA-462
> URL: https://issues.apache.org/jira/browse/CASSANDRA-462
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Reporter: Edmond Lau
>
> I have a 3 node cluster with a replication factor of 2, running on 0.4
> RC1. I've set both my read and write consistency levels to use a
> quorum.
> I'm observing that quorum reads keep invoking read repair and log
> DigestMismatchExceptions from the StorageProxy. In the absence of any
> additional inserts, I'd expect that read repair would happen at most
> once before the 2 nodes responsible for the data both have fresh views
> of the data.
> Here's what I see in my debug log for one machine on two consecutive
> quorum reads for the data. I get similar messages when querying any
> of the 3 nodes. Similar messages are logged on subsequent queries for
> the exact same row/column. The issue happens when reading both
> supercolumns or columns. Restarting the cluster has no effect.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,317 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,360 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 17@172.16.130.130:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,365 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 18@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:26:20,380 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:26:20,387
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:26:20,449
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,475 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:26:20,477 ReadVerbHandler.java
> (line 100) Read key test; sending response to 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:26:20,478
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:26:20,480
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,482
> ReadResponseResolver.java (line 148) resolve: 1 ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,099 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 224@172.16.130.130:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 225@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:27:22,103 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:27:22,103
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:27:22,107
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 1
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,109 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:27:22,114 ReadVerbHandler.java
> (line 100) Read key test; sending response to 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:27:22,114
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:27:22,205
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,207
> ReadResponseResolver.java (line 148) resolve: 1 ms.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (CASSANDRA-462) Read repair happens on every
quorum read
Posted by "Jonathan Ellis (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/CASSANDRA-462?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12760752#action_12760752 ]
Jonathan Ellis commented on CASSANDRA-462:
------------------------------------------
03
compute digest correctly, using byte[] contents instead of toString. switch to MD5 for non-wtfery.
02
logging
01
formatting + cleanup
> Read repair happens on every quorum read
> ----------------------------------------
>
> Key: CASSANDRA-462
> URL: https://issues.apache.org/jira/browse/CASSANDRA-462
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Reporter: Edmond Lau
> Attachments: 0001-CASSANDRA-462-formatting-cleanup.txt, 0002-logging.txt, 0003-compute-digest-correctly-using-byte-contents-instea.txt
>
>
> I have a 3 node cluster with a replication factor of 2, running on 0.4
> RC1. I've set both my read and write consistency levels to use a
> quorum.
> I'm observing that quorum reads keep invoking read repair and log
> DigestMismatchExceptions from the StorageProxy. In the absence of any
> additional inserts, I'd expect that read repair would happen at most
> once before the 2 nodes responsible for the data both have fresh views
> of the data.
> Here's what I see in my debug log for one machine on two consecutive
> quorum reads for the data. I get similar messages when querying any
> of the 3 nodes. Similar messages are logged on subsequent queries for
> the exact same row/column. The issue happens when reading both
> supercolumns or columns. Restarting the cluster has no effect.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,317 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,360 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 17@172.16.130.130:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,365 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 18@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:26:20,380 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:26:20,387
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:26:20,449
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,475 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:26:20,477 ReadVerbHandler.java
> (line 100) Read key test; sending response to 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:26:20,478
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:26:20,480
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,482
> ReadResponseResolver.java (line 148) resolve: 1 ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,099 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 224@172.16.130.130:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 225@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:27:22,103 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:27:22,103
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:27:22,107
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 1
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,109 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:27:22,114 ReadVerbHandler.java
> (line 100) Read key test; sending response to 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:27:22,114
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:27:22,205
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,207
> ReadResponseResolver.java (line 148) resolve: 1 ms.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (CASSANDRA-462) Read repair happens on every
quorum read
Posted by "Jonathan Ellis (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/CASSANDRA-462?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12760394#action_12760394 ]
Jonathan Ellis commented on CASSANDRA-462:
------------------------------------------
Do you see the same behavior when you run w/ replication factor of 3? (Wiping out your data and commitlog & restarting is the easiest way to change replication atm.) I know there is at least one group testing 3 nodes / replication 3.
> Read repair happens on every quorum read
> ----------------------------------------
>
> Key: CASSANDRA-462
> URL: https://issues.apache.org/jira/browse/CASSANDRA-462
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Reporter: Edmond Lau
>
> I have a 3 node cluster with a replication factor of 2, running on 0.4
> RC1. I've set both my read and write consistency levels to use a
> quorum.
> I'm observing that quorum reads keep invoking read repair and log
> DigestMismatchExceptions from the StorageProxy. In the absence of any
> additional inserts, I'd expect that read repair would happen at most
> once before the 2 nodes responsible for the data both have fresh views
> of the data.
> Here's what I see in my debug log for one machine on two consecutive
> quorum reads for the data. I get similar messages when querying any
> of the 3 nodes. Similar messages are logged on subsequent queries for
> the exact same row/column. The issue happens when reading both
> supercolumns or columns. Restarting the cluster has no effect.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,317 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,360 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 17@172.16.130.130:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,365 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 18@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:26:20,380 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:26:20,387
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:26:20,449
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,475 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:26:20,477 ReadVerbHandler.java
> (line 100) Read key test; sending response to 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:26:20,478
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:26:20,480
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,482
> ReadResponseResolver.java (line 148) resolve: 1 ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,099 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 224@172.16.130.130:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 225@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:27:22,103 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:27:22,103
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:27:22,107
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 1
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,109 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:27:22,114 ReadVerbHandler.java
> (line 100) Read key test; sending response to 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:27:22,114
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:27:22,205
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,207
> ReadResponseResolver.java (line 148) resolve: 1 ms.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (CASSANDRA-462) Read repair happens on every
quorum read
Posted by "Edmond Lau (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/CASSANDRA-462?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12760415#action_12760415 ]
Edmond Lau commented on CASSANDRA-462:
--------------------------------------
The same behavior happens on repeated reads w/ a replication factor of 3:
DEBUG [pool-1-thread-10] 2009-09-28 22:13:02,058 CassandraServer.java (line 305) multiget
DEBUG [pool-1-thread-10] 2009-09-28 22:13:02,059 StorageProxy.java (line 375) strongread reading data for SliceByNamesReadCommand(table='Analytics', key='00NGRxOjiHjQzlRIts5DqWugci8H2uQU', columnParent='QueryPath(columnFamilyN\
ame='timestamp', superColumnName='[B@1ec278b5', columnName='null')', columns=[country:US,]) from 837@172.16.130.130:7000
DEBUG [pool-1-thread-10] 2009-09-28 22:13:02,059 StorageProxy.java (line 382) strongread reading digest for SliceByNamesReadCommand(table='Analytics', key='00NGRxOjiHjQzlRIts5DqWugci8H2uQU', columnParent='QueryPath(columnFamil\
yName='timestamp', superColumnName='[B@1ec278b5', columnName='null')', columns=[country:US,]) from 838@172.16.130.131:7000
DEBUG [pool-1-thread-10] 2009-09-28 22:13:02,059 StorageProxy.java (line 382) strongread reading digest for SliceByNamesReadCommand(table='Analytics', key='00NGRxOjiHjQzlRIts5DqWugci8H2uQU', columnParent='QueryPath(columnFamil\
yName='timestamp', superColumnName='[B@1ec278b5', columnName='null')', columns=[country:US,]) from 838@172.16.130.129:7000
DEBUG [ROW-READ-STAGE:7] 2009-09-28 22:13:02,061 ReadVerbHandler.java (line 100) Read key 00NGRxOjiHjQzlRIts5DqWugci8H2uQU; sending response to 48325865-7324-FA54-7789-7ABAD95244B8@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:2] 2009-09-28 22:13:02,061 ResponseVerbHandler.java (line 34) Processing response on a callback from 48325865-7324-FA54-7789-7ABAD95244B8@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:4] 2009-09-28 22:13:02,063 ResponseVerbHandler.java (line 34) Processing response on a callback from 48325865-7324-FA54-7789-7ABAD95244B8@172.16.130.131:7000
DEBUG [pool-1-thread-10] 2009-09-28 22:13:02,063 ReadResponseResolver.java (line 84) Response deserialization time : 0 ms.
DEBUG [pool-1-thread-10] 2009-09-28 22:13:02,063 ReadResponseResolver.java (line 84) Response deserialization time : 0 ms.
INFO [pool-1-thread-10] 2009-09-28 22:13:02,063 StorageProxy.java (line 411) DigestMismatchException: 00NGRxOjiHjQzlRIts5DqWugci8H2uQU
DEBUG [ROW-READ-STAGE:8] 2009-09-28 22:13:02,065 ReadVerbHandler.java (line 100) Read key 00NGRxOjiHjQzlRIts5DqWugci8H2uQU; sending response to 839@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:1] 2009-09-28 22:13:02,065 ResponseVerbHandler.java (line 34) Processing response on a callback from 839@172.16.130.130:7000
DEBUG [RESPONSE-STAGE:3] 2009-09-28 22:13:02,066 ResponseVerbHandler.java (line 34) Processing response on a callback from 839@172.16.130.129:7000
DEBUG [RESPONSE-STAGE:3] 2009-09-28 22:13:02,066 ResponseVerbHandler.java (line 34) Processing response on a callback from 839@172.16.130.131:7000
DEBUG [pool-1-thread-10] 2009-09-28 22:13:02,067 ReadResponseResolver.java (line 84) Response deserialization time : 0 ms.
DEBUG [pool-1-thread-10] 2009-09-28 22:13:02,067 ReadResponseResolver.java (line 84) Response deserialization time : 0 ms.
INFO [pool-1-thread-10] 2009-09-28 22:13:02,067 ReadResponseResolver.java (line 148) resolve: 0 ms.
> Read repair happens on every quorum read
> ----------------------------------------
>
> Key: CASSANDRA-462
> URL: https://issues.apache.org/jira/browse/CASSANDRA-462
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Reporter: Edmond Lau
>
> I have a 3 node cluster with a replication factor of 2, running on 0.4
> RC1. I've set both my read and write consistency levels to use a
> quorum.
> I'm observing that quorum reads keep invoking read repair and log
> DigestMismatchExceptions from the StorageProxy. In the absence of any
> additional inserts, I'd expect that read repair would happen at most
> once before the 2 nodes responsible for the data both have fresh views
> of the data.
> Here's what I see in my debug log for one machine on two consecutive
> quorum reads for the data. I get similar messages when querying any
> of the 3 nodes. Similar messages are logged on subsequent queries for
> the exact same row/column. The issue happens when reading both
> supercolumns or columns. Restarting the cluster has no effect.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,317 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,360 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 17@172.16.130.130:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,365 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 18@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:26:20,380 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:26:20,387
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:26:20,449
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,475 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:26:20,477 ReadVerbHandler.java
> (line 100) Read key test; sending response to 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:26:20,478
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:26:20,480
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,482
> ReadResponseResolver.java (line 148) resolve: 1 ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,099 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 224@172.16.130.130:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 225@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:27:22,103 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:27:22,103
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:27:22,107
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 1
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,109 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:27:22,114 ReadVerbHandler.java
> (line 100) Read key test; sending response to 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:27:22,114
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:27:22,205
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,207
> ReadResponseResolver.java (line 148) resolve: 1 ms.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (CASSANDRA-462) Read repair happens on every
quorum read
Posted by "Hudson (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/CASSANDRA-462?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12761195#action_12761195 ]
Hudson commented on CASSANDRA-462:
----------------------------------
Integrated in Cassandra #214 (See [http://hudson.zones.apache.org/hudson/job/Cassandra/214/])
logging for digests. patch by jbellis for
formatting + cleanup. patch by jbellis for
> Read repair happens on every quorum read
> ----------------------------------------
>
> Key: CASSANDRA-462
> URL: https://issues.apache.org/jira/browse/CASSANDRA-462
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Affects Versions: 0.4
> Reporter: Edmond Lau
> Assignee: Jonathan Ellis
> Fix For: 0.4
>
> Attachments: 0001-CASSANDRA-462-formatting-cleanup.txt, 0002-logging.txt, 0003-compute-digest-correctly-using-byte-contents-instea.txt, 462-0-4.patch
>
>
> I have a 3 node cluster with a replication factor of 2, running on 0.4
> RC1. I've set both my read and write consistency levels to use a
> quorum.
> I'm observing that quorum reads keep invoking read repair and log
> DigestMismatchExceptions from the StorageProxy. In the absence of any
> additional inserts, I'd expect that read repair would happen at most
> once before the 2 nodes responsible for the data both have fresh views
> of the data.
> Here's what I see in my debug log for one machine on two consecutive
> quorum reads for the data. I get similar messages when querying any
> of the 3 nodes. Similar messages are logged on subsequent queries for
> the exact same row/column. The issue happens when reading both
> supercolumns or columns. Restarting the cluster has no effect.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,317 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,360 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 17@172.16.130.130:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,365 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 18@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:26:20,380 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:26:20,387
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:26:20,449
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from EEF5BCFF-D592-F1DE-6DEE-B74029218A29@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,474
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,475 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:26:20,477 ReadVerbHandler.java
> (line 100) Read key test; sending response to 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:26:20,478
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:26:20,480
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 19@172.16.130.131:7000
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-1] 2009-09-26 00:26:20,481
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-1] 2009-09-26 00:26:20,482
> ReadResponseResolver.java (line 148) resolve: 1 ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,099 CassandraServer.java
> (line 305) multiget
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 375) strongread reading data for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', co\
> lumnName='null')', columns=[www.ooyala.com,]) from 224@172.16.130.130:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,100 StorageProxy.java
> (line 382) strongread reading digest for
> SliceByNamesReadCommand(table='Analytics', key='test',
> columnParent='QueryPath(columnFamilyName='Domain',
> superColumnName='null', \
> columnName='null')', columns=[www.ooyala.com,]) from 225@172.16.130.131:7000
> DEBUG [ROW-READ-STAGE:1] 2009-09-26 00:27:22,103 ReadVerbHandler.java
> (line 100) Read key test; sending response to
> CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:1] 2009-09-26 00:27:22,103
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:2] 2009-09-26 00:27:22,107
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from CD1A7545-F759-1CA7-4D17-87FA4A16E2E4@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 1
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,108
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,109 StorageProxy.java
> (line 411) DigestMismatchException: test
> DEBUG [ROW-READ-STAGE:2] 2009-09-26 00:27:22,114 ReadVerbHandler.java
> (line 100) Read key test; sending response to 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:3] 2009-09-26 00:27:22,114
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.130:7000
> DEBUG [RESPONSE-STAGE:4] 2009-09-26 00:27:22,205
> ResponseVerbHandler.java (line 34) Processing response on a callback
> from 226@172.16.130.131:7000
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> DEBUG [pool-1-thread-2] 2009-09-26 00:27:22,206
> ReadResponseResolver.java (line 84) Response deserialization time : 0
> ms.
> INFO [pool-1-thread-2] 2009-09-26 00:27:22,207
> ReadResponseResolver.java (line 148) resolve: 1 ms.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.