[
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)
