incubator-cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ilya Kirnos <i...@cardspring.com>
Subject Request trace question
Date Tue, 26 Feb 2013 00:33:08 GMT
Here's a sample request trace (Cassandra 1.2.1), where there's a gap of
almost 60ms between one of the two local quorum nodes receiving a message
and the row cache getting hit.  There's then a further almost 60ms delay
between the response enqueue and the actual send. Please see 54.234.178.159 in
the trace below.  My question is what (besides GC pauses) could be causing
this?  There was no load on the nodes during this request.

Thanks.

tracing on;
CONSISTENCY LOCAL_QUORUM;
select * from "Account" where key = 'AXNB7rW9q7l4dqOT4gNkcwfU767fcFtW';

Now tracing requests.
Consistency level set to LOCAL_QUORUM.

 key                              | name
----------------------------------+--------------
 AXNB7rW9q7l4dqOT4gNkcwfU767fcFtW | juicy


Tracing session: 47aaf840-7fa3-11e2-98e2-bbb3d297e375

 activity                                 | timestamp    | source         |
source_elapsed
------------------------------------------+--------------+----------------+----------------
                       execute_cql3_query | 23:30:03,354 |   107.20.35.23 |
             0
                        Parsing statement | 23:30:03,354 |   107.20.35.23 |
            40
                       Peparing statement | 23:30:03,354 |   107.20.35.23 |
           190
         Sending message to /10.87.26.112 | 23:30:03,354 |   107.20.35.23 |
           435
          Sending message to /10.35.85.85 | 23:30:03,354 |   107.20.35.23 |
           571
      Message received from /23.22.38.255 | 23:30:03,356 |   107.20.35.23 |
          2754
   Processing response from /23.22.38.255 | 23:30:03,356 |   107.20.35.23 |
          2862
      Message received from /107.20.35.23 | 23:30:03,356 |   23.22.38.255 |
            44
                            Row cache hit | 23:30:03,356 |   23.22.38.255 |
           203
      Enqueuing response to /107.20.35.23 | 23:30:03,356 |   23.22.38.255 |
           281
         Sending message to /10.169.19.28 | 23:30:03,356 |   23.22.38.255 |
           384
      Message received from /107.20.35.23 | 23:30:03,356 | 54.234.178.159 |
            20
                            Row cache hit | 23:30:03,415 | 54.234.178.159 |
         59441
      Enqueuing response to /107.20.35.23 | 23:30:03,415 | 54.234.178.159 |
         59554
         Sending message to /10.169.19.28 | 23:30:03,475 | 54.234.178.159 |
        119282
    Message received from /54.234.178.159 | 23:30:03,476 |   107.20.35.23 |
        122085
 Processing response from /54.234.178.159 | 23:30:03,476 |   107.20.35.23 |
        122226
                         Request complete | 23:30:03,476 |   107.20.35.23 |
        122399

EC2 IP mapping:
10.35.85.85 = 54.234.178.159
10.87.26.112 = 23.22.38.255

-- 
-ilya

Mime
View raw message