Cassandraコンシステンシログ分析


詳細
次のCassandraの一貫性についての議論に続きます.
Cassandraコンシステンシの問題とクライアントソリューション
 
Cassandraのソースコードにいくつかのログを追加することで、今日は問題の根本的な原因を見つけたはずです.計3台の機械10.130.24.90,10.130.3.2.91,10.130.224.91,10.130.2.4143
問題原因分析:
ログはリクエストの前後順に切り取られます.テーブルのプライマリ・キーは(empID,deptID)
ログ1:
要求は91マシンに送信され、first_の挿入が要求される.nameはeran 10003のデータで、タイムスタンプが1392953766795000でfirst_が取られているのが見えますnameはeran 10003
DEBUG [Thrift:22] 2014-02-21 11:36:06,795 CassandraServer.java (line 1916) execute_cql3_query:[INSERT INTO employees (empID, deptID, first_name, last_name) VALUES (111, 222, 'eran10003', 'landau');] with clever:QUORUM
TRACE [Thrift:22] 2014-02-21 11:36:06,795 QueryProcessor.java (line 97) Process org.apache.cassandra.cql3.statements.UpdateStatement@1342464f @CL.QUORUM
 INFO [Thrift:22] 2014-02-21 11:36:06,795 StorageProxy.java (line 801) destination:/10.130.24.90
 INFO [Thrift:22] 2014-02-21 11:36:06,795 StorageProxy.java (line 822) insert to different server
 INFO [Thrift:22] 2014-02-21 11:36:06,796 StorageProxy.java (line 831) direct writes to local DC
TRACE [Thrift:22] 2014-02-21 11:36:06,796 MessagingService.java (line 615) /10.130.24.91 sending MUTATION to 29474@/10.130.24.90
 INFO [Thrift:22] 2014-02-21 11:36:06,796 StorageProxy.java (line 801) destination:/10.130.24.143
 INFO [Thrift:22] 2014-02-21 11:36:06,796 StorageProxy.java (line 822) insert to different server
 INFO [Thrift:22] 2014-02-21 11:36:06,796 StorageProxy.java (line 831) direct writes to local DC
TRACE [Thrift:22] 2014-02-21 11:36:06,796 MessagingService.java (line 615) /10.130.24.91 sending MUTATION to 29475@/10.130.24.143
 INFO [Thrift:22] 2014-02-21 11:36:06,796 StorageProxy.java (line 801) destination:/10.130.24.91
 INFO [Thrift:22] 2014-02-21 11:36:06,797 StorageProxy.java (line 817) insertLocal
DEBUG [MutationStage:112] 2014-02-21 11:36:06,797 Keyspace.java (line 351) RowMutation:RowMutation(keyspace='contactks', key='0000006f', modifications=[java.nio.HeapByteBuffer[pos=0 lim=10 cap=12]: timestamp:1392953766795000,java.nio.HeapByteBuffer[pos=0 lim=20 cap=38]:eran10003 timestamp:1392953766795000,java.nio.HeapByteBuffer[pos=0 lim=19 cap=36]:landau timestamp:1392953766795000,])
DEBUG [MutationStage:112] 2014-02-21 11:36:06,797 Keyspace.java (line 359) Appending to commitlog
DEBUG [MutationStage:112] 2014-02-21 11:36:06,797 Keyspace.java (line 375) Adding to employees memtable
DEBUG [Thread-3] 2014-02-21 11:36:06,798 MessagingService.java (line 697) Message received from /10.130.24.90, id :29474
DEBUG [RequestResponseStage:312] 2014-02-21 11:36:06,798 MessageDeliveryTask.java (line 61) doVerb:REQUEST_RESPONSE
DEBUG [Thrift:22] 2014-02-21 11:36:06,798 Tracing.java (line 157) request complete 

  
ログ2:
要求は90マシンに送信され、first_の挿入が要求される.nameはeran 10004のデータで、タイムスタンプが1392953753016000でfirst_が取られているのが見えますnameはまだeran 10003
DEBUG [Thrift:16] 2014-02-21 11:35:53,016 org.apache.cassandra.thrift.CassandraServer (line 1916) execute_cql3_query:[INSERT INTO employees (empID, deptID, first_name, last_name) VALUES (111, 222, 'eran10004', 'landau');] with clever:QUORUM
TRACE [Thrift:16] 2014-02-21 11:35:53,016 org.apache.cassandra.cql3.QueryProcessor (line 97) Process org.apache.cassandra.cql3.statements.UpdateStatement@6372d3ed @CL.QUORUM
 INFO [Thrift:16] 2014-02-21 11:35:53,016 org.apache.cassandra.service.StorageProxy (line 801) destination:/10.130.24.90
 INFO [Thrift:16] 2014-02-21 11:35:53,016 org.apache.cassandra.service.StorageProxy (line 817) insertLocal
 INFO [Thrift:16] 2014-02-21 11:35:53,017 org.apache.cassandra.service.StorageProxy (line 801) destination:/10.130.24.143
 INFO [Thrift:16] 2014-02-21 11:35:53,017 org.apache.cassandra.service.StorageProxy (line 822) insert to different server
 INFO [Thrift:16] 2014-02-21 11:35:53,017 org.apache.cassandra.service.StorageProxy (line 831) direct writes to local DC
TRACE [Thrift:16] 2014-02-21 11:35:53,017 org.apache.cassandra.net.MessagingService (line 615) /10.130.24.90 sending MUTATION to 28704@/10.130.24.143
 INFO [Thrift:16] 2014-02-21 11:35:53,017 org.apache.cassandra.service.StorageProxy (line 801) destination:/10.130.24.91
 INFO [Thrift:16] 2014-02-21 11:35:53,018 org.apache.cassandra.service.StorageProxy (line 822) insert to different server
 INFO [Thrift:16] 2014-02-21 11:35:53,018 org.apache.cassandra.service.StorageProxy (line 831) direct writes to local DC
TRACE [Thrift:16] 2014-02-21 11:35:53,018 org.apache.cassandra.net.MessagingService (line 615) /10.130.24.90 sending MUTATION to 28705@/10.130.24.91
DEBUG [MutationStage:117] 2014-02-21 11:35:53,017 org.apache.cassandra.db.Keyspace (line 351) RowMutation:RowMutation(keyspace='contactks', key='0000006f', modifications=[java.nio.HeapByteBuffer[pos=0 lim=10 cap=12]: timestamp:1392953753016000,java.nio.HeapByteBuffer[pos=0 lim=20 cap=38]:eran10004 timestamp:1392953753016000,java.nio.HeapByteBuffer[pos=0 lim=19 cap=36]:landau timestamp:1392953753016000,])
DEBUG [MutationStage:117] 2014-02-21 11:35:53,018 org.apache.cassandra.db.Keyspace (line 359) Appending to commitlog
DEBUG [MutationStage:117] 2014-02-21 11:35:53,019 org.apache.cassandra.db.Keyspace (line 375) Adding to employees memtable
DEBUG [Thread-8] 2014-02-21 11:35:53,020 org.apache.cassandra.net.MessagingService (line 697) Message received from /10.130.24.91, id :28705
DEBUG [Thread-10] 2014-02-21 11:35:53,020 org.apache.cassandra.net.MessagingService (line 697) Message received from /10.130.24.143, id :28704
DEBUG [RequestResponseStage:82] 2014-02-21 11:35:53,021 org.apache.cassandra.net.MessageDeliveryTask (line 61) doVerb:REQUEST_RESPONSE
DEBUG [RequestResponseStage:83] 2014-02-21 11:35:53,021 org.apache.cassandra.net.MessageDeliveryTask (line 61) doVerb:REQUEST_RESPONSE
DEBUG [Thrift:16] 2014-02-21 11:35:53,021 org.apache.cassandra.tracing.Tracing (line 157) request complete

 
上記の結果を見ると、新しく挿入されたデータ:eran 10004は、取得に成功しなかったが、要求は確かにサーバに送信され、実行されていることが分かった.いったい何が原因なのか.Cassandraデータストレージの特徴を熟知しているのは、Cassandraの各列がバージョン別に格納されていることを知っているに違いない.すなわち、新しいデータを挿入すると、Cassandraはバージョン番号としてタイムスタンプを与えなければならない.プライマリ・キーが一致すれば、元のデータは削除されず、古いデータに直接新しいデータを上書きし、タイムスタンプでソートする.クエリのたびにタイムスタンプが最も大きいものが取得されます.
ログを結合すると、eran 10003のタイムスタンプは1392953766795000で、eran 10004のタイムスタンプより大きい:1392953753016000です.そこで検索すると、Cassandraはeran 10003が最新だと思っていたが、eran 10004は取得できなかった.
タイムスタンプはサーバのローカル時間であり、91の時間が90より大きいため問題が発生します.
 
ソリューション:
1.Ntp同期91および90および143を使用する時間.
2、タイムスタンプには、サービス側ではなくクライアント制御があり、マルチクライアントであれば、クライアント間で時間を同期する必要があります.
もちろんConsistency Level:QUORUMも必要です.