cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Clint Kelly <clint.ke...@gmail.com>
Subject Best practices for route tracing
Date Sun, 16 Nov 2014 21:42:15 GMT
Hi all,

I am trying to debug some high-latency outliers (99th percentile) in an
application I'm working on.  I thought that I could turn on route tracing,
print the route traces to logs, and then examine my logs after a load test
to find the highest-latency paths and figure out what is going on.

I did something similar to what is described here:
http://www.datastax.com/documentation/developer/java-driver/2.1/java-driver/tracing_t.html

Under low amounts of traffic, this looks great and I can see nice trace
logs:

Total duration: 599 us (id: ae159110-6dd8-11e4-a6a1-cd4ac3ad1896)
                                  Executing single-partition query on
lg_users_C |   13:36:52.898 |     /10.29.2.9 |          204
                                                    Acquiring sstable
references |   13:36:52.898 |     /10.29.2.9 |          207
                                                     Merging memtable
tombstones |   13:36:52.898 |     /10.29.2.9 |          213
                                         Bloom filter allows skipping
sstable 40 |   13:36:52.898 |     /10.29.2.9 |          231
                                         Bloom filter allows skipping
sstable 38 |   13:36:52.898 |     /10.29.2.9 |          237
                                         Bloom filter allows skipping
sstable 37 |   13:36:52.898 |     /10.29.2.9 |          243
                                                    Key cache hit for
sstable 39 |   13:36:52.898 |     /10.29.2.9 |          251
                               Seeking to partition indexed section in data
file |   13:36:52.898 |     /10.29.2.9 |          251
       Skipped 0/4 non-slice-intersecting sstables, included 0 due to
tombstones |   13:36:52.898 |     /10.29.2.9 |          455
                                      Merging data from memtables and 1
sstables |   13:36:52.898 |     /10.29.2.9 |          457
                                              Read 0 live and 0 tombstoned
cells |   13:36:52.898 |     /10.29.2.9 |          472


Under heavier load, however, things seem to fall over, and I get a lot of
exceptions like:

14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.9:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.8:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.9:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.12:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.9:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.9:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.10:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.11:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying xwing07.ul.wibidata.net/10.29.2.7:9042, trying next host (error
is: com.datastax.driver.core.exceptions.DriverException: Timeout during
read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.10:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.9:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.8:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying xwing07.ul.wibidata.net/10.29.2.7:9042, trying next host (error
is: com.datastax.driver.core.exceptions.DriverException: Timeout during
read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.8:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 DEBUG com.datastax.driver.core.RequestHandler: Error
querying /10.29.2.11:9042, trying next host (error is:
com.datastax.driver.core.exceptions.DriverException: Timeout during read)
14/11/16 13:39:41 WARN com.datastax.driver.core.Connection: Timeout while
setting keyspace on connection to /10.29.2.11:9042. This should not happen
but is not critical (it will retried)

Is this expected?  I am running only ~100 reads per second on this load
test, which I didn't think should be too much.

One thing I noticed is that the example I referenced above explicitly calls:

      insert.disableTracing();

do I need to do that in my application for a statement that is not used
again?  What if I have a prepared statement that I issue several time
consecutively?

Thanks!

-Clint

Mime
View raw message