cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Benedict (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CASSANDRA-6823) TimedOutException/dropped mutations running stress on 2.1
Date Fri, 07 Mar 2014 20:14:44 GMT

    [ https://issues.apache.org/jira/browse/CASSANDRA-6823?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13924285#comment-13924285
] 

Benedict commented on CASSANDRA-6823:
-------------------------------------

I would guess you're seeing latency spikes induced by flushing. If the "messages dropped"
are sandwiched between an "Enqueuing flush" and "Completed flushing", that's the culprit.


Does the same *new* stress not report these errors against 2.0?

> TimedOutException/dropped mutations running stress on 2.1 
> ----------------------------------------------------------
>
>                 Key: CASSANDRA-6823
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-6823
>             Project: Cassandra
>          Issue Type: Bug
>            Reporter: dan jatnieks
>            Priority: Minor
>              Labels: stress
>         Attachments: stress.log, system.log
>
>
> While testing CASSANDRA-6357, I am seeing TimedOutException errors running stress on
both 2.1 and trunk, and system log is showing dropped mutation messages.
> {noformat}
> $ ant -Dversion=2.1.0-SNAPSHOT jar
> $ ./bin/cassandra
> $ ./cassandra-2.1/tools/bin/cassandra-stress write n=10000000
> Created keyspaces. Sleeping 1s for propagation.
> Warming up WRITE with 50000 iterations...
> Connected to cluster: Test Cluster
> Datatacenter: datacenter1; Host: localhost/127.0.0.1; Rack: rack1
> Sleeping 2s...
> Running WRITE with 50 threads  for 10000000 iterations
> ops       ,    op/s,adj op/s,   key/s,    mean,     med,     .95,     .99,    .999, 
   max,   time,   stderr
> 74597     ,   74590,   74590,   74590,     0.7,     0.3,     1.7,     7.8,    39.4, 
 156.0,    1.0,  0.00000
> 175807    ,  100469,  111362,  100469,     0.5,     0.3,     1.0,     2.2,    16.4, 
 105.2,    2.0,  0.00000
> 278037    ,  100483,  110412,  100483,     0.5,     0.4,     0.9,     2.2,    15.9, 
  95.4,    3.0,  0.13983
> 366806    ,   86301,   86301,   86301,     0.6,     0.4,     0.9,     2.4,    97.6, 
 107.0,    4.1,  0.10002
> 473244    ,  105209,  115906,  105209,     0.5,     0.3,     1.0,     2.2,    10.2, 
  99.6,    5.1,  0.08246
> 574363    ,   99939,  112606,   99939,     0.5,     0.3,     1.0,     2.2,     8.4, 
 115.3,    6.1,  0.07297
> 665162    ,   89343,   89343,   89343,     0.6,     0.3,     1.1,     2.3,    12.5, 
 116.4,    7.1,  0.06256
> 768575    ,  102028,  102028,  102028,     0.5,     0.3,     1.0,     2.1,    10.7, 
 116.0,    8.1,  0.05703
> 870318    ,  100383,  112278,  100383,     0.5,     0.4,     1.0,     2.1,     8.2, 
 109.1,    9.1,  0.04984
> 972584    ,  100496,  111616,  100496,     0.5,     0.3,     1.0,     2.3,    10.3, 
 109.1,   10.1,  0.04542
> 1063466   ,   88566,   88566,   88566,     0.6,     0.3,     1.1,     2.5,   107.3, 
 116.9,   11.2,  0.04152
> 1163218   ,   98512,  107549,   98512,     0.5,     0.3,     1.2,     3.4,    17.9, 
  92.9,   12.2,  0.04007
> 1257989   ,   93578,  103808,   93578,     0.5,     0.3,     1.4,     3.8,    12.6, 
 105.6,   13.2,  0.03687
> 1349628   ,   90205,   99257,   90205,     0.6,     0.3,     1.2,     2.9,    20.3, 
  99.6,   14.2,  0.03401
> 1448125   ,   97133,  106429,   97133,     0.5,     0.3,     1.2,     2.9,    11.9, 
 102.2,   15.2,  0.03170
> 1536662   ,   87137,   95464,   87137,     0.6,     0.4,     1.1,     2.9,    83.7, 
  94.0,   16.2,  0.02964
> 1632373   ,   94446,  102735,   94446,     0.5,     0.4,     1.1,     2.6,    11.7, 
  85.5,   17.2,  0.02818
> 1717028   ,   83533,   83533,   83533,     0.6,     0.4,     1.1,     2.7,    87.4, 
 101.8,   18.3,  0.02651
> 1817081   ,   97807,  108004,   97807,     0.5,     0.3,     1.1,     2.5,    14.5, 
  99.1,   19.3,  0.02712
> 1904103   ,   85634,   94846,   85634,     0.6,     0.3,     1.2,     3.0,    92.4, 
 105.3,   20.3,  0.02585
> 2001438   ,   95991,  104822,   95991,     0.5,     0.3,     1.2,     2.7,    13.5, 
  95.3,   21.3,  0.02482
> 2086571   ,   89121,   99429,   89121,     0.6,     0.3,     1.2,     3.2,    30.9, 
 103.3,   22.3,  0.02367
> 2184096   ,   88718,   97020,   88718,     0.6,     0.3,     1.3,     3.2,    85.6, 
  98.0,   23.4,  0.02262
> 2276823   ,   91795,   91795,   91795,     0.5,     0.3,     1.3,     3.5,    81.1, 
 102.1,   24.4,  0.02174
> 2381493   ,  101074,  101074,  101074,     0.5,     0.3,     1.3,     3.3,    12.9, 
  99.1,   25.4,  0.02123
> 2466415   ,   83368,   92292,   83368,     0.6,     0.4,     1.2,     3.0,    14.3, 
 188.5,   26.4,  0.02037
> 2567406   ,  100099,  109267,  100099,     0.5,     0.3,     1.4,     3.3,    10.9, 
  94.2,   27.4,  0.01989
> 2653040   ,   84476,   91922,   84476,     0.6,     0.3,     1.4,     3.2,    77.0, 
 100.3,   28.5,  0.01937
> TimedOutException(acknowledged_by:0)
> TimedOutException(acknowledged_by:0)
> TimedOutException(acknowledged_by:0)
> TimedOutException(acknowledged_by:0)
> TimedOutException(acknowledged_by:0)
> TimedOutException(acknowledged_by:0)
> TimedOutException(acknowledged_by:0)
> TimedOutException(acknowledged_by:0)
> ...
> 9825371   ,   84636,   91716,   84636,     0.6,     0.3,     1.4,     4.5,    23.4, 
  86.4,  125.7,  0.00894
> 9915317   ,   87803,   93938,   87803,     0.6,     0.3,     1.3,     4.2,    62.4, 
  87.2,  126.7,  0.00888
> 10000000  ,   93564,  101405,   93564,     0.5,     0.3,     1.4,     4.2,    16.2, 
  83.1,  127.6,  0.00880
> Results:
> real op rate              : 78378
> adjusted op rate          : 78378
> adjusted op rate stderr   : 0
> key rate                  : 78378
> latency mean              : 0.6
> latency median            : 0.3
> latency 95th percentile   : 1.1
> latency 99th percentile   : 3.2
> latency 99.9th percentile : 20.0
> latency max               : 11141.1
> Total operation time      : 00:02:07
> END
> {noformat}
> And in from the system log:
> {noformat}
> [jenkins@blade-2-1a ~]$ grep -i "messages dropped" /var/log/cassandra/system.log
> INFO  [ScheduledTasks:1] 2014-03-07 11:35:27,872 MessagingService.java:818 - 18 MUTATION
messages dropped in last 5000ms
> INFO  [ScheduledTasks:1] 2014-03-07 11:35:53,037 MessagingService.java:818 - 18 MUTATION
messages dropped in last 5000ms
> INFO  [ScheduledTasks:1] 2014-03-07 11:36:43,210 MessagingService.java:818 - 218 MUTATION
messages dropped in last 5000ms
> {noformat}
> I am seeing the same results using {{\-mode thrift}} as well the default using the java-driver.



--
This message was sent by Atlassian JIRA
(v6.2#6252)

Mime
View raw message