Last active
April 3, 2018 12:33
-
-
Save kw217/bdb92bc5261c3d34aebab59d2eb29f72 to your computer and use it in GitHub Desktop.
Odd behaviour of Cassandra MVs in Cassandra 3.0.7.1159
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| # Output of DESCRIBE for the relevant view: | |
| CREATE MATERIALIZED VIEW edison.lus_subscriber_phone AS | |
| SELECT phone, id, n, revision | |
| FROM edison.scs_subscriber | |
| WHERE phone IS NOT NULL AND id IS NOT NULL AND n IS NOT NULL | |
| PRIMARY KEY (phone, id, n) | |
| WITH CLUSTERING ORDER BY (id ASC, n ASC) | |
| AND bloom_filter_fp_chance = 0.01 | |
| AND caching = {'keys': 'NONE', 'rows_per_partition': 'NONE'} | |
| AND comment = '' | |
| AND compaction = {'class': 'org.apache.cassandra.db.compaction.MemoryOnlyStrategy'} | |
| AND compression = {'enabled': 'false'} | |
| AND crc_check_chance = 1.0 | |
| AND dclocal_read_repair_chance = 0.1 | |
| AND default_time_to_live = 0 | |
| AND gc_grace_seconds = 864000 | |
| AND max_index_interval = 2048 | |
| AND memtable_flush_period_in_ms = 0 | |
| AND min_index_interval = 128 | |
| AND read_repair_chance = 0.0 | |
| AND speculative_retry = '99PERCENTILE'; | |
| # First time, we get the expected value: | |
| edison@cqlsh> select phone,id,n,revision,writetime(revision) from edison.lus_subscriber_phone where phone = '0008482643'; | |
| phone | id | n | revision | writetime(revision) | |
| ------------+------------------------------+---+-------------------------------------------+--------------------- | |
| 0008482643 | 20160811040203AAAA0008482643 | 0 | (03a288d0-62f2-11e6-acef-f53c88dc0995, 3) | 1471270227073002 | |
| (1 rows) | |
| Tracing session: a24740c0-6487-11e6-a30e-a95212c3e25f | |
| activity | timestamp | source | source_elapsed | |
| --------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------------+---------------- | |
| Execute CQL3 query | 2016-08-17 14:33:58.732000 | 192.168.100.165 | 0 | |
| Parsing select phone,id,n,revision,writetime(revision) from edison.lus_subscriber_phone where phone = '0008482643'; [SharedPool-Worker-26] | 2016-08-17 14:33:58.733000 | 192.168.100.165 | 554 | |
| Preparing statement [SharedPool-Worker-26] | 2016-08-17 14:33:58.733000 | 192.168.100.165 | 822 | |
| reading data from /192.168.100.157 [SharedPool-Worker-26] | 2016-08-17 14:33:58.735000 | 192.168.100.165 | 2887 | |
| Sending READ message to /192.168.100.157 [MessagingService-Outgoing-/192.168.100.157] | 2016-08-17 14:33:58.737000 | 192.168.100.165 | 4563 | |
| READ message received from /192.168.100.165 [MessagingService-Incoming-/192.168.100.165] | 2016-08-17 14:33:58.738000 | 192.168.100.157 | 49 | |
| Executing single-partition query on lus_subscriber_phone [SharedPool-Worker-1] | 2016-08-17 14:33:58.739000 | 192.168.100.157 | 441 | |
| Acquiring sstable references [SharedPool-Worker-1] | 2016-08-17 14:33:58.739000 | 192.168.100.157 | 561 | |
| Partition index with 0 entries found for sstable 105 [SharedPool-Worker-1] | 2016-08-17 14:33:58.739000 | 192.168.100.157 | 653 | |
| Skipped 0/1 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-1] | 2016-08-17 14:33:58.739000 | 192.168.100.157 | 728 | |
| Merging data from memtables and 1 sstables [SharedPool-Worker-1] | 2016-08-17 14:33:58.739000 | 192.168.100.157 | 786 | |
| Read 1 live and 0 tombstone cells [SharedPool-Worker-1] | 2016-08-17 14:33:58.739001 | 192.168.100.157 | 896 | |
| Enqueuing response to /192.168.100.165 [SharedPool-Worker-1] | 2016-08-17 14:33:58.739001 | 192.168.100.157 | 1041 | |
| Sending REQUEST_RESPONSE message to /192.168.100.165 [MessagingService-Outgoing-/192.168.100.165] | 2016-08-17 14:33:58.739001 | 192.168.100.157 | 1191 | |
| REQUEST_RESPONSE message received from /192.168.100.157 [MessagingService-Incoming-/192.168.100.157] | 2016-08-17 14:33:58.740000 | 192.168.100.165 | 7615 | |
| Processing response from /192.168.100.157 [SharedPool-Worker-37] | 2016-08-17 14:33:58.741000 | 192.168.100.165 | 8200 | |
| Request complete | 2016-08-17 14:33:58.741765 | 192.168.100.165 | 9765 | |
| # Second time, we unexpectedly get null: | |
| edison@cqlsh> select phone,id,n,revision,writetime(revision) from edison.lus_subscriber_phone where phone = '0008482643'; | |
| phone | id | n | revision | writetime(revision) | |
| ------------+------------------------------+---+----------+--------------------- | |
| 0008482643 | 20160811040203AAAA0008482643 | 0 | null | null | |
| (1 rows) | |
| Tracing session: ba4b5300-6487-11e6-a30e-a95212c3e25f | |
| activity | timestamp | source | source_elapsed | |
| -------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------------+---------------- | |
| Execute CQL3 query | 2016-08-17 14:34:39.024000 | 192.168.100.165 | 0 | |
| Parsing select phone,id,n,revision,writetime(revision) from edison.lus_subscriber_phone where phone = '0008482643'; [SharedPool-Worker-1] | 2016-08-17 14:34:39.025000 | 192.168.100.165 | 805 | |
| Preparing statement [SharedPool-Worker-1] | 2016-08-17 14:34:39.026000 | 192.168.100.165 | 1347 | |
| reading data from /192.168.100.176 [SharedPool-Worker-1] | 2016-08-17 14:34:39.026000 | 192.168.100.165 | 1791 | |
| READ message received from /192.168.100.165 [MessagingService-Incoming-/192.168.100.165] | 2016-08-17 14:34:39.027000 | 192.168.100.176 | 105 | |
| Sending READ message to /192.168.100.176 [MessagingService-Outgoing-/192.168.100.176] | 2016-08-17 14:34:39.027000 | 192.168.100.165 | 2291 | |
| Executing single-partition query on lus_subscriber_phone [SharedPool-Worker-6] | 2016-08-17 14:34:39.028000 | 192.168.100.176 | 832 | |
| Acquiring sstable references [SharedPool-Worker-6] | 2016-08-17 14:34:39.029000 | 192.168.100.176 | 1905 | |
| Partition index with 0 entries found for sstable 95 [SharedPool-Worker-6] | 2016-08-17 14:34:39.029000 | 192.168.100.176 | 2065 | |
| Skipped 0/1 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-6] | 2016-08-17 14:34:39.029000 | 192.168.100.176 | 2140 | |
| Merging data from memtables and 1 sstables [SharedPool-Worker-6] | 2016-08-17 14:34:39.029000 | 192.168.100.176 | 2188 | |
| Read 1 live and 0 tombstone cells [SharedPool-Worker-6] | 2016-08-17 14:34:39.029000 | 192.168.100.176 | 2252 | |
| Enqueuing response to /192.168.100.165 [SharedPool-Worker-6] | 2016-08-17 14:34:39.030000 | 192.168.100.176 | 2429 | |
| Sending REQUEST_RESPONSE message to /192.168.100.165 [MessagingService-Outgoing-/192.168.100.165] | 2016-08-17 14:34:39.030000 | 192.168.100.176 | 2856 | |
| REQUEST_RESPONSE message received from /192.168.100.176 [MessagingService-Incoming-/192.168.100.176] | 2016-08-17 14:34:39.032000 | 192.168.100.165 | 7237 | |
| Processing response from /192.168.100.176 [SharedPool-Worker-2] | 2016-08-17 14:34:39.032000 | 192.168.100.165 | 7399 | |
| Request complete | 2016-08-17 14:34:39.031830 | 192.168.100.165 | 7830 | |
| # The base row is fine, every time it's queried we get the same result: | |
| edison@cqlsh> select id,phone,n,revision,writetime(revision) from edison.scs_subscriber where id = '20160811040203AAAA0008482643'; | |
| id | phone | n | revision | writetime(revision) | |
| ------------------------------+------------+---+-------------------------------------------+--------------------- | |
| 20160811040203AAAA0008482643 | 0008482643 | 0 | (03a288d0-62f2-11e6-acef-f53c88dc0995, 3) | 1471270227073002 | |
| (1 rows) | |
| Tracing session: 89af5620-648b-11e6-a30e-a95212c3e25f | |
| activity | timestamp | source | source_elapsed | |
| ----------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------------+---------------- | |
| Execute CQL3 query | 2016-08-17 15:01:55.459000 | 192.168.100.165 | 0 | |
| Parsing select id,phone,n,revision,writetime(revision) from edison.scs_subscriber where id = '20160811040203AAAA0008482643'; [SharedPool-Worker-1] | 2016-08-17 15:01:55.462000 | 192.168.100.165 | 2929 | |
| Preparing statement [SharedPool-Worker-1] | 2016-08-17 15:01:55.462000 | 192.168.100.165 | 3406 | |
| Executing single-partition query on scs_subscriber [SharedPool-Worker-3] | 2016-08-17 15:01:55.468000 | 192.168.100.165 | 9177 | |
| Acquiring sstable references [SharedPool-Worker-3] | 2016-08-17 15:01:55.468000 | 192.168.100.165 | 9261 | |
| Bloom filter allows skipping sstable 20285 [SharedPool-Worker-3] | 2016-08-17 15:01:55.468000 | 192.168.100.165 | 9542 | |
| Bloom filter allows skipping sstable 20284 [SharedPool-Worker-3] | 2016-08-17 15:01:55.469000 | 192.168.100.165 | 10153 | |
| Bloom filter allows skipping sstable 20207 [SharedPool-Worker-3] | 2016-08-17 15:01:55.469000 | 192.168.100.165 | 10238 | |
| Bloom filter allows skipping sstable 20202 [SharedPool-Worker-3] | 2016-08-17 15:01:55.469000 | 192.168.100.165 | 10275 | |
| Bloom filter allows skipping sstable 20193 [SharedPool-Worker-3] | 2016-08-17 15:01:55.469000 | 192.168.100.165 | 10301 | |
| Bloom filter allows skipping sstable 20169 [SharedPool-Worker-3] | 2016-08-17 15:01:55.469000 | 192.168.100.165 | 10354 | |
| Bloom filter allows skipping sstable 20077 [SharedPool-Worker-3] | 2016-08-17 15:01:55.469000 | 192.168.100.165 | 10379 | |
| Bloom filter allows skipping sstable 19969 [SharedPool-Worker-3] | 2016-08-17 15:01:55.469001 | 192.168.100.165 | 10425 | |
| Partition index with 0 entries found for sstable 19950 [SharedPool-Worker-3] | 2016-08-17 15:01:55.470000 | 192.168.100.165 | 10998 | |
| Skipped 0/10 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-3] | 2016-08-17 15:01:55.488000 | 192.168.100.165 | 29487 | |
| Merging data from memtables and 9 sstables [SharedPool-Worker-3] | 2016-08-17 15:01:55.489000 | 192.168.100.165 | 29947 | |
| Read 1 live and 0 tombstone cells [SharedPool-Worker-3] | 2016-08-17 15:01:55.490000 | 192.168.100.165 | 31191 | |
| Request complete | 2016-08-17 15:01:55.491087 | 192.168.100.165 | 32087 | |
| # SSTable used for first query: | |
| # sstabledump /var/lib/cassandra/data/edison/lus_subscriber_phone-167702e05f6611e6a73bed42d2f0cc13/mb-105-big-Data.db -d -k 0008482643 | |
| [0008482643]@2881129 Row[info=[ts=1471270227073002] del=deletedAt=1471270227073001, localDeletion=1471270227 ]: 20160811040203AAAA0008482643, 0 | [revision=03a288d0-62f2-11e6-acef-f53c88dc0995:3 ts=1471270227073002] | |
| # SSTable used for second query: | |
| # sstabledump /var/lib/cassandra/data/edison/lus_subscriber_phone-167702e05f6611e6a73bed42d2f0cc13/mb-95-big-Data.db -d -k 0008482643 | |
| [0008482643]@2551623 Row[info=[ts=1471270227073002] del=deletedAt=1471270227073001, localDeletion=1471270227 ]: 20160811040203AAAA0008482643, 0 | | |
| # Data from base table (slightly edited): | |
| # sstabledump /var/lib/cassandra/data/edison/scs_subscriber-140a48a05f6611e6b3adb39915d87438/mb-19950-big-Data.db -d -k 20160811040203AAAA0008482643611e6b3adb39915d87438/mb-19950-big-Data.db -d -k 20160811040203AAAA000 | |
| [20160811040203AAAA0008482643]@142571847 deletedAt=1471270227073001, localDeletion=1471270227 | |
| [20160811040203AAAA0008482643]@142571847 Row[info=[ts=-9223372036854775808] ]: 0 | [data4=03a288d0-62f2-11e6-acef-f53c88dc0995:67a63dfba7712...lots of blob data omitted...9a5d25e0e ts=1471270227073002], [foo=1NX00084826430123456789abcdef0123456789 ts=1471270227073002], [bar=0008482643@example.com ts=1471270227073002], [phone=0008482643 ts=1471270227073002], [revision=03a288d0-62f2-11e6-acef-f53c88dc0995:3 ts=1471270227073002] | |
| # Ten seconds after the timestamp, in debug.log on the server hosting mb-95 is the following (may not be related; something similar appears on the other server four seconds later): | |
| ERROR [SharedPool-Worker-3] 2016-08-17 14:10:37,192 Keyspace.java:490 - Unknown exception caught while attempting to update MaterializedView! edison.scs_subscriber | |
| java.lang.AssertionError: We shouldn't have got there is the base row had no associated entry | |
| at org.apache.cassandra.db.view.ViewUpdateGenerator.computeLivenessInfoForEntry(ViewUpdateGenerator.java:455) ~[cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.view.ViewUpdateGenerator.updateEntry(ViewUpdateGenerator.java:273) ~[cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.view.ViewUpdateGenerator.addBaseTableUpdate(ViewUpdateGenerator.java:127) ~[cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.view.TableViews.addToViewUpdateGenerators(TableViews.java:403) ~[cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.view.TableViews.generateViewUpdates(TableViews.java:236) ~[cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.view.TableViews.pushViewReplicaUpdates(TableViews.java:140) ~[cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.Keyspace.apply(Keyspace.java:485) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.Keyspace.apply(Keyspace.java:384) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.Mutation.applyFuture(Mutation.java:205) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.Mutation.apply(Mutation.java:217) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.Mutation.apply(Mutation.java:231) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.db.ReadRepairVerbHandler.doVerb(ReadRepairVerbHandler.java:28) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:67) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_91] | |
| at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:164) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$LocalSessionFutureTask.run(AbstractLocalAwareExecutorService.java:136) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:105) [cassandra-all-3.0.7.1159.jar:3.0.7.1159] | |
| at java.lang.Thread.run(Thread.java:745) [na:1.8.0_91] | |
| WARN [SharedPool-Worker-3] 2016-08-17 14:10:37,194 AbstractLocalAwareExecutorService.java:169 - Uncaught exception on thread Thread[SharedPool-Worker-3,5,m |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
thanks, does it fix now ? we are facing it with 3.7 version.