cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Corentin Chary (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CASSANDRA-13031) Speed-up start-up sequence by avoiding un-needed flushes
Date Thu, 05 Jan 2017 07:23:59 GMT

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

Corentin Chary commented on CASSANDRA-13031:
--------------------------------------------

I won't have access to the HDD machine until next week (the one where forceBlockingFlush takes
>500ms). Here are the results on another machine with an SSD:

{code}
rm logs/*; ./bin/nodetool stopdaemon ; ./bin/cassandra ; sleep 1; grep took logs/system.log



debug = false, ssd, only basic keyspaces, one peer

run-1
INFO  [main] 2017-01-05 08:14:06,341 SystemKeyspace.java:858 - forceblockingFlush local took
213 
INFO  [main] 2017-01-05 08:14:06,743 Server.java:158 - Startup took 6.609

run-2
INFO  [main] 2017-01-05 08:11:27,624 SystemKeyspace.java:858 - forceblockingFlush local took
288 
INFO  [main] 2017-01-05 08:11:27,905 Server.java:158 - Startup took 6.662


debug = true, ssd, only basic keyspaces, one peer

run-1
INFO  [main] 2017-01-05 08:06:38,232 SystemKeyspace.java:858 - forceblockingFlush local took
285 
INFO  [main] 2017-01-05 08:06:38,395 SystemKeyspace.java:858 - forceblockingFlush local took
116 
INFO  [main] 2017-01-05 08:06:38,531 SystemKeyspace.java:858 - forceblockingFlush local took
130 
INFO  [main] 2017-01-05 08:06:38,630 SystemKeyspace.java:858 - forceblockingFlush local took
95 
INFO  [main] 2017-01-05 08:06:38,816 SystemKeyspace.java:858 - forceblockingFlush local took
181 
INFO  [main] 2017-01-05 08:06:38,959 SystemKeyspace.java:858 - forceblockingFlush local took
136 
INFO  [main] 2017-01-05 08:06:39,234 SystemKeyspace.java:858 - forceblockingFlush local took
188 
INFO  [main] 2017-01-05 08:06:40,350 SystemKeyspace.java:858 - forceblockingFlush local took
210 
INFO  [main] 2017-01-05 08:06:40,732 SystemKeyspace.java:858 - forceblockingFlush local took
227 
INFO  [main] 2017-01-05 08:06:40,732 SystemKeyspace.java:1087 - setBootstrapState took 228
INFO  [main] 2017-01-05 08:06:41,012 SystemKeyspace.java:858 - forceblockingFlush local took
253 
INFO  [main] 2017-01-05 08:06:41,012 SystemKeyspace.java:850 - updateTokens took 266
INFO  [main] 2017-01-05 08:06:41,138 Server.java:158 - Startup took 7.616

run-2
INFO  [main] 2017-01-05 08:07:20,579 SystemKeyspace.java:858 - forceblockingFlush local took
286 
INFO  [main] 2017-01-05 08:07:20,753 SystemKeyspace.java:858 - forceblockingFlush local took
153 
INFO  [main] 2017-01-05 08:07:20,962 SystemKeyspace.java:858 - forceblockingFlush local took
203 
INFO  [main] 2017-01-05 08:07:21,199 SystemKeyspace.java:858 - forceblockingFlush local took
196 
INFO  [main] 2017-01-05 08:07:21,384 SystemKeyspace.java:858 - forceblockingFlush local took
181 
INFO  [main] 2017-01-05 08:07:21,593 SystemKeyspace.java:858 - forceblockingFlush local took
193 
INFO  [main] 2017-01-05 08:07:21,768 SystemKeyspace.java:858 - forceblockingFlush local took
172 
INFO  [main] 2017-01-05 08:07:22,726 SystemKeyspace.java:858 - forceblockingFlush local took
189 
INFO  [main] 2017-01-05 08:07:23,058 SystemKeyspace.java:858 - forceblockingFlush local took
178 
INFO  [main] 2017-01-05 08:07:23,058 SystemKeyspace.java:1087 - setBootstrapState took 179
INFO  [main] 2017-01-05 08:07:23,255 SystemKeyspace.java:858 - forceblockingFlush local took
185 
INFO  [main] 2017-01-05 08:07:23,255 SystemKeyspace.java:850 - updateTokens took 189
INFO  [main] 2017-01-05 08:07:23,438 Server.java:158 - Startup took 7.773



---
Creating views:

debug = false
INFO  [CompactionExecutor:3] 2017-01-05 08:16:30,015 SystemKeyspace.java:858 - forceblockingFlush
built_views took 178 
INFO  [CompactionExecutor:3] 2017-01-05 08:16:30,015 SystemKeyspace.java:591 - setViewBuilt
took 181
INFO  [CompactionExecutor:3] 2017-01-05 08:16:30,202 SystemKeyspace.java:858 - forceblockingFlush
views_builds_in_progress took 185 
INFO  [CompactionExecutor:3] 2017-01-05 08:16:30,202 SystemKeyspace.java:626 - finishViewBuildStatus
took 368
INFO  [CompactionExecutor:3] 2017-01-05 08:16:30,335 SystemKeyspace.java:858 - forceblockingFlush
built_views took 129 
INFO  [CompactionExecutor:3] 2017-01-05 08:16:30,335 SystemKeyspace.java:591 - setViewBuilt
took 131
INFO  [CompactionExecutor:4] 2017-01-05 08:16:34,012 SystemKeyspace.java:858 - forceblockingFlush
built_views took 211 
INFO  [CompactionExecutor:4] 2017-01-05 08:16:34,012 SystemKeyspace.java:591 - setViewBuilt
took 215
INFO  [CompactionExecutor:4] 2017-01-05 08:16:34,187 SystemKeyspace.java:858 - forceblockingFlush
views_builds_in_progress took 174 
INFO  [CompactionExecutor:4] 2017-01-05 08:16:34,187 SystemKeyspace.java:626 - finishViewBuildStatus
took 390
INFO  [CompactionExecutor:4] 2017-01-05 08:16:34,369 SystemKeyspace.java:858 - forceblockingFlush
built_views took 179 
INFO  [CompactionExecutor:4] 2017-01-05 08:16:34,370 SystemKeyspace.java:591 - setViewBuilt
took 180

debug = true
INFO  [CompactionExecutor:4] 2017-01-05 08:04:55,486 SystemKeyspace.java:858 - forceblockingFlush
built_views took 159 
INFO  [CompactionExecutor:4] 2017-01-05 08:04:55,487 SystemKeyspace.java:591 - setViewBuilt
took 161
INFO  [CompactionExecutor:4] 2017-01-05 08:04:55,600 SystemKeyspace.java:858 - forceblockingFlush
views_builds_in_progress took 112 
INFO  [CompactionExecutor:4] 2017-01-05 08:04:55,601 SystemKeyspace.java:626 - finishViewBuildStatus
took 275
INFO  [CompactionExecutor:4] 2017-01-05 08:04:55,818 SystemKeyspace.java:858 - forceblockingFlush
built_views took 214 
INFO  [CompactionExecutor:4] 2017-01-05 08:04:55,819 SystemKeyspace.java:591 - setViewBuilt
took 215
INFO  [CompactionExecutor:4] 2017-01-05 08:05:01,087 SystemKeyspace.java:858 - forceblockingFlush
built_views took 169 
INFO  [CompactionExecutor:4] 2017-01-05 08:05:01,087 SystemKeyspace.java:591 - setViewBuilt
took 171
INFO  [CompactionExecutor:4] 2017-01-05 08:05:01,245 SystemKeyspace.java:858 - forceblockingFlush
views_builds_in_progress took 157 
INFO  [CompactionExecutor:4] 2017-01-05 08:05:01,245 SystemKeyspace.java:626 - finishViewBuildStatus
took 329
INFO  [CompactionExecutor:4] 2017-01-05 08:05:01,416 SystemKeyspace.java:858 - forceblockingFlush
built_views took 168 
INFO  [CompactionExecutor:4] 2017-01-05 08:05:01,416 SystemKeyspace.java:591 - setViewBuilt
took 169


{code}

As expected forceBlockingFlush in SystemKeyspace.java is called way less with debug = false.

It also doesn't seem to have any negative effect when creating views, which is expected because
reading something that's likely in the buffer cache will always be multiple order of magnitude
faster than flushing/fsyncing.
 

> Speed-up start-up sequence by avoiding un-needed flushes
> --------------------------------------------------------
>
>                 Key: CASSANDRA-13031
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-13031
>             Project: Cassandra
>          Issue Type: Bug
>            Reporter: Corentin Chary
>            Assignee: Corentin Chary
>            Priority: Minor
>             Fix For: 3.x
>
>         Attachments: 0001-Avoid-un-needed-system-flushes-on-startup.patch, debug-fast.log,
debug.log, debug_130131.diff, debug_130131_2.diff
>
>
> Similar to CASSANDRA-12969, do a conditional update for all functions
>     with a forced blocking flush to avoid slowed-down boot sequences. The
>     small performance hit of doing a read is always smaller than the one
>     associated with a fsync().



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message