[jira] [Commented] (CASSANDRA-5534) Writing wide row causes high CPU usage after compaction
[
https://issues.apache.org/jira/browse/CASSANDRA-5534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13700682#comment-13700682
]
Ryan McGuire commented on CASSANDRA-5534:
-
Alex, I think it would be useful to know what the root cause of this was, so we
can track it going forward. Running a 'git bisect' should tell us.
> Writing wide row causes high CPU usage after compaction
> ---
>
> Key: CASSANDRA-5534
> URL: https://issues.apache.org/jira/browse/CASSANDRA-5534
> Project: Cassandra
> Issue Type: Bug
>Affects Versions: 2.0 beta 1
>Reporter: Ryan McGuire
>Assignee: Sylvain Lebresne
> Fix For: 2.0
>
> Attachments: wide_row_stress.trunk.log.txt.gz
>
>
> Introduced in commit -e74c13ff08663d306dcc5cdc99c07e9e6c12ca21- (see below)
> there is a significant slow down when creating a wide row with
> cassandra-stress:
> Testing with the prior (good) commit I used this to write a single wide row,
> which completed rather quickly:
> {code}
> $ ccm create -v git:60f09f0121e0801851b9ab017eddf7e326fa05fb wide-row
> Fetching Cassandra updates...
> Cloning Cassandra (from local cache)
> Checking out requested branch (60f09f0121e0801851b9ab017eddf7e326fa05fb)
> Compiling Cassandra 60f09f0121e0801851b9ab017eddf7e326fa05fb ...
> Current cluster is now: wide-row
> $ ccm populate -n 1
> $ ccm start
> $ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency/95th/99th,elapsed_time
> 1,0,0,273.3,273.3,273.3,0
> END
> real 0m7.106s
> user 0m1.710s
> sys 0m0.120s
> {code}
> Using the bugged commit (e74c13ff08663d306dcc5cdc99c07e9e6c12ca21) I get a
> significant slow down:
> {code}
> 02:42 PM:~$ ccm create -v git:e74c13ff08663d306dcc5cdc99c07e9e6c12ca21
> wide-row
> Fetching Cassandra updates...
> Current cluster is now: wide-row
> 02:42 PM:~$ ccm populate -n 1
> 02:42 PM:~$ ccm start
> 02:42 PM:~$ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency,95th,99th,elapsed_time
> 1,0,0,423.2,423.2,423.2,0
> Total operation time : 00:00:00
> END
> real 4m16.394s
> user 0m2.230s
> sys 0m0.137s
> {code}
> Interestingly, the commit in question just says it's a merge from
> cassandra-1.2, but I do not see this same slowdown using that branch, this
> only occurs in trunk.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (CASSANDRA-5534) Writing wide row causes high CPU usage after compaction
[
https://issues.apache.org/jira/browse/CASSANDRA-5534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13700424#comment-13700424
]
Alex Zarutin commented on CASSANDRA-5534:
-
latest test on cassandra-1.2:
$> ccm create -v git:cassandra-1.2 test-1.2.6
Fetching Cassandra updates...
Cloning Cassandra (from local cache)
Checking out requested branch (cassandra-1.2)
Compiling Cassandra cassandra-1.2 ...
Current cluster is now: test-1.2.6
$> ccm populate -n 1
$> ccm start
$> time ccm node1 stress -c 1 -S 1000 -n 1
Created keyspaces. Sleeping 1s for propagation.
total,interval_op_rate,interval_key_rate,latency/95th/99th,elapsed_time
1,0,0,233.6,233.6,233.6,0
END
real0m6.539s
user0m1.714s
sys 0m0.137s
latest test on trunk:
$> ccm create -v git:trunk test-trunk
Fetching Cassandra updates...
Cloning Cassandra (from local cache)
Checking out requested branch (trunk)
Compiling Cassandra trunk ...
Current cluster is now: test-trunk
$> ccm populate -n 1
$> ccm start
$> time ccm node1 stress -c 1 -S 1000 -n 1
Created keyspaces. Sleeping 1s for propagation.
total,interval_op_rate,interval_key_rate,latency,95th,99th,elapsed_time
1,0,0,343.1,343.1,343.1,0
Total operation time : 00:00:00
END
real0m7.333s
user0m1.945s
sys 0m0.136s
> Writing wide row causes high CPU usage after compaction
> ---
>
> Key: CASSANDRA-5534
> URL: https://issues.apache.org/jira/browse/CASSANDRA-5534
> Project: Cassandra
> Issue Type: Bug
>Affects Versions: 2.0 beta 1
>Reporter: Ryan McGuire
>Assignee: Sylvain Lebresne
> Fix For: 2.0
>
> Attachments: wide_row_stress.trunk.log.txt.gz
>
>
> Introduced in commit -e74c13ff08663d306dcc5cdc99c07e9e6c12ca21- (see below)
> there is a significant slow down when creating a wide row with
> cassandra-stress:
> Testing with the prior (good) commit I used this to write a single wide row,
> which completed rather quickly:
> {code}
> $ ccm create -v git:60f09f0121e0801851b9ab017eddf7e326fa05fb wide-row
> Fetching Cassandra updates...
> Cloning Cassandra (from local cache)
> Checking out requested branch (60f09f0121e0801851b9ab017eddf7e326fa05fb)
> Compiling Cassandra 60f09f0121e0801851b9ab017eddf7e326fa05fb ...
> Current cluster is now: wide-row
> $ ccm populate -n 1
> $ ccm start
> $ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency/95th/99th,elapsed_time
> 1,0,0,273.3,273.3,273.3,0
> END
> real 0m7.106s
> user 0m1.710s
> sys 0m0.120s
> {code}
> Using the bugged commit (e74c13ff08663d306dcc5cdc99c07e9e6c12ca21) I get a
> significant slow down:
> {code}
> 02:42 PM:~$ ccm create -v git:e74c13ff08663d306dcc5cdc99c07e9e6c12ca21
> wide-row
> Fetching Cassandra updates...
> Current cluster is now: wide-row
> 02:42 PM:~$ ccm populate -n 1
> 02:42 PM:~$ ccm start
> 02:42 PM:~$ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency,95th,99th,elapsed_time
> 1,0,0,423.2,423.2,423.2,0
> Total operation time : 00:00:00
> END
> real 4m16.394s
> user 0m2.230s
> sys 0m0.137s
> {code}
> Interestingly, the commit in question just says it's a merge from
> cassandra-1.2, but I do not see this same slowdown using that branch, this
> only occurs in trunk.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (CASSANDRA-5534) Writing wide row causes high CPU usage after compaction
[
https://issues.apache.org/jira/browse/CASSANDRA-5534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13694121#comment-13694121
]
Sylvain Lebresne commented on CASSANDRA-5534:
-
Would you mind testing that again? I just tried the same test with current
trunk and it's fast (< 2s for the whole stress).
> Writing wide row causes high CPU usage after compaction
> ---
>
> Key: CASSANDRA-5534
> URL: https://issues.apache.org/jira/browse/CASSANDRA-5534
> Project: Cassandra
> Issue Type: Bug
>Affects Versions: 2.0 beta 1
>Reporter: Ryan McGuire
>Assignee: Sylvain Lebresne
> Fix For: 2.0
>
> Attachments: wide_row_stress.trunk.log.txt.gz
>
>
> Introduced in commit -e74c13ff08663d306dcc5cdc99c07e9e6c12ca21- (see below)
> there is a significant slow down when creating a wide row with
> cassandra-stress:
> Testing with the prior (good) commit I used this to write a single wide row,
> which completed rather quickly:
> {code}
> $ ccm create -v git:60f09f0121e0801851b9ab017eddf7e326fa05fb wide-row
> Fetching Cassandra updates...
> Cloning Cassandra (from local cache)
> Checking out requested branch (60f09f0121e0801851b9ab017eddf7e326fa05fb)
> Compiling Cassandra 60f09f0121e0801851b9ab017eddf7e326fa05fb ...
> Current cluster is now: wide-row
> $ ccm populate -n 1
> $ ccm start
> $ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency/95th/99th,elapsed_time
> 1,0,0,273.3,273.3,273.3,0
> END
> real 0m7.106s
> user 0m1.710s
> sys 0m0.120s
> {code}
> Using the bugged commit (e74c13ff08663d306dcc5cdc99c07e9e6c12ca21) I get a
> significant slow down:
> {code}
> 02:42 PM:~$ ccm create -v git:e74c13ff08663d306dcc5cdc99c07e9e6c12ca21
> wide-row
> Fetching Cassandra updates...
> Current cluster is now: wide-row
> 02:42 PM:~$ ccm populate -n 1
> 02:42 PM:~$ ccm start
> 02:42 PM:~$ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency,95th,99th,elapsed_time
> 1,0,0,423.2,423.2,423.2,0
> Total operation time : 00:00:00
> END
> real 4m16.394s
> user 0m2.230s
> sys 0m0.137s
> {code}
> Interestingly, the commit in question just says it's a merge from
> cassandra-1.2, but I do not see this same slowdown using that branch, this
> only occurs in trunk.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (CASSANDRA-5534) Writing wide row causes high CPU usage after compaction
[
https://issues.apache.org/jira/browse/CASSANDRA-5534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13648087#comment-13648087
]
Ryan McGuire commented on CASSANDRA-5534:
-
The bisect brought me back to a950b9257f4c92d067eb5e1d437096699123ac9b which is
from [CASSANDRA-5125|https://issues.apache.org/jira/browse/CASSANDRA-5125] -
that's the first instance where this slowdown occurs.
> Writing wide row causes high CPU usage after compaction
> ---
>
> Key: CASSANDRA-5534
> URL: https://issues.apache.org/jira/browse/CASSANDRA-5534
> Project: Cassandra
> Issue Type: Bug
>Affects Versions: 2.0
>Reporter: Ryan McGuire
>Assignee: Jonathan Ellis
> Attachments: wide_row_stress.trunk.log.txt.gz
>
>
> Introduced in commit e74c13ff08663d306dcc5cdc99c07e9e6c12ca21 there is a
> significant slow down when creating a wide row with cassandra-stress:
> Testing with the prior (good) commit I used this to write a single wide row,
> which completed rather quickly:
> {code}
> $ ccm create -v git:60f09f0121e0801851b9ab017eddf7e326fa05fb wide-row
> Fetching Cassandra updates...
> Cloning Cassandra (from local cache)
> Checking out requested branch (60f09f0121e0801851b9ab017eddf7e326fa05fb)
> Compiling Cassandra 60f09f0121e0801851b9ab017eddf7e326fa05fb ...
> Current cluster is now: wide-row
> $ ccm populate -n 1
> $ ccm start
> $ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency/95th/99th,elapsed_time
> 1,0,0,273.3,273.3,273.3,0
> END
> real 0m7.106s
> user 0m1.710s
> sys 0m0.120s
> {code}
> Using the bugged commit (e74c13ff08663d306dcc5cdc99c07e9e6c12ca21) I get a
> significant slow down:
> {code}
> 02:42 PM:~$ ccm create -v git:e74c13ff08663d306dcc5cdc99c07e9e6c12ca21
> wide-row
> Fetching Cassandra updates...
> Current cluster is now: wide-row
> 02:42 PM:~$ ccm populate -n 1
> 02:42 PM:~$ ccm start
> 02:42 PM:~$ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency,95th,99th,elapsed_time
> 1,0,0,423.2,423.2,423.2,0
> Total operation time : 00:00:00
> END
> real 4m16.394s
> user 0m2.230s
> sys 0m0.137s
> {code}
> Interestingly, the commit in question just says it's a merge from
> cassandra-1.2, but I do not see this same slowdown using that branch, this
> only occurs in trunk.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (CASSANDRA-5534) Writing wide row causes high CPU usage after compaction
[
https://issues.apache.org/jira/browse/CASSANDRA-5534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13648052#comment-13648052
]
Ryan McGuire commented on CASSANDRA-5534:
-
No, you're right. I think my git-fu was failing me, I was just going by git
log, but I think I need to do a full bisect. I'll update when I find the real
cause.
> Writing wide row causes high CPU usage after compaction
> ---
>
> Key: CASSANDRA-5534
> URL: https://issues.apache.org/jira/browse/CASSANDRA-5534
> Project: Cassandra
> Issue Type: Bug
>Affects Versions: 2.0
>Reporter: Ryan McGuire
>Assignee: Jonathan Ellis
> Attachments: wide_row_stress.trunk.log.txt.gz
>
>
> Introduced in commit e74c13ff08663d306dcc5cdc99c07e9e6c12ca21 there is a
> significant slow down when creating a wide row with cassandra-stress:
> Testing with the prior (good) commit I used this to write a single wide row,
> which completed rather quickly:
> {code}
> $ ccm create -v git:60f09f0121e0801851b9ab017eddf7e326fa05fb wide-row
> Fetching Cassandra updates...
> Cloning Cassandra (from local cache)
> Checking out requested branch (60f09f0121e0801851b9ab017eddf7e326fa05fb)
> Compiling Cassandra 60f09f0121e0801851b9ab017eddf7e326fa05fb ...
> Current cluster is now: wide-row
> $ ccm populate -n 1
> $ ccm start
> $ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency/95th/99th,elapsed_time
> 1,0,0,273.3,273.3,273.3,0
> END
> real 0m7.106s
> user 0m1.710s
> sys 0m0.120s
> {code}
> Using the bugged commit (e74c13ff08663d306dcc5cdc99c07e9e6c12ca21) I get a
> significant slow down:
> {code}
> 02:42 PM:~$ ccm create -v git:e74c13ff08663d306dcc5cdc99c07e9e6c12ca21
> wide-row
> Fetching Cassandra updates...
> Current cluster is now: wide-row
> 02:42 PM:~$ ccm populate -n 1
> 02:42 PM:~$ ccm start
> 02:42 PM:~$ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency,95th,99th,elapsed_time
> 1,0,0,423.2,423.2,423.2,0
> Total operation time : 00:00:00
> END
> real 4m16.394s
> user 0m2.230s
> sys 0m0.137s
> {code}
> Interestingly, the commit in question just says it's a merge from
> cassandra-1.2, but I do not see this same slowdown using that branch, this
> only occurs in trunk.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (CASSANDRA-5534) Writing wide row causes high CPU usage after compaction
[
https://issues.apache.org/jira/browse/CASSANDRA-5534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13647986#comment-13647986
]
Jonathan Ellis commented on CASSANDRA-5534:
---
It takes multiple minutes for me on e74c13ff08663d306dcc5cdc99c07e9e6c12ca21^
as well. Are you sure that's the problem?
> Writing wide row causes high CPU usage after compaction
> ---
>
> Key: CASSANDRA-5534
> URL: https://issues.apache.org/jira/browse/CASSANDRA-5534
> Project: Cassandra
> Issue Type: Bug
>Affects Versions: 2.0
>Reporter: Ryan McGuire
>Assignee: Jonathan Ellis
> Attachments: wide_row_stress.trunk.log.txt.gz
>
>
> Introduced in commit e74c13ff08663d306dcc5cdc99c07e9e6c12ca21 there is a
> significant slow down when creating a wide row with cassandra-stress:
> Testing with the prior (good) commit I used this to write a single wide row,
> which completed rather quickly:
> {code}
> $ ccm create -v git:60f09f0121e0801851b9ab017eddf7e326fa05fb wide-row
> Fetching Cassandra updates...
> Cloning Cassandra (from local cache)
> Checking out requested branch (60f09f0121e0801851b9ab017eddf7e326fa05fb)
> Compiling Cassandra 60f09f0121e0801851b9ab017eddf7e326fa05fb ...
> Current cluster is now: wide-row
> $ ccm populate -n 1
> $ ccm start
> $ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency/95th/99th,elapsed_time
> 1,0,0,273.3,273.3,273.3,0
> END
> real 0m7.106s
> user 0m1.710s
> sys 0m0.120s
> {code}
> Using the bugged commit (e74c13ff08663d306dcc5cdc99c07e9e6c12ca21) I get a
> significant slow down:
> {code}
> 02:42 PM:~$ ccm create -v git:e74c13ff08663d306dcc5cdc99c07e9e6c12ca21
> wide-row
> Fetching Cassandra updates...
> Current cluster is now: wide-row
> 02:42 PM:~$ ccm populate -n 1
> 02:42 PM:~$ ccm start
> 02:42 PM:~$ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency,95th,99th,elapsed_time
> 1,0,0,423.2,423.2,423.2,0
> Total operation time : 00:00:00
> END
> real 4m16.394s
> user 0m2.230s
> sys 0m0.137s
> {code}
> Interestingly, the commit in question just says it's a merge from
> cassandra-1.2, but I do not see this same slowdown using that branch, this
> only occurs in trunk.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (CASSANDRA-5534) Writing wide row causes high CPU usage after compaction
[
https://issues.apache.org/jira/browse/CASSANDRA-5534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13647815#comment-13647815
]
Ryan McGuire commented on CASSANDRA-5534:
-
The reason I titled this bug with the phrase "after compaction" is that the
very last line of the log file that talked about copaction is what it stayed on
for the majority of that 4 minutes that it ran for. I don't have any other
clues that this is related to compaction.
> Writing wide row causes high CPU usage after compaction
> ---
>
> Key: CASSANDRA-5534
> URL: https://issues.apache.org/jira/browse/CASSANDRA-5534
> Project: Cassandra
> Issue Type: Bug
>Affects Versions: 2.0
>Reporter: Ryan McGuire
>Assignee: Jonathan Ellis
> Attachments: wide_row_stress.trunk.log.txt.gz
>
>
> Introduced in commit e74c13ff08663d306dcc5cdc99c07e9e6c12ca21 there is a
> significant slow down when creating a wide row with cassandra-stress:
> Testing with the prior (good) commit I used this to write a single wide row,
> which completed rather quickly:
> {code}
> $ ccm create -v git:60f09f0121e0801851b9ab017eddf7e326fa05fb wide-row
> Fetching Cassandra updates...
> Cloning Cassandra (from local cache)
> Checking out requested branch (60f09f0121e0801851b9ab017eddf7e326fa05fb)
> Compiling Cassandra 60f09f0121e0801851b9ab017eddf7e326fa05fb ...
> Current cluster is now: wide-row
> $ ccm populate -n 1
> $ ccm start
> $ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency/95th/99th,elapsed_time
> 1,0,0,273.3,273.3,273.3,0
> END
> real 0m7.106s
> user 0m1.710s
> sys 0m0.120s
> {code}
> Using the bugged commit (e74c13ff08663d306dcc5cdc99c07e9e6c12ca21) I get a
> significant slow down:
> {code}
> 02:42 PM:~$ ccm create -v git:e74c13ff08663d306dcc5cdc99c07e9e6c12ca21
> wide-row
> Fetching Cassandra updates...
> Current cluster is now: wide-row
> 02:42 PM:~$ ccm populate -n 1
> 02:42 PM:~$ ccm start
> 02:42 PM:~$ time ccm node1 stress -c 1 -S 1000 -n 1
> Created keyspaces. Sleeping 1s for propagation.
> total,interval_op_rate,interval_key_rate,latency,95th,99th,elapsed_time
> 1,0,0,423.2,423.2,423.2,0
> Total operation time : 00:00:00
> END
> real 4m16.394s
> user 0m2.230s
> sys 0m0.137s
> {code}
> Interestingly, the commit in question just says it's a merge from
> cassandra-1.2, but I do not see this same slowdown using that branch, this
> only occurs in trunk.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
