incubator-cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Alain RODRIGUEZ <arodr...@gmail.com>
Subject High disk read throughput on only one node.
Date Tue, 18 Dec 2012 17:26:49 GMT
Hi,

I am experimenting a strange issue in my C* 1.1.6, 3 node, RF=3 cluster.

root@ip-10-64-177-38:~# nodetool ring
Note: Ownership information does not include topology, please specify a
keyspace.
Address         DC          Rack        Status State   Load            Owns
               Token

               141784319550391032739561396922763706368
10.64.167.32    eu-west     1b          Up     Normal  178.37 GB
33.33%              28356863910078203714492389662765613056
10.250.202.154  eu-west     1b          Up     Normal  174.93 GB
33.33%              85070591730234615865843651857942052863
10.64.177.38    eu-west     1b          Up     Normal  167.13 GB
33.33%              141784319550391032739561396922763706368

root@ip-10-64-177-38:~# nodetool ring cassa_teads
Address         DC          Rack        Status State   Load
 Effective-Ownership Token

               141784319550391032739561396922763706368
10.64.167.32    eu-west     1b          Up     Normal  178.37 GB
100.00%             28356863910078203714492389662765613056
10.250.202.154  eu-west     1b          Up     Normal  174.93 GB
100.00%             85070591730234615865843651857942052863
10.64.177.38    eu-west     1b          Up     Normal  167.13 GB
100.00%             141784319550391032739561396922763706368

My cluster is well balanced, all the nodes have an identical configuration,
but yet I have a lot of disk reads on one of them as you can see in these
screenshots:

Datastax OpsCenter :
http://img4.imageshack.us/img4/2528/datastaxopscenterheighr.png
or
AWS console : http://img59.imageshack.us/img59/5223/ec2managementconsole.png

I have tried to see what is read from any nodes with "inotifywatch -r -t300
/raid0 > inotifywatch5min" and get the following result:

root@ip-10-64-177-38:~# cat inotifywatch5min
total       access  close_nowrite  open      filename
234580   113280  60691             60609
 /raid0/cassandra/data/cassa_teads/data_viewer/
56013      27108   14454            14451
/raid0/cassandra/data/cassa_teads/data_ip_viewer/
30748      14998   7884              7866
 /raid0/cassandra/data/cassa_teads/algo_ad_newcapping/
301          147      76                  78
/raid0/cassandra/data/cassa_teads/data_transac/
191           95       48                  48
   /raid0/cassandra/data/cassa_teads/data_cust_website_viewer/
6               0        3                    3           /raid0/cassandra/
2               0        1                    1
  /raid0/cassandra/data/
2               0        1                    1
  /raid0/cassandra/commitlog/
2               0        1                    1
  /raid0/cassandra/saved_caches/


root@ip-10-250-202-154:~# cat inotifywatch5min
total       access  modify  close_write  close_nowrite  open  moved_from
 moved_to  create  delete  filename
307378  115456  77706   12                57119             57035
 /raid0/cassandra/data/cassa_teads/data_viewer/
55395    26878   0           0                 14259             14258
  /raid0/cassandra/data/cassa_teads/data_ip_viewer/
36155    17653   0           0                 9256               9246
   /raid0/cassandra/data/cassa_teads/algo_ad_newcapping/
7377      188      7153      6                 4                    11
      /raid0/cassandra/data/cassa_teads/data_action/
401        0         364        6                 4                    12
        /raid0/cassandra/data/cassa_teads/stats_ad_uv/
244        120      0           0                 62                   62
       /raid0/cassandra/data/cassa_teads/data_transac/
160        76        0           0                 42                   42
        /raid0/cassandra/data/cassa_teads/data_cust_website_viewer/
26          0         0           0                 13                   13
         /raid0/cassandra/data/cassa_teads/
12          0         2           2                 1                     3
          /raid0/cassandra/commitlog/
6            0         0           0                 3
 3          /raid0/cassandra/
2            0         0           0                 1
 1          /raid0/cassandra/data/
2            0         0           0                 1
 1          /raid0/cassandra/saved_caches/


root@ip-10-64-167-32:~# cat inotifywatch5min
total       access  modify  close_write  close_nowrite  open    filename
218489   105379  0            0                  56615         56495
 /raid0/cassandra/data/cassa_teads/data_viewer/
61553     29733   0             0                  15911        15909
 /raid0/cassandra/data/cassa_teads/data_ip_viewer/
33262     16214   0             0                  8528          8520
 /raid0/cassandra/data/cassa_teads/algo_ad_newcapping/
407         0         370          6                  4               12
     /raid0/cassandra/data/cassa_teads/stats_ad_uv/
280         134      0             0                  73              73
    /raid0/cassandra/data/cassa_teads/data_transac/
163          79       0             0                  42              42
    /raid0/cassandra/data/cassa_teads/data_cust_website_viewer/
17            0        3             3                  1                 4
       /raid0/cassandra/commitlog/
8             0        0              0                  4
4        /raid0/cassandra/data/cassa_teads/
6             0        0              0                  3
3        /raid0/cassandra/
2             0        0              0                  1
1        /raid0/cassandra/data/
2             0        0              0                  1
1        /raid0/cassandra/saved_caches/

I see no reason to have a md0 disk read throughput up to 8 time bigger on
the .38 node...

root@ip-10-64-167-32:~# iostat -mx 5 100

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz
avgqu-sz   await  svctm  %util
xvdap1            0.00     0.40    0.20    0.40     0.00     0.00    18.67
    0.00    6.67   6.67   0.40
xvdb              3.60     0.00  471.60    0.00    13.48     0.00    58.53
   33.31   69.58   1.79  84.20
xvdc              3.40     0.00  474.40    0.00    13.76     0.00    59.42
   30.06   62.63   1.72  81.60
xvdd              2.60     0.00  478.20    0.00    13.69     0.00    58.61
   28.74   61.74   1.76  84.40
xvde              3.40     0.00  472.40    0.00    13.34     0.00    57.82
   23.08   47.96   1.74  82.40
md0               0.00     0.00 1954.20    0.00    55.57     0.00    58.24
    0.00    0.00   0.00   0.00

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          11.95   11.88   11.54   48.33    0.20   16.10

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz
avgqu-sz   await  svctm  %util
xvdap1            0.00     2.40    0.40    1.00     0.00     0.01    25.14
    0.15  110.00  55.71   7.80
xvdb              3.40     0.00  481.60   63.20    13.94     2.59    62.13
   33.79   62.86   1.56  84.80
xvdc              3.60     0.00  469.20   64.40    13.43     2.68    61.81
   40.35   76.23   1.54  82.40
xvdd              6.60     0.20  480.80   64.40    13.93     2.65    62.28
   45.99   84.72   1.63  88.60
xvde              6.60     0.00  482.00   65.60    14.20     2.68    63.14
   48.76   89.77   1.61  88.00
md0               0.00     0.00 1910.80  257.80    54.92    10.60    61.88
    0.00    0.00   0.00   0.00

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          12.41   12.82   10.93   36.15    0.21   27.48

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz
avgqu-sz   await  svctm  %util
xvdap1            0.00     0.60    2.40    0.60     0.03     0.00    23.47
    0.18   58.67  24.67   7.40
xvdb              3.80     0.00  429.20    4.80    12.41     0.20    59.48
   16.44   37.94   1.70  73.80
xvdc              3.00     0.00  432.60    4.80    12.47     0.20    59.33
   20.74   47.44   1.71  75.00
xvdd              2.20     0.00  439.60    4.80    12.56     0.20    58.80
   17.57   39.44   1.78  79.20
xvde              2.00     0.00  449.20    3.60    12.84     0.15    58.73
   15.96   35.29   1.68  76.00
md0               0.00     0.00 1744.40   18.00    49.63     0.75    58.55
    0.00    0.00   0.00   0.00

Did anyone experiments something similar ?

How can I dig further to see what is wrong ?

Any idea on what on C* can be responsible of this king of targeted reads ?

Alain

Mime
View raw message