Hi First I delete one column, then I delete one row. Then try to read all columns from the same row, all operations from same client app.
The consistency level is read/write quorum. Check the Cassandra log, the local node don't perform the delete operation but send the mutation to other nodes (192.168.0.6, 192.168.0.1) After delete, I try to read all columns from the row, I found the node found "Digest mismatch" due to Quorum consistency configuration, but the result is not correct. From the log, I can see the delete mutation already accepted by 192.168.0.6, 192.168.0.1, but when 192.168.0.5 read response from 0.6 and 0.1, and then it merge the data, but finally 0.5 shows the result which is the dirty data. Following logs shows the change of column "737461747573" , 192.168.0.5 try to read from 0.1 and 0.6, it should be deleted, but finally it shows it has the data. log: 192.168.0.5 DEBUG [Thrift:17] 2012-06-28 15:59:42,198 StorageProxy.java (line 653) Command/ConsistencyLevel is SliceByNamesReadCommand(table='drc', key=7878323239537570657254616e67307878, columnParent='QueryPath(columnFamilyName='queue', superColumnName='null', columnName='null')', columns=[6578656375746554696d65,6669726554696d65,67726f75705f6964,696e517565756554696d65,6c6f67526f6f744964,6d6f54797065,706172746974696f6e,7265636569766554696d65,72657175657374,7265747279,7365727669636550726f7669646572, 737461747573,757365724e616d65,])/QUORUM DEBUG [Thrift:17] 2012-06-28 15:59:42,198 ReadCallback.java (line 79) Blockfor is 2; setting up requests to /192.168.0.6,/192.168.0.1 DEBUG [Thrift:17] 2012-06-28 15:59:42,198 StorageProxy.java (line 674) reading data from /192.168.0.6 DEBUG [Thrift:17] 2012-06-28 15:59:42,198 StorageProxy.java (line 694) reading digest from /192.168.0.1 DEBUG [RequestResponseStage:2] 2012-06-28 15:59:42,199 ResponseVerbHandler.java (line 44) Processing response on a callback from 6556@/192.168.0.6 DEBUG [RequestResponseStage:2] 2012-06-28 15:59:42,199 AbstractRowResolver.java (line 66) Preprocessed data response DEBUG [RequestResponseStage:6] 2012-06-28 15:59:42,199 ResponseVerbHandler.java (line 44) Processing response on a callback from 6557@/192.168.0.1 DEBUG [RequestResponseStage:6] 2012-06-28 15:59:42,199 AbstractRowResolver.java (line 66) Preprocessed digest response DEBUG [Thrift:17] 2012-06-28 15:59:42,199 RowDigestResolver.java (line 65) resolving 2 responses DEBUG [Thrift:17] 2012-06-28 15:59:42,200 StorageProxy.java (line 733) Digest mismatch: org.apache.cassandra.service.DigestMismatchException: Mismatch for key DecoratedKey(100572974179274741747356988451225858264, 7878323239537570657254616e67307878) (b725ab25696111be49aaa7c4b7afa52d vs d41d8cd98f00b204e9800998ecf8427e) DEBUG [RequestResponseStage:9] 2012-06-28 15:59:42,201 ResponseVerbHandler.java (line 44) Processing response on a callback from 6558@/192.168.0.6 DEBUG [RequestResponseStage:7] 2012-06-28 15:59:42,201 ResponseVerbHandler.java (line 44) Processing response on a callback from 6559@/192.168.0.1 DEBUG [RequestResponseStage:9] 2012-06-28 15:59:42,201 AbstractRowResolver.java (line 66) Preprocessed data response DEBUG [RequestResponseStage:7] 2012-06-28 15:59:42,201 AbstractRowResolver.java (line 66) Preprocessed data response DEBUG [Thrift:17] 2012-06-28 15:59:42,201 RowRepairResolver.java (line 63) resolving 2 responses DEBUG [Thrift:17] 2012-06-28 15:59:42,201 SliceQueryFilter.java (line 123) collecting 0 of 2147483647: 6669726554696d65:false:13@1340870382109004 DEBUG [Thrift:17] 2012-06-28 15:59:42,201 SliceQueryFilter.java (line 123) collecting 1 of 2147483647: 67726f75705f6964:false:10@1340870382109014 DEBUG [Thrift:17] 2012-06-28 15:59:42,201 SliceQueryFilter.java (line 123) collecting 2 of 2147483647: 696e517565756554696d65:false:13@1340870382109005 DEBUG [Thrift:17] 2012-06-28 15:59:42,201 SliceQueryFilter.java (line 123) collecting 3 of 2147483647: 6c6f67526f6f744964:false:7@1340870382109015 DEBUG [Thrift:17] 2012-06-28 15:59:42,202 SliceQueryFilter.java (line 123) collecting 4 of 2147483647: 6d6f54797065:false:6@1340870382109009 DEBUG [Thrift:17] 2012-06-28 15:59:42,202 SliceQueryFilter.java (line 123) collecting 5 of 2147483647: 706172746974696f6e:false:2@1340870382109001 DEBUG [Thrift:17] 2012-06-28 15:59:42,202 SliceQueryFilter.java (line 123) collecting 6 of 2147483647: 7265636569766554696d65:false:13@1340870382109003 DEBUG [Thrift:17] 2012-06-28 15:59:42,202 SliceQueryFilter.java (line 123) collecting 7 of 2147483647: 72657175657374:false:300@1340870382109013 DEBUG [RequestResponseStage:5] 2012-06-28 15:59:42,202 ResponseVerbHandler.java (line 44) Processing response on a callback from 6552@/192.168.0.1 DEBUG [Thrift:17] 2012-06-28 15:59:42,202 SliceQueryFilter.java (line 123) collecting 8 of 2147483647: 7265747279:false:1@1340870382109006 DEBUG [Thrift:17] 2012-06-28 15:59:42,202 SliceQueryFilter.java (line 123) collecting 9 of 2147483647: 7365727669636550726f7669646572:false:4@1340870382109007 DEBUG [Thrift:17] 2012-06-28 15:59:42,203 SliceQueryFilter.java (line 123) collecting 10 of 2147483647: 737461747573:false:8@1340870382152000 DEBUG [Thrift:17] 2012-06-28 15:59:42,203 SliceQueryFilter.java (line 123) collecting 11 of 2147483647: 757365724e616d65:false:4@1340870382109000 DEBUG [Thrift:17] 2012-06-28 15:59:42,203 RowRepairResolver.java (line 89) versions merged DEBUG [Thrift:17] 2012-06-28 15:59:42,203 RowRepairResolver.java (line 102) resolve: 2 ms. DEBUG [Thrift:18] 2012-06-28 15:59:42,204 ClientState.java (line 123) logged in: #<User casadm groups=[]> DEBUG [Thrift:18] 2012-06-28 15:59:42,204 CassandraServer.java (line 305) get_slice 192.168.0.1: DEBUG [MutationStage:21] 2012-06-28 15:59:42,177 RowMutationVerbHandler.java (line 44) Applying RowMutation(keyspace='drc', key='7878323239537570657254616e67307878', modifications=[ColumnFamily(queue [737461747573:true:4@1340870382175000,])]) DEBUG [MutationStage:21] 2012-06-28 15:59:42,178 Table.java (line 391) applying mutation of row 7878323239537570657254616e67307878 DEBUG [MutationStage:23] 2012-06-28 15:59:42,187 RowMutationVerbHandler.java (line 44) Applying RowMutation(keyspace='drc', key='7878323239537570657254616e67307878', modifications=[ColumnFamily(queue -deleted at 1340870382185000- [])]) DEBUG [MutationStage:23] 2012-06-28 15:59:42,187 Table.java (line 391) applying mutation of row 7878323239537570657254616e67307878 DEBUG [MutationStage:20] 2012-06-28 15:59:42,189 Table.java (line 425) mutating indexed column 737461747573 value 4445515545554544 DEBUG [MutationStage:20] 2012-06-28 15:59:42,189 CollationController.java (line 77) collectTimeOrderedData DEBUG [MutationStage:20] 2012-06-28 15:59:42,190 Table.java (line 449) Pre-mutation index row is ColumnFamily(queue [737461747573 :false:8@1340870382152000,]) DEBUG [MutationStage:20] 2012-06-28 15:59:42,190 Table.java (line 500) skipping index update for obsolete mutation of 737461747573 DEBUG [ReadStage:5] 2012-06-28 15:59:42,199 CollationController.java (line 77) collectTimeOrderedData DEBUG [ReadStage:5] 2012-06-28 15:59:42,199 ReadVerbHandler.java (line 73) digest is b725ab25696111be49aaa7c4b7afa52d DEBUG [ReadStage:5] 2012-06-28 15:59:42,199 ReadVerbHandler.java (line 58) Read key 7878323239537570657254616e67307878; sending response to 6557@/ 192.168.0.3 DEBUG [ReadStage:6] 2012-06-28 15:59:42,200 CollationController.java (line 77) collectTimeOrderedData DEBUG [ReadStage:6] 2012-06-28 15:59:42,201 ReadVerbHandler.java (line 58) Read key 7878323239537570657254616e67307878; sending response to 6559@/ 192.168.0.3 DEBUG [MutationStage:23] 2012-06-28 15:59:42,201 Table.java (line 425) mutating indexed column 6669726554696d65 value null DEBUG [MutationStage:21] 2012-06-28 15:59:42,201 Table.java (line 425) mutating indexed column 737461747573 value 4fec0eee DEBUG [MutationStage:23] 2012-06-28 15:59:42,201 Table.java (line 425) mutating indexed column 6669726554696d65536c696365 value null DEBUG [MutationStage:21] 2012-06-28 15:59:42,201 CollationController.java (line 77) collectTimeOrderedData DEBUG [MutationStage:23] 2012-06-28 15:59:42,202 Table.java (line 425) mutating indexed column 696e517565756554696d65 value null DEBUG [MutationStage:21] 2012-06-28 15:59:42,202 Table.java (line 449) Pre-mutation index row is ColumnFamily(queue [737461747573 :false:8@1340870382152000,]) DEBUG [MutationStage:23] 2012-06-28 15:59:42,202 Table.java (line 425) mutating indexed column 696e517565756554696d65536c696365 value null DEBUG [MutationStage:23] 2012-06-28 15:59:42,202 Table.java (line 425) mutating indexed column 6d6f54797065 value null DEBUG [MutationStage:21] 2012-06-28 15:59:42,202 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(DEQUEUED, 4445515545554544):ColumnFamily(queue.idxStatus [7878323239537570657254616e67307878:true:4@1340870382152000,]) DEBUG [MutationStage:23] 2012-06-28 15:59:42,202 Table.java (line 425) mutating indexed column 706172746974696f6e value null DEBUG [MutationStage:21] 2012-06-28 15:59:42,202 RowMutationVerbHandler.java (line 56) RowMutation(keyspace='drc', key='7878323239537570657254616e67307878', modifications=[ColumnFamily(queue [737461747573:true:4@1340870382175000,])]) applied. Sending response to 6552@/192.168.0.3 192.168.0.6: DEBUG [MutationStage:6] 2012-06-28 15:59:42,177 RowMutationVerbHandler.java (line 44) Applying RowMutation(keyspace='drc', key='7878323239537570657254616e67307878', modifications=[ColumnFamily(queue [737461747573:true:4@1340870382175000,])]) DEBUG [MutationStage:6] 2012-06-28 15:59:42,177 Table.java (line 391) applying mutation of row 7878323239537570657254616e67307878 DEBUG [MutationStage:6] 2012-06-28 15:59:42,184 Table.java (line 425) mutating indexed column 737461747573 value 4fec0eee DEBUG [MutationStage:6] 2012-06-28 15:59:42,184 CollationController.java (line 77) collectTimeOrderedData DEBUG [MutationStage:6] 2012-06-28 15:59:42,184 Table.java (line 449) Pre-mutation index row is ColumnFamily(queue [737461747573 :false:8@1340870382152000,]) DEBUG [MutationStage:6] 2012-06-28 15:59:42,184 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(DEQUEUED, 4445515545554544):ColumnFamily(queue.idxStatus [7878323239537570657254616e67307878:true:4@1340870382152000,]) DEBUG [MutationStage:6] 2012-06-28 15:59:42,184 RowMutationVerbHandler.java (line 56) RowMutation(keyspace='drc', key='7878323239537570657254616e67307878', modifications=[ColumnFamily(queue [737461747573:true:4@1340870382175000,])]) applied. Sending response to 6550@/192.168.0.3 DEBUG [MutationStage:10] 2012-06-28 15:59:42,187 RowMutationVerbHandler.java (line 44) Applying RowMutation(keyspace='drc', key='7878323239537570657254616e67307878', modifications=[ColumnFamily(queue -deleted at 1340870382185000- [])]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,187 Table.java (line 391) applying mutation of row 7878323239537570657254616e67307878 DEBUG [MutationStage:10] 2012-06-28 15:59:42,190 Table.java (line 425) mutating indexed column 6669726554696d65 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,190 Table.java (line 425) mutating indexed column 6669726554696d65536c696365 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,190 Table.java (line 425) mutating indexed column 696e517565756554696d65 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,190 Table.java (line 425) mutating indexed column 696e517565756554696d65536c696365 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,190 Table.java (line 425) mutating indexed column 6d6f54797065 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,190 Table.java (line 425) mutating indexed column 706172746974696f6e value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,190 Table.java (line 425) mutating indexed column 7265636569766554696d65 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,190 Table.java (line 425) mutating indexed column 7265636569766554696d65536c696365 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,191 Table.java (line 425) mutating indexed column 7365727669636550726f7669646572 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,191 Table.java (line 425) mutating indexed column 737461747573 value null DEBUG [MutationStage:10] 2012-06-28 15:59:42,191 CollationController.java (line 77) collectTimeOrderedData DEBUG [MutationStage:10] 2012-06-28 15:59:42,191 Table.java (line 449) Pre-mutation index row is ColumnFamily(queue [6669726554696d65:false:13@1340870382109004 ,6669726554696d65536c696365:false:13@1340870382109011 ,696e517565756554696d65:false:13@1340870382109005 ,696e517565756554696d65536c696365:false:13@1340870382109012 ,6d6f54797065:false:6@1340870382109009 ,706172746974696f6e:false:2@1340870382109001 ,7265636569766554696d65:false:13@1340870382109003 ,7265636569766554696d65536c696365:false:13@1340870382109010 ,7365727669636550726f7669646572:false:4@1340870382109007,737461747573 :true:4@1340870382175000,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,191 Table.java (line 500) skipping index update for obsolete mutation of 737461747573 DEBUG [MutationStage:10] 2012-06-28 15:59:42,191 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(3898026790553046681950927403065, 31333430383730333531373839):ColumnFamily(queue.idxFireTime [7878323239537570657254616e67307878:true:4@1340870382109004,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,192 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(3898026790552830793920833138736, 31333430383431363030303030):ColumnFamily(queue.idxFireTimeRange [7878323239537570657254616e67307878:true:4@1340870382109011,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,192 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(3898026790553046681950927403065, 31333430383730333531373839):ColumnFamily(queue.idxInQueueTime [7878323239537570657254616e67307878:true:4@1340870382109005,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,192 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(3898026790552830793920833138736, 31333430383431363030303030):ColumnFamily(queue.idxInQueueTimeRange [7878323239537570657254616e67307878:true:4@1340870382109012,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,192 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(TestMo, 546573744d6f):ColumnFamily(queue.idxMoType [7878323239537570657254616e67307878:true:4@1340870382109009,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,193 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(32, 3332):ColumnFamily(queue.idxPartitionId [7878323239537570657254616e67307878:true:4@1340870382109001,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,193 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(3898026790553046681950927403065, 31333430383730333531373839):ColumnFamily(queue.idxRecvTime [7878323239537570657254616e67307878:true:4@1340870382109003,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,193 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(3898026790552830793920833138736, 31333430383431363030303030):ColumnFamily(queue.idxRecvTimeRange [7878323239537570657254616e67307878:true:4@1340870382109010,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,193 KeysIndex.java (line 103) removed index entry for cleaned-up value DecoratedKey(test, 74657374):ColumnFamily(queue.idxServiceProvider [7878323239537570657254616e67307878:true:4@1340870382109007,]) DEBUG [MutationStage:10] 2012-06-28 15:59:42,193 RowMutationVerbHandler.java (line 56) RowMutation(keyspace='drc', key='7878323239537570657254616e67307878', modifications=[ColumnFamily(queue -deleted at 1340870382185000- [])]) applied. Sending response to 6553@/ 192.168.0.3 DEBUG [ReadStage:17] 2012-06-28 15:59:42,198 CollationController.java (line 77) collectTimeOrderedData DEBUG [ReadStage:17] 2012-06-28 15:59:42,199 ReadVerbHandler.java (line 58) Read key 7878323239537570657254616e67307878; sending response to 6556@/ 192.168.0.3 BRs //Ares
