[ https://issues.apache.org/jira/browse/CASSANDRA-12915?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15726079#comment-15726079 ]
Corentin Chary commented on CASSANDRA-12915: -------------------------------------------- {code} CREATE KEYSPACE test WITH replication = {'class': 'SimpleStrategy', 'replication_factor': '1'} AND durable_writes = true; CREATE TABLE test.test ( r text PRIMARY KEY, a text, b text, c text, data text ) WITH bloom_filter_fp_chance = 0.01 AND caching = {'keys': 'ALL', 'rows_per_partition': 'NONE'} AND comment = '' AND compaction = {'class': 'org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy', 'max_threshold': '32', 'min_threshold': '4'} AND compression = {'chunk_length_in_kb': '64', 'class': 'org.apache.cassandra.io.compress.LZ4Compressor'} 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'; CREATE CUSTOM INDEX test_a_idx ON test.test (a) USING 'org.apache.cassandra.index.sasi.SASIIndex' WITH OPTIONS = {'analyzer_class': 'org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer', 'case_sensitive': 'true'}; CREATE CUSTOM INDEX test_c_idx ON test.test (c) USING 'org.apache.cassandra.index.sasi.SASIIndex' WITH OPTIONS = {'analyzer_class': 'org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer', 'case_sensitive': 'true'}; CREATE CUSTOM INDEX test_b_idx ON test.test (b) USING 'org.apache.cassandra.index.sasi.SASIIndex' WITH OPTIONS = {'analyzer_class': 'org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer', 'case_sensitive': 'true'}; {code} {code} $ cat > generate.py import sys import random def main(args): n = int(args[1]) for i in xrange(n): a = '0' b = i % 10 c = i % (n / 10) + random.randint(0, 10) print ("%d,%s,%d,%d,%d" % (i, a, b, c, i)) if __name__ == '__main__': main(sys.argv) $ python generate.py 2000000 > test.csv {code} {code} COPY test.test FROM 'test.csv' WITH MAXBATCHSIZE = 100 AND MAXATTEMPTS = 10 AND MAXINSERTERRORS = 999999; SELECT * FROM test.test WHERE a = '0' AND c = '44859' ALLOW FILTERING; {code} 3.X - with logs but without optimisations - 20ms (according to tracing) {code} TRACE [ReadStage-2] 2016-12-06 17:58:08,743 QueryPlan.java:60 - Analyzing org.apache.cassandra.config.CFMetaData@450c6f26[cfId=04e98180-bbb7-11e6-9680-cf420076f59b,ksName=test,cfName=test,flags=[COMPOUND],params=TableParams{comment=, read_repair_chance=0.0, dclocal_read_repair_chance=0.1, bloom_filter_fp_chance=0.01, crc_check_chance=1.0, gc_grace_seconds=864000, default_time_to_live=0, memtable_flush_period_in_ms=0, min_index_interval=128, max_index_interval=2048, speculative_retry=99PERCENTILE, caching={'keys' : 'ALL', 'rows_per_partition' : 'NONE'}, compaction=CompactionParams{class=org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy, options={max_threshold=32, min_threshold=4}}, compression=org.apache.cassandra.schema.CompressionParams@8f72cea3, extensions={}, cdc=false},comparator=comparator(),partitionColumns=[[] | [a b c data]],partitionKeyColumns=[r],clusteringColumns=[],keyValidator=org.apache.cassandra.db.marshal.UTF8Type,columnMetadata=[a, r, b, c, data],droppedColumns={},triggers=[],indexes=[org.apache.cassandra.schema.IndexMetadata@78b5523d[id=2e3c652f-e00c-3bd3-b2e9-90de1c170900,name=test_a_idx,kind=CUSTOM,options={analyzer_class=org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer, case_sensitive=true, class_name=org.apache.cassandra.index.sasi.SASIIndex, target=a}], org.apache.cassandra.schema.IndexMetadata@4e4f20d2[id=6b00489b-7010-396e-9348-9f32f5167f88,name=test_b_idx,kind=CUSTOM,options={analyzer_class=org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer, case_sensitive=true, class_name=org.apache.cassandra.index.sasi.SASIIndex, target=b}], org.apache.cassandra.schema.IndexMetadata@681c0362[id=45fcb286-b87a-3d18-a04b-b899a9880c91,name=test_c_idx,kind=CUSTOM,options={analyzer_class=org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer, case_sensitive=true, class_name=org.apache.cassandra.index.sasi.SASIIndex, target=c}]]] [a = 0, c = 44859] TRACE [ReadStage-2] 2016-12-06 17:58:08,744 QueryController.java:289 - Expressions: [Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []}, Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}], Op: AND TRACE [ReadStage-2] 2016-12-06 17:58:08,745 QueryController.java:321 - Final view: {Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}=[SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big)], Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []}=[SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big)]} TRACE [ReadStage-2] 2016-12-06 17:58:08,745 QueryController.java:270 - Estimated row count for Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}: 3 TRACE [ReadStage-2] 2016-12-06 17:58:08,745 QueryController.java:270 - Estimated row count for Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []}: 1559 TRACE [ReadStage-2] 2016-12-06 17:58:08,745 QueryController.java:157 - Searching (Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []},[SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big)]) TRACE [ReadStage-2] 2016-12-06 17:58:08,746 QueryController.java:161 - Found 13 tokens TRACE [ReadStage-2] 2016-12-06 17:58:08,746 QueryController.java:177 - (Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []},[SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big)]) LIMIT 100 13 TRACE [ReadStage-2] 2016-12-06 17:58:08,746 QueryController.java:157 - Searching (Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []},[SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big)]) TRACE [ReadStage-2] 2016-12-06 17:58:08,747 QueryController.java:161 - Found 2000000 tokens TRACE [ReadStage-2] 2016-12-06 17:58:08,747 QueryController.java:177 - (Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []},[SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big)]) LIMIT 100 2000000 TRACE [ReadStage-2] 2016-12-06 17:58:08,747 QueryController.java:201 - count: 13, ratio: 1.0, threshold: 100 TRACE [ReadStage-2] 2016-12-06 17:58:08,747 QueryController.java:201 - count: 2000000, ratio: 6.5E-6, threshold: 100 TRACE [ReadStage-2] 2016-12-06 17:58:08,747 QueryPlan.java:65 - done {code} 3.X - with logs and optimisations - 5ms (according to tracing) We can see that it skips the search on other indexes as soon as it finds enough tokens. Even without with optimisation it would have discarded the results from 'a' because it returns way more results than the filter on 'c'. {code} TRACE [ReadStage-2] 2016-12-06 17:39:13,280 QueryController.java:289 - Expressions: [Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}, Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []}], Op: AND TRACE [ReadStage-2] 2016-12-06 17:39:13,280 QueryController.java:321 - Final view: {Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}=[SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big)], Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []}=[SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big)]} TRACE [ReadStage-2] 2016-12-06 17:39:13,280 QueryController.java:270 - Estimated row count for Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}: 3 TRACE [ReadStage-2] 2016-12-06 17:39:13,280 QueryController.java:270 - Estimated row count for Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []}: 1559 TRACE [ReadStage-2] 2016-12-06 17:39:13,280 QueryController.java:157 - Searching (Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []},[SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big)]) INFO [ReadStage-2] 2016-12-06 17:39:13,280 TermIterator.java:51 - Search Concurrency Factor is set to 1 for ReadStage-2 TRACE [ReadStage-2] 2016-12-06 17:39:13,281 QueryController.java:161 - Found 13 tokens TRACE [ReadStage-2] 2016-12-06 17:39:13,281 QueryController.java:177 - (Expression{name: c, op: EQ, lower: (44859, true), upper: (44859, true), exclusions: []},[SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: c, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big)]) LIMIT 100 13 TRACE [ReadStage-2] 2016-12-06 17:39:13,281 QueryController.java:181 - We found less than 100 tokens. Stopping. TRACE [ReadStage-2] 2016-12-06 17:39:13,281 QueryController.java:201 - count: 13, ratio: 1.0, threshold: 100 {code} That's a 4x improvement with 2M rows. It gives even better results for the worst case: {code} SELECT * FROM test.test WHERE a = '0' AND c = '0' ALLOW FILTERING; {code} With the current code: {code} ReadTimeout: Error from server: code=1200 [Coordinator node timed out waiting for replica nodes' responses] message="Operation timed out - received only 0 responses." info={'received_responses': 0, 'required_responses': 1, 'consistency': 'ONE'} {code} With the optimisations it takes only a few ms {code} TRACE [ReadStage-2] 2016-12-06 18:07:50,945 QueryPlan.java:60 - Analyzing org.apache.cassandra.config.CFMetaData@3b6bbdb0[cfId=04e98180-bbb7-11e6-9680-cf420076f59b,ksName=test,cfName=test,flags=[COMPOUND],params=TableParams{comment=, read_repair_chance=0.0, dclocal_read_repair_chance=0.1, bloom_filter_fp_chance=0.01, crc_check_chance=1.0, gc_grace_seconds=864000, default_time_to_live=0, memtable_flush_period_in_ms=0, min_index_interval=128, max_index_interval=2048, speculative_retry=99PERCENTILE, caching={'keys' : 'ALL', 'rows_per_partition' : 'NONE'}, compaction=CompactionParams{class=org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy, options={max_threshold=32, min_threshold=4}}, compression=org.apache.cassandra.schema.CompressionParams@8f72cea3, extensions={}, cdc=false},comparator=comparator(),partitionColumns=[[] | [a b c data]],partitionKeyColumns=[r],clusteringColumns=[],keyValidator=org.apache.cassandra.db.marshal.UTF8Type,columnMetadata=[a, r, b, c, data],droppedColumns={},triggers=[],indexes=[org.apache.cassandra.schema.IndexMetadata@33285244[id=2e3c652f-e00c-3bd3-b2e9-90de1c170900,name=test_a_idx,kind=CUSTOM,options={analyzer_class=org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer, case_sensitive=true, class_name=org.apache.cassandra.index.sasi.SASIIndex, target=a}], org.apache.cassandra.schema.IndexMetadata@4003dd6d[id=6b00489b-7010-396e-9348-9f32f5167f88,name=test_b_idx,kind=CUSTOM,options={analyzer_class=org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer, case_sensitive=true, class_name=org.apache.cassandra.index.sasi.SASIIndex, target=b}], org.apache.cassandra.schema.IndexMetadata@26e37ee0[id=45fcb286-b87a-3d18-a04b-b899a9880c91,name=test_c_idx,kind=CUSTOM,options={analyzer_class=org.apache.cassandra.index.sasi.analyzer.NonTokenizingAnalyzer, case_sensitive=true, class_name=org.apache.cassandra.index.sasi.SASIIndex, target=c}]]] [a = 0, c = 0] TRACE [ReadStage-2] 2016-12-06 18:07:50,946 QueryController.java:289 - Expressions: [Expression{name: c, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}, Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}], Op: AND TRACE [ReadStage-2] 2016-12-06 18:07:50,946 QueryController.java:321 - Final view: {Expression{name: c, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}=[], Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}=[SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big)]} TRACE [ReadStage-2] 2016-12-06 18:07:50,946 QueryController.java:270 - Estimated row count for Expression{name: c, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}: 0 TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryController.java:270 - Estimated row count for Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []}: 3 TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryController.java:157 - Searching (Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []},[SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big)]) TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryController.java:161 - Found 2000000 tokens TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryController.java:177 - (Expression{name: a, op: EQ, lower: (0, true), upper: (0, true), exclusions: []},[SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-40-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-34-big), SSTableIndex(column: a, SSTable: /home/iksaif/dev/data/data/test/test-04e98180bbb711e69680cf420076f59b/mc-39-big)]) LIMIT 100 2000000 TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryController.java:157 - Searching (Expression{name: c, op: EQ, lower: (0, true), upper: (0, true), exclusions: []},[]) TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryController.java:161 - Found 0 tokens TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryController.java:201 - count: 2000000, ratio: 0.0, threshold: 100 TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryController.java:204 - Skipping TRACE [ReadStage-2] 2016-12-06 18:07:50,947 QueryPlan.java:65 - done {code} I can try to run it with more rows if necessary. Didn't get the time to write unit tests today, hopefully tomorrow. > SASI: Index intersection can be very inefficient > ------------------------------------------------ > > Key: CASSANDRA-12915 > URL: https://issues.apache.org/jira/browse/CASSANDRA-12915 > Project: Cassandra > Issue Type: Improvement > Components: sasi > Reporter: Corentin Chary > Fix For: 3.x > > > It looks like RangeIntersectionIterator.java and be pretty inefficient in > some cases. Let's take the following query: > SELECT data FROM table WHERE index1 = 'foo' AND index2 = 'bar'; > In this case: > * index1 = 'foo' will match 2 items > * index2 = 'bar' will match ~300k items > On my setup, the query will take ~1 sec, most of the time being spent in > disk.TokenTree.getTokenAt(). > if I patch RangeIntersectionIterator so that it doesn't try to do the > intersection (and effectively only use 'index1') the query will run in a few > tenth of milliseconds. > I see multiple solutions for that: > * Add a static thresold to avoid the use of the index for the intersection > when we know it will be slow. Probably when the range size factor is very > small and the range size is big. > * CASSANDRA-10765 -- This message was sent by Atlassian JIRA (v6.3.4#6332)