Hi Chap,
You don't indicate which version of Cassandra and what client side driver
you are using, but I have seen the same behavior with Cassandra 2.0.2 and
earlier versions of the Java Driver. With Cassandra 2.0.3 and the 2.0.0rc2
driver, my read timeouts are basically nonexistent at my current load
levels.
Not sure how this applies if you're still on 1.x versions of Cassandra
since we moved off of that branch a few months ago. Ditto for the client
driver if you're using something other than the Java Driver, or the 1.x
version of same. Our problems were due to changes specific to the 2.x
versions only.
Steve
On Wed, Feb 5, 2014 at 2:14 PM, Chap Lovejoy <chaplove...@gmail.com> wrote:
> Hi,
>
> We're seeing pretty regular rpc timeout errors on what appear to be simple
> queries. We're running a three node cluster under pretty light load. We're
> averaging 30-40 writes/sec and about 8 reads/sec according to OpsCenter.
> The failures don't seem to be related to any changes in load. A single
> query repeated from CQLSH (about once a second or so) will fail
> approximately one out of ten times. I do see an increase in the average
> read latency around the time of the failure, though it's unclear if that's
> from the single failed request or if others are affected. This seems to
> happen most on a number of similarly structured tables. One is:
>
> CREATE TABLE psr (
> inst_id bigint,
> prosp_id bigint,
> inter_id bigint,
> avail text,
> comments text,
> email text,
> first_name text,
> last_name text,
> m_id text,
> m_num text,
> phone text,
> info blob,
> status text,
> time timestamp,
> PRIMARY KEY ((inst_id, prosp_id), inter_id)
> ) WITH CLUSTERING ORDER BY (inter_id DESC) AND
> bloom_filter_fp_chance=0.010000 AND
> caching='KEYS_ONLY' AND
> comment='' AND
> dclocal_read_repair_chance=0.000000 AND
> gc_grace_seconds=864000 AND
> index_interval=128 AND
> read_repair_chance=0.100000 AND
> replicate_on_write='true' AND
> populate_io_cache_on_flush='false' AND
> default_time_to_live=0 AND
> speculative_retry='99.0PERCENTILE' AND
> memtable_flush_period_in_ms=0 AND
> compaction={'class': 'SizeTieredCompactionStrategy'} AND
> compression={'sstable_compression': 'LZ4Compressor'};
>
> I'm executing the query:
> SELECT inter_id FROM "psr" WHERE inst_id = 1 AND prosp_id =
> 127788649174986752 AND inter_id < 30273563814527279 LIMIT 10000;
>
> Normally this query returns 32 rows. A total of 413 match the partition
> key.
>
> Here is a trace for a successful run:
> | timestamp | source
> | source_elapsed
> --------------------------------------------------+---------
> -----+---------------+----------------
> execute_cql3_query | 21:52:20,831 |
> 10.128.32.141 | 0
> Message received from /10.128.32.141 | 21:52:20,826 |
> 10.128.32.140 | 69
> Executing single-partition query on psr | 21:52:20,827 |
> 10.128.32.140 | 502
> Acquiring sstable references | 21:52:20,827 |
> 10.128.32.140 | 517
> Merging memtable tombstones | 21:52:20,827 |
> 10.128.32.140 | 576
> Key cache hit for sstable 54 | 21:52:20,827 |
> 10.128.32.140 | 685
> Seeking to partition indexed section in data file | 21:52:20,827 |
> 10.128.32.140 | 697
> Skipped 1/2 non-slice-intersecting sstables, | 21:52:20,827 |
> 10.128.32.140 | 751
> included 0 due to tombstones
> Merging data from memtables and 1 sstables | 21:52:20,827 |
> 10.128.32.140 | 773
> Read 32 live and 0 tombstoned cells | 21:52:20,828 |
> 10.128.32.140 | 2055
> Enqueuing response to /10.128.32.141 | 21:52:20,829 |
> 10.128.32.140 | 2172
> Sending message to /10.128.32.141 | 21:52:20,829 |
> 10.128.32.140 | 2341
> Parsing SELECT ... | 21:52:20,831 |
> 10.128.32.141 | 105
> Preparing statement | 21:52:20,831 |
> 10.128.32.141 | 200
> Sending message to /10.128.32.140 | 21:52:20,831 |
> 10.128.32.141 | 492
> Message received from /10.128.32.140 | 21:52:20,836 |
> 10.128.32.141 | 5361
> Processing response from /10.128.32.140 | 21:52:20,836 |
> 10.128.32.141 | 5534
> Request complete | 21:52:20,837 |
> 10.128.32.141 | 6013
>
>
> And here is on unsuccessful run:
>
> | timestamp | source
> | source_elapsed
> ---------------------------------------------------+--------
> ------+---------------+---------------
> execute_cql3_query | 21:56:19,792 |
> 10.128.32.141 | 0
> Parsing SELECT ... | 21:56:19,792 |
> 10.128.32.141 | 69
> Preparing statement | 21:56:19,792 |
> 10.128.32.141 | 160
> Sending message to /10.128.32.137 | 21:56:19,792 |
> 10.128.32.141 | 509
> Message received from /10.128.32.141 | 21:56:19,793 |
> 10.128.32.137 | 57
> Executing single-partition query on psr | 21:56:19,794 |
> 10.128.32.137 | 412
> Acquiring sstable references | 21:56:19,794 |
> 10.128.32.137 | 444
> Merging memtable tombstones | 21:56:19,794 |
> 10.128.32.137 | 486
> Key cache hit for sstable 59 | 21:56:19,794 |
> 10.128.32.137 | 555
> Seeking to partition indexed section in data file | 21:56:19,794 |
> 10.128.32.137 | 569
> Key cache hit for sstable 3 | 21:56:19,794 |
> 10.128.32.137 | 609
> Seeking to partition indexed section in data file | 21:56:19,794 |
> 10.128.32.137 | 621
> Timed out; received 0 of 1 responses | 21:56:24,792 |
> 10.128.32.141 | 5000766
> Request complete | 21:56:24,792 |
> 10.128.32.141 | 5000888
>
> The output of cfstats is:
>
> SSTable count: 3
> Space used (live), bytes: 606268
> Space used (total), bytes: 612372
> SSTable Compression Ratio: 0.4011882905126778
> Number of keys (estimate): 768
> Memtable cell count: 156
> Memtable data size, bytes: 60451
> Memtable switch count: 34
> Local read count: 1439
> Local read latency: NaN ms
> Local write count: 618
> Local write latency: NaN ms
> Pending tasks: 0
> Bloom filter false positives: 0
> Bloom filter false ratio: 0.00000
> Bloom filter space used, bytes: 1840
> Compacted partition minimum bytes: 447
> Compacted partition maximum bytes: 20501
> Compacted partition mean bytes: 3478
> Average live cells per slice (last five minutes): 0.0
> Average tombstones per slice (last five minutes): 0.0
>
> Is there a problem with the table structure or query that would be causing
> these failures? Should we expect timeouts as a regular occurrence in
> operation and be prepared to retry every query as needed?
>
> I'd really appreciate any input you could offer on how to improve this.
> These timeouts are causing some rather troublesome errors in our
> application.
>
> Thank you,
> Chap
>
--
Steve Robenalt
Software Architect
HighWire | Stanford University
425 Broadway St, Redwood City, CA 94063
srobe...@stanford.edu
http://highwire.stanford.edu
