Open hshankar opened 5 years ago
I cannot reproduce it. Can you attach the LOG file?
LOG:
2018/11/30-06:19:07.228147 7f36ec3f0700 RocksDB version: 5.15.10 2018/11/30-06:19:07.228826 7f36ec3f0700 Git sha rocksdb_build_git_sha: 2018/11/30-06:19:07.228830 7f36ec3f0700 Compile date Oct 9 2018 2018/11/30-06:19:07.229044 7f36ec3f0700 DB SUMMARY 2018/11/30-06:19:07.232671 7f36ec3f0700 CURRENT file: CURRENT 2018/11/30-06:19:07.232676 7f36ec3f0700 IDENTITY file: IDENTITY 2018/11/30-06:19:07.232683 7f36ec3f0700 MANIFEST file: MANIFEST-077374 size: 807643 Bytes 2018/11/30-06:19:07.232686 7f36ec3f0700 SST files in $DATADIR dir, Total Num: 427, files: 022266.sst 022267.sst 022268.sst 022269.sst 022270.sst 022271.sst 022272.sst 022273.sst 022274.sst 2018/11/30-06:19:07.232689 7f36ec3f0700 Write Ahead Log file in $DATADIR: 077729.log size: 3357401 ; 2018/11/30-06:19:07.232709 7f36ec3f0700 Options.error_if_exists: 0 2018/11/30-06:19:07.232909 7f36ec3f0700 Options.create_if_missing: 1 2018/11/30-06:19:07.232911 7f36ec3f0700 Options.paranoid_checks: 1 2018/11/30-06:19:07.232915 7f36ec3f0700 Options.env: 0x7f35c1ad6100 2018/11/30-06:19:07.232916 7f36ec3f0700 Options.info_log: 0x7f367c16f670 2018/11/30-06:19:07.232919 7f36ec3f0700 Options.max_file_opening_threads: 16 2018/11/30-06:19:07.232928 7f36ec3f0700 Options.statistics: 0x7f367c002cd0 2018/11/30-06:19:07.232937 7f36ec3f0700 Options.use_fsync: 0 2018/11/30-06:19:07.232940 7f36ec3f0700 Options.max_log_file_size: 0 2018/11/30-06:19:07.232941 7f36ec3f0700 Options.max_manifest_file_size: 1073741824 2018/11/30-06:19:07.232944 7f36ec3f0700 Options.log_file_time_to_roll: 0 2018/11/30-06:19:07.232962 7f36ec3f0700 Options.keep_log_file_num: 5 2018/11/30-06:19:07.232963 7f36ec3f0700 Options.recycle_log_file_num: 0 2018/11/30-06:19:07.232965 7f36ec3f0700 Options.allow_fallocate: 1 2018/11/30-06:19:07.232967 7f36ec3f0700 Options.allow_mmap_reads: 0 2018/11/30-06:19:07.232969 7f36ec3f0700 Options.allow_mmap_writes: 0 2018/11/30-06:19:07.232985 7f36ec3f0700 Options.use_direct_reads: 0 2018/11/30-06:19:07.232993 7f36ec3f0700 Options.use_direct_io_for_flush_and_compaction: 0 2018/11/30-06:19:07.232999 7f36ec3f0700 Options.create_missing_column_families: 0 2018/11/30-06:19:07.233001 7f36ec3f0700 Options.db_log_dir: 2018/11/30-06:19:07.233009 7f36ec3f0700 Options.wal_dir: $DATADIR 2018/11/30-06:19:07.233016 7f36ec3f0700 Options.table_cache_numshardbits: 6 2018/11/30-06:19:07.233017 7f36ec3f0700 Options.max_subcompactions: 1 2018/11/30-06:19:07.233019 7f36ec3f0700 Options.max_background_flushes: -1 2018/11/30-06:19:07.233027 7f36ec3f0700 Options.WAL_ttl_seconds: 0 2018/11/30-06:19:07.233041 7f36ec3f0700 Options.WAL_size_limit_MB: 0 2018/11/30-06:19:07.233048 7f36ec3f0700 Options.manifest_preallocation_size: 4194304 2018/11/30-06:19:07.233055 7f36ec3f0700 Options.is_fd_close_on_exec: 1 2018/11/30-06:19:07.233071 7f36ec3f0700 Options.advise_random_on_open: 1 2018/11/30-06:19:07.233074 7f36ec3f0700 Options.db_write_buffer_size: 0 2018/11/30-06:19:07.233075 7f36ec3f0700 Options.write_buffer_manager: 0x7f367c002960 2018/11/30-06:19:07.233076 7f36ec3f0700 Options.access_hint_on_compaction_start: 1 2018/11/30-06:19:07.233082 7f36ec3f0700 Options.new_table_reader_for_compaction_inputs: 0 2018/11/30-06:19:07.233084 7f36ec3f0700 Options.random_access_max_buffer_size: 1048576 2018/11/30-06:19:07.233086 7f36ec3f0700 Options.use_adaptive_mutex: 0 2018/11/30-06:19:07.233087 7f36ec3f0700 Options.rate_limiter: (nil) 2018/11/30-06:19:07.233101 7f36ec3f0700 Options.sst_file_manager.rate_bytes_per_sec: 0 2018/11/30-06:19:07.233105 7f36ec3f0700 Options.wal_recovery_mode: 2 2018/11/30-06:19:07.233107 7f36ec3f0700 Options.enable_thread_tracking: 0 2018/11/30-06:19:07.233108 7f36ec3f0700 Options.enable_pipelined_write: 0 2018/11/30-06:19:07.233110 7f36ec3f0700 Options.allow_concurrent_memtable_write: 1 2018/11/30-06:19:07.233113 7f36ec3f0700 Options.enable_write_thread_adaptive_yield: 1 2018/11/30-06:19:07.233114 7f36ec3f0700 Options.write_thread_max_yield_usec: 100 2018/11/30-06:19:07.233121 7f36ec3f0700 Options.write_thread_slow_yield_usec: 3 2018/11/30-06:19:07.233125 7f36ec3f0700 Options.row_cache: None 2018/11/30-06:19:07.233130 7f36ec3f0700 Options.wal_filter: None 2018/11/30-06:19:07.233131 7f36ec3f0700 Options.avoid_flush_during_recovery: 0 2018/11/30-06:19:07.233133 7f36ec3f0700 Options.allow_ingest_behind: 0 2018/11/30-06:19:07.233139 7f36ec3f0700 Options.preserve_deletes: 0 2018/11/30-06:19:07.233143 7f36ec3f0700 Options.two_write_queues: 0 2018/11/30-06:19:07.233144 7f36ec3f0700 Options.manual_wal_flush: 0 2018/11/30-06:19:07.233146 7f36ec3f0700 Options.max_background_jobs: 2 2018/11/30-06:19:07.233147 7f36ec3f0700 Options.max_background_compactions: 5 2018/11/30-06:19:07.233149 7f36ec3f0700 Options.avoid_flush_during_shutdown: 0 2018/11/30-06:19:07.233158 7f36ec3f0700 Options.writable_file_max_buffer_size: 1048576 2018/11/30-06:19:07.233160 7f36ec3f0700 Options.delayed_write_rate : 16777216 2018/11/30-06:19:07.233161 7f36ec3f0700 Options.max_total_wal_size: 0 2018/11/30-06:19:07.233163 7f36ec3f0700 Options.delete_obsolete_files_period_micros: 21600000000 2018/11/30-06:19:07.233165 7f36ec3f0700 Options.stats_dump_period_sec: 600 2018/11/30-06:19:07.233177 7f36ec3f0700 Options.max_open_files: -1 2018/11/30-06:19:07.233183 7f36ec3f0700 Options.bytes_per_sync: 0 2018/11/30-06:19:07.233184 7f36ec3f0700 Options.wal_bytes_per_sync: 0 2018/11/30-06:19:07.233200 7f36ec3f0700 Options.compaction_readahead_size: 0 2018/11/30-06:19:07.233207 7f36ec3f0700 Compression algorithms supported: 2018/11/30-06:19:07.233209 7f36ec3f0700 kZSTDNotFinalCompression supported: 1 2018/11/30-06:19:07.233210 7f36ec3f0700 kZSTD supported: 1 2018/11/30-06:19:07.233212 7f36ec3f0700 kXpressCompression supported: 0 2018/11/30-06:19:07.233217 7f36ec3f0700 kLZ4HCCompression supported: 1 2018/11/30-06:19:07.233222 7f36ec3f0700 kLZ4Compression supported: 1 2018/11/30-06:19:07.233225 7f36ec3f0700 kBZip2Compression supported: 1 2018/11/30-06:19:07.233227 7f36ec3f0700 kZlibCompression supported: 1 2018/11/30-06:19:07.233228 7f36ec3f0700 kSnappyCompression supported: 1 2018/11/30-06:19:07.233232 7f36ec3f0700 Fast CRC32 supported: Not supported on x86 2018/11/30-06:19:07.239526 7f36ec3f0700 [db/version_set.cc:3248] Recovering from manifest file: MANIFEST-077374 2018/11/30-06:19:07.246192 7f36ec3f0700 [db/column_family.cc:475] --------------- Options for column family [default]: 2018/11/30-06:19:07.246196 7f36ec3f0700 Options.comparator: leveldb.BytewiseComparator 2018/11/30-06:19:07.246197 7f36ec3f0700 Options.merge_operator: None 2018/11/30-06:19:07.246269 7f36ec3f0700 Options.compaction_filter: None 2018/11/30-06:19:07.246270 7f36ec3f0700 Options.compaction_filter_factory: None 2018/11/30-06:19:07.246271 7f36ec3f0700 Options.memtable_factory: SkipListFactory 2018/11/30-06:19:07.246273 7f36ec3f0700 Options.table_factory: BlockBasedTable 2018/11/30-06:19:07.247628 7f36ec3f0700 table_factory options: flush_block_policy_factory: FlushBlockBySizePolicyFactory (0x7f367c16f6d0) cache_index_and_filter_blocks: 0 cache_index_and_filter_blocks_with_high_priority: 0 pin_l0_filter_and_index_blocks_in_cache: 0 pin_top_level_index_and_filter: 1 index_type: 0 hash_index_allow_collision: 1 checksum: 1 no_block_cache: 0 block_cache: 0x7f367c174f80 block_cache_name: LRUCache block_cache_options: capacity : 524288 num_shard_bits : 0 strict_capacity_limit : 0 high_pri_pool_ratio: 0.000 block_cache_compressed: (nil) persistent_cache: (nil) block_size: 4096 block_size_deviation: 10 block_restart_interval: 16 index_block_restart_interval: 1 metadata_block_size: 4096 partition_filters: 0 use_delta_encoding: 1 filter_policy: rocksdb.BuiltinBloomFilter whole_key_filtering: 1 verify_compression: 0 read_amp_bytes_per_bit: 0 format_version: 0 enable_index_compression: 1 block_align: 0 2018/11/30-06:19:07.247643 7f36ec3f0700 Options.write_buffer_size: 8388608 2018/11/30-06:19:07.247644 7f36ec3f0700 Options.max_write_buffer_number: 3 2018/11/30-06:19:07.247656 7f36ec3f0700 Options.compression: Snappy 2018/11/30-06:19:07.247659 7f36ec3f0700 Options.bottommost_compression: Disabled 2018/11/30-06:19:07.247669 7f36ec3f0700 Options.prefix_extractor: rocksdb.FixedPrefix.456 2018/11/30-06:19:07.247672 7f36ec3f0700 Options.memtable_insert_with_hint_prefix_extractor: nullptr 2018/11/30-06:19:07.247681 7f36ec3f0700 Options.num_levels: 7 2018/11/30-06:19:07.247682 7f36ec3f0700 Options.min_write_buffer_number_to_merge: 1 2018/11/30-06:19:07.247684 7f36ec3f0700 Options.max_write_buffer_number_to_maintain: 0 2018/11/30-06:19:07.247685 7f36ec3f0700 Options.bottommost_compression_opts.window_bits: -14 2018/11/30-06:19:07.247690 7f36ec3f0700 Options.bottommost_compression_opts.level: 32767 2018/11/30-06:19:07.247693 7f36ec3f0700 Options.bottommost_compression_opts.strategy: 0 2018/11/30-06:19:07.247700 7f36ec3f0700 Options.bottommost_compression_opts.max_dict_bytes: 0 2018/11/30-06:19:07.247702 7f36ec3f0700 Options.bottommost_compression_opts.zstd_max_train_bytes: 0 2018/11/30-06:19:07.247704 7f36ec3f0700 Options.bottommost_compression_opts.enabled: false 2018/11/30-06:19:07.247706 7f36ec3f0700 Options.compression_opts.window_bits: -14 2018/11/30-06:19:07.247712 7f36ec3f0700 Options.compression_opts.level: 32767 2018/11/30-06:19:07.247713 7f36ec3f0700 Options.compression_opts.strategy: 0 2018/11/30-06:19:07.247714 7f36ec3f0700 Options.compression_opts.max_dict_bytes: 0 2018/11/30-06:19:07.247732 7f36ec3f0700 Options.compression_opts.zstd_max_train_bytes: 0 2018/11/30-06:19:07.247744 7f36ec3f0700 Options.compression_opts.enabled: false 2018/11/30-06:19:07.247759 7f36ec3f0700 Options.level0_file_num_compaction_trigger: 4 2018/11/30-06:19:07.247777 7f36ec3f0700 Options.level0_slowdown_writes_trigger: 20 2018/11/30-06:19:07.248122 7f36ec3f0700 Options.level0_stop_writes_trigger: 36 2018/11/30-06:19:07.248162 7f36ec3f0700 Options.target_file_size_base: 104857600 2018/11/30-06:19:07.248164 7f36ec3f0700 Options.target_file_size_multiplier: 1 2018/11/30-06:19:07.248165 7f36ec3f0700 Options.max_bytes_for_level_base: 268435456 2018/11/30-06:19:07.248166 7f36ec3f0700 Options.level_compaction_dynamic_level_bytes: 0 2018/11/30-06:19:07.248168 7f36ec3f0700 Options.max_bytes_for_level_multiplier: 10.000000 2018/11/30-06:19:07.248179 7f36ec3f0700 Options.max_bytes_for_level_multiplier_addtl[0]: 1 2018/11/30-06:19:07.248181 7f36ec3f0700 Options.max_bytes_for_level_multiplier_addtl[1]: 1 2018/11/30-06:19:07.248182 7f36ec3f0700 Options.max_bytes_for_level_multiplier_addtl[2]: 1 2018/11/30-06:19:07.248229 7f36ec3f0700 Options.max_bytes_for_level_multiplier_addtl[3]: 1 2018/11/30-06:19:07.248232 7f36ec3f0700 Options.max_bytes_for_level_multiplier_addtl[4]: 1 2018/11/30-06:19:07.248248 7f36ec3f0700 Options.max_bytes_for_level_multiplier_addtl[5]: 1 2018/11/30-06:19:07.248263 7f36ec3f0700 Options.max_bytes_for_level_multiplier_addtl[6]: 1 2018/11/30-06:19:07.248272 7f36ec3f0700 Options.max_sequential_skip_in_iterations: 8 2018/11/30-06:19:07.248278 7f36ec3f0700 Options.max_compaction_bytes: 2621440000 2018/11/30-06:19:07.248292 7f36ec3f0700 Options.arena_block_size: 1048576 2018/11/30-06:19:07.248315 7f36ec3f0700 Options.soft_pending_compaction_bytes_limit: 68719476736 2018/11/30-06:19:07.248321 7f36ec3f0700 Options.hard_pending_compaction_bytes_limit: 274877906944 2018/11/30-06:19:07.248322 7f36ec3f0700 Options.rate_limit_delay_max_milliseconds: 100 2018/11/30-06:19:07.248323 7f36ec3f0700 Options.disable_auto_compactions: 0 2018/11/30-06:19:07.248328 7f36ec3f0700 Options.compaction_style: kCompactionStyleUniversal 2018/11/30-06:19:07.248333 7f36ec3f0700 Options.compaction_pri: kByCompensatedSize 2018/11/30-06:19:07.248340 7f36ec3f0700 Options.compaction_options_universal.size_ratio: 1 2018/11/30-06:19:07.248344 7f36ec3f0700 Options.compaction_options_universal.min_merge_width: 2 2018/11/30-06:19:07.248350 7f36ec3f0700 Options.compaction_options_universal.max_merge_width: 4294967295 2018/11/30-06:19:07.248351 7f36ec3f0700 Options.compaction_options_universal.max_size_amplification_percent: 200 2018/11/30-06:19:07.248366 7f36ec3f0700 Options.compaction_options_universal.compression_size_percent: -1 2018/11/30-06:19:07.248374 7f36ec3f0700 Options.compaction_options_universal.stop_style: kCompactionStopStyleTotalSize 2018/11/30-06:19:07.248375 7f36ec3f0700 Options.compaction_options_fifo.max_table_files_size: 1073741824 2018/11/30-06:19:07.248392 7f36ec3f0700 Options.compaction_options_fifo.allow_compaction: 0 2018/11/30-06:19:07.248396 7f36ec3f0700 Options.compaction_options_fifo.ttl: 0 2018/11/30-06:19:07.248403 7f36ec3f0700 Options.table_properties_collectors: 2018/11/30-06:19:07.248404 7f36ec3f0700 Options.inplace_update_support: 0 2018/11/30-06:19:07.248405 7f36ec3f0700 Options.inplace_update_num_locks: 10000 2018/11/30-06:19:07.248406 7f36ec3f0700 Options.memtable_prefix_bloom_size_ratio: 0.000000 2018/11/30-06:19:07.248414 7f36ec3f0700 Options.memtable_huge_page_size: 0 2018/11/30-06:19:07.248415 7f36ec3f0700 Options.bloom_locality: 0 2018/11/30-06:19:07.248419 7f36ec3f0700 Options.max_successive_merges: 0 2018/11/30-06:19:07.248426 7f36ec3f0700 Options.optimize_filters_for_hits: 0 2018/11/30-06:19:07.248428 7f36ec3f0700 Options.paranoid_file_checks: 0 2018/11/30-06:19:07.248433 7f36ec3f0700 Options.force_consistency_checks: 0 2018/11/30-06:19:07.248434 7f36ec3f0700 Options.report_bg_io_stats: 0 2018/11/30-06:19:07.248434 7f36ec3f0700 Options.ttl: 0 2018/11/30-06:20:16.278418 7f36ec3f0700 [db/version_set.cc:3529] Recovered from manifest file:$DATADIR/MANIFEST-077374 succeeded,manifest_file_number is 77374, next_file_number is 77743, last_sequence is 71371480, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 0 2018/11/30-06:20:16.278445 7f36ec3f0700 [db/version_set.cc:3537] Column family [default] (ID 0), log number is 77729 2018/11/30-06:20:16.279739 7f36ec3f0700 EVENT_LOG_v1 {"time_micros": 1543558816279733, "job": 1, "event": "recovery_started", "log_files": [77729]} 2018/11/30-06:20:16.279745 7f36ec3f0700 [db/db_impl_open.cc:552] Recovering log #77729 mode 2 2018/11/30-06:20:16.360197 7f36ec3f0700 EVENT_LOG_v1 {"time_micros": 1543558816360174, "cf_name": "default", "job": 1, "event": "table_file_creation", "file_number": 77743, "file_size": 666399, "table_properties": {"data_size": 653637, "index_size": 59437, "filter_size": 3247, "raw_key_size": 389131, "raw_average_key_size": 483, "raw_value_size": 574223, "raw_average_value_size": 714, "num_data_blocks": 172, "num_entries": 804, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:16.360280 7f36ec3f0700 [db/version_set.cc:2906] Creating manifest 77744 2018/11/30-06:20:16.362759 7f36ec3f0700 EVENT_LOG_v1 {"time_micros": 1543558816362754, "job": 1, "event": "recovery_finished"} 2018/11/30-06:20:16.364448 7f36ec3f0700 [db/db_impl_files.cc:508] [JOB 2] Delete info log file $DATADIR//LOG.old.1543523746165244 2018/11/30-06:20:16.367011 7f36ec3f0700 [db/db_impl_open.cc:1221] DB pointer 0x7f367c001200 2018/11/30-06:20:27.245385 7f35b77fe700 [WARN] [db/db_impl.cc:533] ------- DUMPING STATS ------- 2018/11/30-06:20:27.245461 7f35b77fe700 [WARN] [db/db_impl.cc:534] DB Stats Uptime(secs): 80.0 total, 80.0 interval Cumulative writes: 0 writes, 0 keys, 0 commit groups, 0.0 writes per commit group, ingest: 0.00 GB, 0.00 MB/s Cumulative WAL: 0 writes, 0 syncs, 0.00 writes per sync, written: 0.00 GB, 0.00 MB/s Cumulative stall: 00:00:0.000 H:M:S, 0.0 percent Interval writes: 0 writes, 0 keys, 0 commit groups, 0.0 writes per commit group, ingest: 0.00 MB, 0.00 MB/s Interval WAL: 0 writes, 0 syncs, 0.00 writes per sync, written: 0.00 MB, 0.00 MB/s Interval stall: 00:00:0.000 H:M:S, 0.0 percent
Compaction Stats [default] Level Files Size Score Read(GB) Rn(GB) Rnp1(GB) Write(GB) Wnew(GB) Moved(GB) W-Amp Rd(MB/s) Wr(MB/s) Comp(sec) Comp(cnt) Avg(sec) KeyIn KeyDrop
L0 1/0 650.78 KB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 40.4 0 1 0.016 0 0 L3 11/0 1.05 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 L4 68/0 1.36 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 L5 159/0 3.17 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 L6 189/0 3.77 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 Sum 428/0 9.36 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 40.4 0 1 0.016 0 0 Int 0/0 0.00 KB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 40.4 0 1 0.016 0 0 Uptime(secs): 80.0 total, 80.0 interval Flush(GB): cumulative 0.001, interval 0.001 AddFile(GB): cumulative 0.000, interval 0.000 AddFile(Total Files): cumulative 0, interval 0 AddFile(L0 Files): cumulative 0, interval 0 AddFile(Keys): cumulative 0, interval 0 Cumulative compaction: 0.00 GB write, 0.01 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds Interval compaction: 0.00 GB write, 0.01 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds Stalls(count): 0 level0_slowdown, 0 level0_slowdown_with_compaction, 0 level0_numfiles, 0 level0_numfiles_with_compaction, 0 stop for pending_compaction_bytes, 0 slowdown for pending_compaction_bytes, 0 memtable_compaction, 0 memtable_slowdown, interval 0 total count
File Read Latency Histogram By Level [default] ** Level 0 read latency histogram (micros): Count: 6 Average: 2.1667 StdDev: 1.07 Min: 1 Median: 1.5000 Max: 4 Percentiles: P50: 1.50 P75: 2.50 P99: 3.94 P99.9: 3.99 P99.99: 4.00
[ 0, 1 ] 2 33.333% 33.333% ####### ( 1, 2 ] 2 33.333% 66.667% ####### ( 2, 3 ] 1 16.667% 83.333% ### ( 3, 4 ] 1 16.667% 100.000% ###
** Level 3 read latency histogram (micros): Count: 65 Average: 225273.8769 StdDev: 511161.32 Min: 1 Median: 1.9583 Max: 1559310 Percentiles: P50: 1.96 P75: 238.89 P99: 1559310.00 P99.9: 1559310.00 P99.99: 1559310.00
[ 0, 1 ] 21 32.308% 32.308% ###### ( 1, 2 ] 12 18.462% 50.769% #### ( 3, 4 ] 1 1.538% 52.308% ( 34, 51 ] 1 1.538% 53.846% ( 76, 110 ] 3 4.615% 58.462% # ( 110, 170 ] 3 4.615% 63.077% # ( 170, 250 ] 9 13.846% 76.923% ### ( 250, 380 ] 4 6.154% 83.077% # ( 570000, 860000 ] 1 1.538% 84.615% ( 860000, 1200000 ] 1 1.538% 86.154% ( 1200000, 1900000 ] 9 13.846% 100.000% ###
** Level 4 read latency histogram (micros): Count: 387 Average: 16145.2351 StdDev: 66730.47 Min: 1 Median: 113.9474 Max: 353879 Percentiles: P50: 113.95 P75: 330.09 P99: 352050.00 P99.9: 353879.00 P99.99: 353879.00
[ 0, 1 ] 46 11.886% 11.886% ## ( 1, 2 ] 42 10.853% 22.739% ## ( 2, 3 ] 4 1.034% 23.773% ( 3, 4 ] 3 0.775% 24.548% ( 4, 6 ] 4 1.034% 25.581% ( 6, 10 ] 2 0.517% 26.098% ( 10, 15 ] 1 0.258% 26.357% ( 22, 34 ] 6 1.550% 27.907% ( 34, 51 ] 42 10.853% 38.760% ## ( 51, 76 ] 24 6.202% 44.961% # ( 76, 110 ] 17 4.393% 49.354% # ( 110, 170 ] 38 9.819% 59.173% ## ( 170, 250 ] 44 11.370% 70.543% ## ( 250, 380 ] 28 7.235% 77.778% # ( 380, 580 ] 20 5.168% 82.946% # ( 580, 870 ] 10 2.584% 85.530% # ( 870, 1300 ] 5 1.292% 86.822% ( 1300, 1900 ] 13 3.359% 90.181% # ( 1900, 2900 ] 9 2.326% 92.506% ( 2900, 4400 ] 4 1.034% 93.540% ( 4400, 6600 ] 2 0.517% 94.057% ( 9900, 14000 ] 1 0.258% 94.315% ( 75000, 110000 ] 1 0.258% 94.574% ( 110000, 170000 ] 2 0.517% 95.090% ( 170000, 250000 ] 1 0.258% 95.349% ( 250000, 380000 ] 18 4.651% 100.000% #
** Level 5 read latency histogram (micros): Count: 999 Average: 24180.8999 StdDev: 84371.32 Min: 1 Median: 137.6316 Max: 393766 Percentiles: P50: 137.63 P75: 358.44 P99: 364497.01 P99.9: 393766.00 P99.99: 393766.00
[ 0, 1 ] 131 13.113% 13.113% ### ( 1, 2 ] 90 9.009% 22.122% ## ( 2, 3 ] 13 1.301% 23.423% ( 3, 4 ] 2 0.200% 23.624% ( 4, 6 ] 14 1.401% 25.025% ( 6, 10 ] 4 0.400% 25.425% ( 10, 15 ] 1 0.100% 25.526% ( 15, 22 ] 2 0.200% 25.726% ( 22, 34 ] 30 3.003% 28.729% # ( 34, 51 ] 89 8.909% 37.638% ## ( 51, 76 ] 44 4.404% 42.042% # ( 76, 110 ] 27 2.703% 44.745% # ( 110, 170 ] 114 11.411% 56.156% ## ( 170, 250 ] 104 10.410% 66.567% ## ( 250, 380 ] 101 10.110% 76.677% ## ( 380, 580 ] 39 3.904% 80.581% # ( 580, 870 ] 38 3.804% 84.384% # ( 870, 1300 ] 27 2.703% 87.087% # ( 1300, 1900 ] 18 1.802% 88.889% ( 1900, 2900 ] 23 2.302% 91.191% ( 2900, 4400 ] 9 0.901% 92.092% ( 4400, 6600 ] 1 0.100% 92.192% ( 6600, 9900 ] 2 0.200% 92.392% ( 75000, 110000 ] 1 0.100% 92.492% ( 110000, 170000 ] 1 0.100% 92.593% ( 170000, 250000 ] 5 0.501% 93.093% ( 250000, 380000 ] 67 6.707% 99.800% # ( 380000, 570000 ] 2 0.200% 100.000%
** Level 6 read latency histogram (micros): Count: 1031 Average: 26879.4054 StdDev: 86148.24 Min: 0 Median: 101.8148 Max: 368941 Percentiles: P50: 101.81 P75: 366.20 P99: 363034.18 P99.9: 368941.00 P99.99: 368941.00
[ 0, 1 ] 125 12.124% 12.124% ## ( 1, 2 ] 117 11.348% 23.472% ## ( 2, 3 ] 7 0.679% 24.151% ( 3, 4 ] 2 0.194% 24.345% ( 4, 6 ] 5 0.485% 24.830% ( 6, 10 ] 5 0.485% 25.315% ( 10, 15 ] 3 0.291% 25.606% ( 15, 22 ] 1 0.097% 25.703% ( 22, 34 ] 64 6.208% 31.911% # ( 34, 51 ] 124 12.027% 43.938% ## ( 51, 76 ] 42 4.074% 48.012% # ( 76, 110 ] 27 2.619% 50.630% # ( 110, 170 ] 82 7.953% 58.584% ## ( 170, 250 ] 104 10.087% 68.671% ## ( 250, 380 ] 73 7.081% 75.752% # ( 380, 580 ] 38 3.686% 79.437% # ( 580, 870 ] 30 2.910% 82.347% # ( 870, 1300 ] 25 2.425% 84.772% ( 1300, 1900 ] 24 2.328% 87.100% ( 1900, 2900 ] 26 2.522% 89.622% # ( 2900, 4400 ] 11 1.067% 90.689% ( 4400, 6600 ] 1 0.097% 90.786% ( 14000, 22000 ] 1 0.097% 90.883% ( 75000, 110000 ] 4 0.388% 91.271% ( 110000, 170000 ] 2 0.194% 91.465% ( 170000, 250000 ] 9 0.873% 92.338% ( 250000, 380000 ] 79 7.662% 100.000% ##
Compaction Stats [default] Level Files Size Score Read(GB) Rn(GB) Rnp1(GB) Write(GB) Wnew(GB) Moved(GB) W-Amp Rd(MB/s) Wr(MB/s) Comp(sec) Comp(cnt) Avg(sec) KeyIn KeyDrop
L0 1/0 650.78 KB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 40.4 0 1 0.016 0 0 L3 11/0 1.05 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 L4 68/0 1.36 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 L5 159/0 3.17 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 L6 189/0 3.77 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 Sum 428/0 9.36 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 40.4 0 1 0.016 0 0 Int 0/0 0.00 KB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 Uptime(secs): 80.0 total, 0.0 interval Flush(GB): cumulative 0.001, interval 0.000 AddFile(GB): cumulative 0.000, interval 0.000 AddFile(Total Files): cumulative 0, interval 0 AddFile(L0 Files): cumulative 0, interval 0 AddFile(Keys): cumulative 0, interval 0 Cumulative compaction: 0.00 GB write, 0.01 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds Interval compaction: 0.00 GB write, 0.00 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds Stalls(count): 0 level0_slowdown, 0 level0_slowdown_with_compaction, 0 level0_numfiles, 0 level0_numfiles_with_compaction, 0 stop for pending_compaction_bytes, 0 slowdown for pending_compaction_bytes, 0 memtable_compaction, 0 memtable_slowdown, interval 0 total count
File Read Latency Histogram By Level [default] ** Level 0 read latency histogram (micros): Count: 6 Average: 2.1667 StdDev: 1.07 Min: 1 Median: 1.5000 Max: 4 Percentiles: P50: 1.50 P75: 2.50 P99: 3.94 P99.9: 3.99 P99.99: 4.00
[ 0, 1 ] 2 33.333% 33.333% ####### ( 1, 2 ] 2 33.333% 66.667% ####### ( 2, 3 ] 1 16.667% 83.333% ### ( 3, 4 ] 1 16.667% 100.000% ###
** Level 3 read latency histogram (micros): Count: 65 Average: 225273.8769 StdDev: 511161.32 Min: 1 Median: 1.9583 Max: 1559310 Percentiles: P50: 1.96 P75: 238.89 P99: 1559310.00 P99.9: 1559310.00 P99.99: 1559310.00
[ 0, 1 ] 21 32.308% 32.308% ###### ( 1, 2 ] 12 18.462% 50.769% #### ( 3, 4 ] 1 1.538% 52.308% ( 34, 51 ] 1 1.538% 53.846% ( 76, 110 ] 3 4.615% 58.462% # ( 110, 170 ] 3 4.615% 63.077% # ( 170, 250 ] 9 13.846% 76.923% ### ( 250, 380 ] 4 6.154% 83.077% # ( 570000, 860000 ] 1 1.538% 84.615% ( 860000, 1200000 ] 1 1.538% 86.154% ( 1200000, 1900000 ] 9 13.846% 100.000% ###
** Level 4 read latency histogram (micros): Count: 387 Average: 16145.2351 StdDev: 66730.47 Min: 1 Median: 113.9474 Max: 353879 Percentiles: P50: 113.95 P75: 330.09 P99: 352050.00 P99.9: 353879.00 P99.99: 353879.00
[ 0, 1 ] 46 11.886% 11.886% ## ( 1, 2 ] 42 10.853% 22.739% ## ( 2, 3 ] 4 1.034% 23.773% ( 3, 4 ] 3 0.775% 24.548% ( 4, 6 ] 4 1.034% 25.581% ( 6, 10 ] 2 0.517% 26.098% ( 10, 15 ] 1 0.258% 26.357% ( 22, 34 ] 6 1.550% 27.907% ( 34, 51 ] 42 10.853% 38.760% ## ( 51, 76 ] 24 6.202% 44.961% # ( 76, 110 ] 17 4.393% 49.354% # ( 110, 170 ] 38 9.819% 59.173% ## ( 170, 250 ] 44 11.370% 70.543% ## ( 250, 380 ] 28 7.235% 77.778% # ( 380, 580 ] 20 5.168% 82.946% # ( 580, 870 ] 10 2.584% 85.530% # ( 870, 1300 ] 5 1.292% 86.822% ( 1300, 1900 ] 13 3.359% 90.181% # ( 1900, 2900 ] 9 2.326% 92.506% ( 2900, 4400 ] 4 1.034% 93.540% ( 4400, 6600 ] 2 0.517% 94.057% ( 9900, 14000 ] 1 0.258% 94.315% ( 75000, 110000 ] 1 0.258% 94.574% ( 110000, 170000 ] 2 0.517% 95.090% ( 170000, 250000 ] 1 0.258% 95.349% ( 250000, 380000 ] 18 4.651% 100.000% #
** Level 5 read latency histogram (micros): Count: 999 Average: 24180.8999 StdDev: 84371.32 Min: 1 Median: 137.6316 Max: 393766 Percentiles: P50: 137.63 P75: 358.44 P99: 364497.01 P99.9: 393766.00 P99.99: 393766.00
[ 0, 1 ] 131 13.113% 13.113% ### ( 1, 2 ] 90 9.009% 22.122% ## ( 2, 3 ] 13 1.301% 23.423% ( 3, 4 ] 2 0.200% 23.624% ( 4, 6 ] 14 1.401% 25.025% ( 6, 10 ] 4 0.400% 25.425% ( 10, 15 ] 1 0.100% 25.526% ( 15, 22 ] 2 0.200% 25.726% ( 22, 34 ] 30 3.003% 28.729% # ( 34, 51 ] 89 8.909% 37.638% ## ( 51, 76 ] 44 4.404% 42.042% # ( 76, 110 ] 27 2.703% 44.745% # ( 110, 170 ] 114 11.411% 56.156% ## ( 170, 250 ] 104 10.410% 66.567% ## ( 250, 380 ] 101 10.110% 76.677% ## ( 380, 580 ] 39 3.904% 80.581% # ( 580, 870 ] 38 3.804% 84.384% # ( 870, 1300 ] 27 2.703% 87.087% # ( 1300, 1900 ] 18 1.802% 88.889% ( 1900, 2900 ] 23 2.302% 91.191% ( 2900, 4400 ] 9 0.901% 92.092% ( 4400, 6600 ] 1 0.100% 92.192% ( 6600, 9900 ] 2 0.200% 92.392% ( 75000, 110000 ] 1 0.100% 92.492% ( 110000, 170000 ] 1 0.100% 92.593% ( 170000, 250000 ] 5 0.501% 93.093% ( 250000, 380000 ] 67 6.707% 99.800% # ( 380000, 570000 ] 2 0.200% 100.000%
** Level 6 read latency histogram (micros): Count: 1031 Average: 26879.4054 StdDev: 86148.24 Min: 0 Median: 101.8148 Max: 368941 Percentiles: P50: 101.81 P75: 366.20 P99: 363034.18 P99.9: 368941.00 P99.99: 368941.00
[ 0, 1 ] 125 12.124% 12.124% ## ( 1, 2 ] 117 11.348% 23.472% ## ( 2, 3 ] 7 0.679% 24.151% ( 3, 4 ] 2 0.194% 24.345% ( 4, 6 ] 5 0.485% 24.830% ( 6, 10 ] 5 0.485% 25.315% ( 10, 15 ] 3 0.291% 25.606% ( 15, 22 ] 1 0.097% 25.703% ( 22, 34 ] 64 6.208% 31.911% # ( 34, 51 ] 124 12.027% 43.938% ## ( 51, 76 ] 42 4.074% 48.012% # ( 76, 110 ] 27 2.619% 50.630% # ( 110, 170 ] 82 7.953% 58.584% ## ( 170, 250 ] 104 10.087% 68.671% ## ( 250, 380 ] 73 7.081% 75.752% # ( 380, 580 ] 38 3.686% 79.437% # ( 580, 870 ] 30 2.910% 82.347% # ( 870, 1300 ] 25 2.425% 84.772% ( 1300, 1900 ] 24 2.328% 87.100% ( 1900, 2900 ] 26 2.522% 89.622% # ( 2900, 4400 ] 11 1.067% 90.689% ( 4400, 6600 ] 1 0.097% 90.786% ( 14000, 22000 ] 1 0.097% 90.883% ( 75000, 110000 ] 4 0.388% 91.271% ( 110000, 170000 ] 2 0.194% 91.465% ( 170000, 250000 ] 9 0.873% 92.338% ( 250000, 380000 ] 79 7.662% 100.000% ##
2018/11/30-06:20:27.246866 7f35b77fe700 [WARN] [db/db_impl.cc:484] STATISTICS: rocksdb.block.cache.miss COUNT : 348 rocksdb.block.cache.hit COUNT : 875 rocksdb.block.cache.add COUNT : 348 rocksdb.block.cache.add.failures COUNT : 0 rocksdb.block.cache.index.miss COUNT : 0 rocksdb.block.cache.index.hit COUNT : 0 rocksdb.block.cache.index.add COUNT : 0 rocksdb.block.cache.index.bytes.insert COUNT : 0 rocksdb.block.cache.index.bytes.evict COUNT : 0 rocksdb.block.cache.filter.miss COUNT : 0 rocksdb.block.cache.filter.hit COUNT : 0 rocksdb.block.cache.filter.add COUNT : 0 rocksdb.block.cache.filter.bytes.insert COUNT : 0 rocksdb.block.cache.filter.bytes.evict COUNT : 0 rocksdb.block.cache.data.miss COUNT : 348 rocksdb.block.cache.data.hit COUNT : 875 rocksdb.block.cache.data.add COUNT : 348 rocksdb.block.cache.data.bytes.insert COUNT : 1445408 rocksdb.block.cache.bytes.read COUNT : 4029680 rocksdb.block.cache.bytes.write COUNT : 1445408 rocksdb.bloom.filter.useful COUNT : 0 rocksdb.bloom.filter.full.positive COUNT : 0 rocksdb.bloom.filter.full.true.positive COUNT : 0 rocksdb.persistent.cache.hit COUNT : 0 rocksdb.persistent.cache.miss COUNT : 0 rocksdb.sim.block.cache.hit COUNT : 0 rocksdb.sim.block.cache.miss COUNT : 0 rocksdb.memtable.hit COUNT : 0 rocksdb.memtable.miss COUNT : 0 rocksdb.l0.hit COUNT : 0 rocksdb.l1.hit COUNT : 0 rocksdb.l2andup.hit COUNT : 0 rocksdb.compaction.key.drop.new COUNT : 0 rocksdb.compaction.key.drop.obsolete COUNT : 0 rocksdb.compaction.key.drop.range_del COUNT : 0 rocksdb.compaction.key.drop.user COUNT : 0 rocksdb.compaction.range_del.drop.obsolete COUNT : 0 rocksdb.compaction.optimized.del.drop.obsolete COUNT : 0 rocksdb.compaction.cancelled COUNT : 0 rocksdb.number.keys.written COUNT : 0 rocksdb.number.keys.read COUNT : 0 rocksdb.number.keys.updated COUNT : 0 rocksdb.bytes.written COUNT : 0 rocksdb.bytes.read COUNT : 0 rocksdb.number.db.seek COUNT : 280 rocksdb.number.db.next COUNT : 1311 rocksdb.number.db.prev COUNT : 0 rocksdb.number.db.seek.found COUNT : 268 rocksdb.number.db.next.found COUNT : 1043 rocksdb.number.db.prev.found COUNT : 0 rocksdb.db.iter.bytes.read COUNT : 906567 rocksdb.no.file.closes COUNT : 0 rocksdb.no.file.opens COUNT : 428 rocksdb.no.file.errors COUNT : 0 rocksdb.l0.slowdown.micros COUNT : 0 rocksdb.memtable.compaction.micros COUNT : 0 rocksdb.l0.num.files.stall.micros COUNT : 0 rocksdb.stall.micros COUNT : 0 rocksdb.db.mutex.wait.micros COUNT : 0 rocksdb.rate.limit.delay.millis COUNT : 0 rocksdb.num.iterators COUNT : 0 rocksdb.number.multiget.get COUNT : 0 rocksdb.number.multiget.keys.read COUNT : 0 rocksdb.number.multiget.bytes.read COUNT : 0 rocksdb.number.deletes.filtered COUNT : 0 rocksdb.number.merge.failures COUNT : 0 rocksdb.bloom.filter.prefix.checked COUNT : 1400 rocksdb.bloom.filter.prefix.useful COUNT : 1117 rocksdb.number.reseeks.iteration COUNT : 0 rocksdb.getupdatessince.calls COUNT : 0 rocksdb.block.cachecompressed.miss COUNT : 0 rocksdb.block.cachecompressed.hit COUNT : 0 rocksdb.block.cachecompressed.add COUNT : 0 rocksdb.block.cachecompressed.add.failures COUNT : 0 rocksdb.wal.synced COUNT : 0 rocksdb.wal.bytes COUNT : 0 rocksdb.write.self COUNT : 0 rocksdb.write.other COUNT : 0 rocksdb.write.timeout COUNT : 0 rocksdb.write.wal COUNT : 0 rocksdb.compact.read.bytes COUNT : 0 rocksdb.compact.write.bytes COUNT : 666399 rocksdb.flush.write.bytes COUNT : 0 rocksdb.number.direct.load.table.properties COUNT : 0 rocksdb.number.superversion_acquires COUNT : 149 rocksdb.number.superversion_releases COUNT : 0 rocksdb.number.superversion_cleanups COUNT : 0 rocksdb.number.block.compressed COUNT : 115 rocksdb.number.block.decompressed COUNT : 707 rocksdb.number.block.not_compressed COUNT : 0 rocksdb.merge.operation.time.nanos COUNT : 0 rocksdb.filter.operation.time.nanos COUNT : 0 rocksdb.row.cache.hit COUNT : 0 rocksdb.row.cache.miss COUNT : 0 rocksdb.read.amp.estimate.useful.bytes COUNT : 0 rocksdb.read.amp.total.read.bytes COUNT : 0 rocksdb.number.rate_limiter.drains COUNT : 0 rocksdb.number.iter.skip COUNT : 0 rocksdb.blobdb.num.put COUNT : 0 rocksdb.blobdb.num.write COUNT : 0 rocksdb.blobdb.num.get COUNT : 0 rocksdb.blobdb.num.multiget COUNT : 0 rocksdb.blobdb.num.seek COUNT : 0 rocksdb.blobdb.num.next COUNT : 0 rocksdb.blobdb.num.prev COUNT : 0 rocksdb.blobdb.num.keys.written COUNT : 0 rocksdb.blobdb.num.keys.read COUNT : 0 rocksdb.blobdb.bytes.written COUNT : 0 rocksdb.blobdb.bytes.read COUNT : 0 rocksdb.blobdb.write.inlined COUNT : 0 rocksdb.blobdb.write.inlined.ttl COUNT : 0 rocksdb.blobdb.write.blob COUNT : 0 rocksdb.blobdb.write.blob.ttl COUNT : 0 rocksdb.blobdb.blob.file.bytes.written COUNT : 0 rocksdb.blobdb.blob.file.bytes.read COUNT : 0 rocksdb.blobdb.blob.file.synced COUNT : 0 rocksdb.blobdb.blob.index.expired.count COUNT : 0 rocksdb.blobdb.blob.index.expired.size COUNT : 0 rocksdb.blobdb.blob.index.evicted.count COUNT : 0 rocksdb.blobdb.blob.index.evicted.size COUNT : 0 rocksdb.blobdb.gc.num.files COUNT : 0 rocksdb.blobdb.gc.num.new.files COUNT : 0 rocksdb.blobdb.gc.failures COUNT : 0 rocksdb.blobdb.gc.num.keys.overwritten COUNT : 0 rocksdb.blobdb.gc.num.keys.expired COUNT : 0 rocksdb.blobdb.gc.num.keys.relocated COUNT : 0 rocksdb.blobdb.gc.bytes.overwritten COUNT : 0 rocksdb.blobdb.gc.bytes.expired COUNT : 0 rocksdb.blobdb.gc.bytes.relocated COUNT : 0 rocksdb.blobdb.fifo.num.files.evicted COUNT : 0 rocksdb.blobdb.fifo.num.keys.evicted COUNT : 0 rocksdb.blobdb.fifo.bytes.evicted COUNT : 0 rocksdb.txn.overhead.mutex.prepare COUNT : 0 rocksdb.txn.overhead.mutex.old.commit.map COUNT : 0 rocksdb.txn.overhead.duplicate.key COUNT : 0 rocksdb.txn.overhead.mutex.snapshot COUNT : 0 rocksdb.number.multiget.keys.found COUNT : 0 rocksdb.db.get.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.db.write.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.compaction.times.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.subcompaction.setup.times.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.table.sync.micros P50 : 1239.000000 P95 : 1239.000000 P99 : 1239.000000 P100 : 1239.000000 COUNT : 1 SUM : 1239 rocksdb.compaction.outfile.sync.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.wal.file.sync.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.manifest.file.sync.micros P50 : 495.000000 P95 : 495.000000 P99 : 495.000000 P100 : 495.000000 COUNT : 1 SUM : 495 rocksdb.table.open.io.micros P50 : 2381632.653061 P95 : 4108421.052632 P99 : 12002666.666667 P100 : 13070567.000000 COUNT : 428 SUM : 1098714296 rocksdb.db.multiget.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.read.block.compaction.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.read.block.get.micros P50 : 219.230769 P95 : 865.857143 P99 : 1804.000000 P100 : 3476.000000 COUNT : 348 SUM : 108773 rocksdb.write.raw.block.micros P50 : 4.840580 P95 : 147.200000 P99 : 973.200000 P100 : 2291.000000 COUNT : 176 SUM : 7809 rocksdb.l0.slowdown.count P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.memtable.compaction.count P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.num.files.stall.count P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.hard.rate.limit.delay.count P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.soft.rate.limit.delay.count P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.numfiles.in.singlecompaction P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.db.seek.micros P50 : 306.666667 P95 : 999.000000 P99 : 3000.000000 P100 : 3546.000000 COUNT : 280 SUM : 116532 rocksdb.db.write.stall P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.sst.read.micros P50 : 120.126582 P95 : 291695.121951 P99 : 370582.926829 P100 : 1559310.000000 COUNT : 2488 SUM : 72760407 rocksdb.num.subcompactions.scheduled P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.bytes.per.read P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.bytes.per.write P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.bytes.per.multiget P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.bytes.compressed P50 : 4093.661972 P95 : 6351.190476 P99 : 6592.142857 P100 : 59432.000000 COUNT : 115 SUM : 549738 rocksdb.bytes.decompressed P50 : 2422556.390977 P95 : 4177813.620072 P99 : 14940224.000000 P100 : 14940224.000000 COUNT : 707 SUM : 1331958013 rocksdb.compression.times.nanos P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.decompression.times.nanos P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.read.num.merge_operands P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.key.size P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.value.size P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.write.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.get.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.multiget.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.seek.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.next.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.prev.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.blob.file.write.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.blob.file.read.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.blob.file.sync.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.gc.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.compression.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.blobdb.decompression.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 rocksdb.db.flush.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0 2018/11/30-06:20:27.246943 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246900) [db/compaction_picker_universal.cc:279] [default] Universal: sorted runs files(5): files[1 0 0 11 68 159 189] max score 1.25 2018/11/30-06:20:27.246946 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246902) [db/compaction_picker_universal.cc:692] [default] Universal: First candidate file 77743[0] to reduce size amp. 2018/11/30-06:20:27.246947 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246903) [db/compaction_picker_universal.cc:723] [default] Universal: size amp not needed. newer-files-total-size 5994915780 earliest-file-size 4052121207 2018/11/30-06:20:27.246955 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246904) [db/compaction_picker_universal.cc:501] [default] Universal: Possible candidate file 77743[0]. 2018/11/30-06:20:27.246956 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246905) [db/compaction_picker_universal.cc:553] [default] Universal: Skipping file 77743[0] with size 666399 (compensated size 666399) 2018/11/30-06:20:27.246958 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246907) [db/compaction_picker_universal.cc:501] [default] Universal: Possible candidate level 3[1]. 2018/11/30-06:20:27.246959 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246908) [db/compaction_picker_universal.cc:553] [default] Universal: Skipping level 3[1] with size 1130996059 (compensated size 1130996059) 2018/11/30-06:20:27.246960 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246908) [db/compaction_picker_universal.cc:501] [default] Universal: Possible candidate level 4[2]. 2018/11/30-06:20:27.246962 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246909) [db/compaction_picker_universal.cc:553] [default] Universal: Skipping level 4[2] with size 1456129331 (compensated size 1456129331) 2018/11/30-06:20:27.246963 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246909) [db/compaction_picker_universal.cc:501] [default] Universal: Possible candidate level 5[3]. 2018/11/30-06:20:27.246964 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246910) [db/compaction_picker_universal.cc:553] [default] Universal: Skipping level 5[3] with size 3407123991 (compensated size 3407123991) 2018/11/30-06:20:27.246966 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246910) [db/compaction_picker_universal.cc:501] [default] Universal: Possible candidate level 6[4]. 2018/11/30-06:20:27.246967 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246911) [db/compaction_picker_universal.cc:553] [default] Universal: Skipping level 6[4] with size 4052121207 (compensated size 4052121207) 2018/11/30-06:20:27.246968 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246912) [db/compaction_picker_universal.cc:501] [default] Universal: Possible candidate file 77743[0]. 2018/11/30-06:20:27.246969 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246913) [db/compaction_picker_universal.cc:623] [default] Universal: Picking file 77743[0] with size 666399 (compensated size 666399) 2018/11/30-06:20:27.246971 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246915) [db/compaction_picker_universal.cc:623] [default] Universal: Picking level 3[1] with size 1130996059 (compensated size 1130996059) 2018/11/30-06:20:27.246972 7f35b77fe700 (Original Log Time 2018/11/30-06:20:27.246930) [db/compaction_picker_universal.cc:332] [default] Universal: compacting for file num -- 2 2018/11/30-06:20:27.246975 7f35b77fe700 [db/compaction_job.cc:1635] [default] [JOB 3] Compacting 1@0 + 11@3 files to L3, score 1.25 2018/11/30-06:20:27.246981 7f35b77fe700 [db/compaction_job.cc:1639] [default] Compaction start summary: Base version 2 Base level 0, inputs: [77743(650KB)], [], [], [77731(102MB) 77732(102MB) 77733(102MB) 77734(102MB) 77735(102MB) 77736(102MB) 77737(102MB) 77738(102MB) 77739(102MB) 77740(102MB) 77741(54MB)], [], [], [] 2018/11/30-06:20:27.247002 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558827246988, "job": 3, "event": "compaction_started", "compaction_reason": "UniversalSortedRunNum", "files_L0": [77743], "files_L1": [], "files_L2": [], "files_L3": [77731, 77732, 77733, 77734, 77735, 77736, 77737, 77738, 77739, 77740, 77741], "files_L4": [], "files_L5": [], "files_L6": [], "score": 1.25, "input_data_size": 1131662458} 2018/11/30-06:20:29.859974 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77748: 356418 keys, 107284766 bytes 2018/11/30-06:20:29.860007 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558829859991, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77748, "file_size": 107284766, "table_properties": {"data_size": 104861098, "index_size": 11723824, "filter_size": 863912, "raw_key_size": 173726383, "raw_average_key_size": 487, "raw_value_size": 87664818, "raw_average_value_size": 245, "num_data_blocks": 35367, "num_entries": 356418, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:32.315960 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77749: 397804 keys, 107507164 bytes 2018/11/30-06:20:32.315993 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558832315975, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77749, "file_size": 107507164, "table_properties": {"data_size": 104860465, "index_size": 14816447, "filter_size": 811730, "raw_key_size": 195301292, "raw_average_key_size": 490, "raw_value_size": 90107399, "raw_average_value_size": 226, "num_data_blocks": 29967, "num_entries": 397804, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:34.451514 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77750: 359372 keys, 107358005 bytes 2018/11/30-06:20:34.451546 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558834451529, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77750, "file_size": 107358005, "table_properties": {"data_size": 104862435, "index_size": 14448790, "filter_size": 759237, "raw_key_size": 176451652, "raw_average_key_size": 491, "raw_value_size": 90286616, "raw_average_value_size": 251, "num_data_blocks": 29275, "num_entries": 359372, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:36.692361 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77751: 387578 keys, 107416139 bytes 2018/11/30-06:20:36.692393 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558836692376, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77751, "file_size": 107416139, "table_properties": {"data_size": 104861086, "index_size": 14720270, "filter_size": 794246, "raw_key_size": 190300798, "raw_average_key_size": 491, "raw_value_size": 90261664, "raw_average_value_size": 232, "num_data_blocks": 29746, "num_entries": 387578, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:38.836321 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77752: 357632 keys, 107363612 bytes 2018/11/30-06:20:38.836353 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558838836336, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77752, "file_size": 107363612, "table_properties": {"data_size": 104860279, "index_size": 14473156, "filter_size": 756986, "raw_key_size": 175597312, "raw_average_key_size": 491, "raw_value_size": 90258574, "raw_average_value_size": 252, "num_data_blocks": 29373, "num_entries": 357632, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:40.686291 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77753: 343636 keys, 107381066 bytes 2018/11/30-06:20:40.686322 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558840686305, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77753, "file_size": 107381066, "table_properties": {"data_size": 104862589, "index_size": 14289027, "filter_size": 744810, "raw_key_size": 168920836, "raw_average_key_size": 491, "raw_value_size": 90069864, "raw_average_value_size": 262, "num_data_blocks": 28923, "num_entries": 343636, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:43.023108 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77754: 405898 keys, 107497221 bytes 2018/11/30-06:20:43.023153 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558843023128, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77754, "file_size": 107497221, "table_properties": {"data_size": 104861302, "index_size": 14940229, "filter_size": 818531, "raw_key_size": 199700412, "raw_average_key_size": 491, "raw_value_size": 90257374, "raw_average_value_size": 222, "num_data_blocks": 30159, "num_entries": 405898, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:44.933719 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77755: 369828 keys, 107392699 bytes 2018/11/30-06:20:44.933752 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558844933735, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77755, "file_size": 107392699, "table_properties": {"data_size": 104860235, "index_size": 14581470, "filter_size": 772407, "raw_key_size": 181955376, "raw_average_key_size": 492, "raw_value_size": 90222516, "raw_average_value_size": 243, "num_data_blocks": 29455, "num_entries": 369828, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:46.997013 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77756: 394787 keys, 107446546 bytes 2018/11/30-06:20:46.997042 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558846997026, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77756, "file_size": 107446546, "table_properties": {"data_size": 104859465, "index_size": 14774126, "filter_size": 802982, "raw_key_size": 194235204, "raw_average_key_size": 492, "raw_value_size": 90144823, "raw_average_value_size": 228, "num_data_blocks": 29822, "num_entries": 394787, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:49.489900 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77757: 360605 keys, 107378129 bytes 2018/11/30-06:20:49.489931 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558849489914, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77757, "file_size": 107378129, "table_properties": {"data_size": 104862811, "index_size": 14527492, "filter_size": 760403, "raw_key_size": 177417660, "raw_average_key_size": 492, "raw_value_size": 90345525, "raw_average_value_size": 250, "num_data_blocks": 29412, "num_entries": 360605, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:50.493819 7f35b77fe700 [db/compaction_job.cc:1324] [default] [JOB 3] Generated table #77758: 144027 keys, 57271123 bytes 2018/11/30-06:20:50.493870 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850493839, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77758, "file_size": 57271123, "table_properties": {"data_size": 56059136, "index_size": 6946916, "filter_size": 353530, "raw_key_size": 70693148, "raw_average_key_size": 490, "raw_value_size": 48434180, "raw_average_value_size": 336, "num_data_blocks": 15095, "num_entries": 144027, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2018/11/30-06:20:50.830640 7f35b77fe700 [db/compaction_job.cc:1390] [default] [JOB 3] Compacted 1@0 + 11@3 files to L3 => 1131296470 bytes 2018/11/30-06:20:50.831711 7f35b77fe700 (Original Log Time 2018/11/30-06:20:50.831503) [db/compaction_job.cc:750] [default] compacted to: files[0 0 0 11 68 159 189] max score 1.00, MB/sec: 48.7 rd, 48.7 wr, level 3, files in(1, 11) out(11) MB in(0.6, 1078.6) out(1078.9), read-write-amplify(3395.8) write-amplify(1697.6) OK, records in: 3878070, records dropped: 485 output_compression: Snappy 2018/11/30-06:20:50.831719 7f35b77fe700 (Original Log Time 2018/11/30-06:20:50.831539) EVENT_LOG_v1 {"time_micros": 1543558850831524, "job": 3, "event": "compaction_finished", "compaction_time_micros": 23248638, "output_level": 3, "num_output_files": 11, "total_output_size": 1131296470, "num_input_records": 3878070, "num_output_records": 3877585, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [0, 0, 0, 11, 68, 159, 189]} 2018/11/30-06:20:50.832073 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850832068, "job": 3, "event": "table_file_deletion", "file_number": 77743} 2018/11/30-06:20:50.841598 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850841591, "job": 3, "event": "table_file_deletion", "file_number": 77741} 2018/11/30-06:20:50.858659 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850858651, "job": 3, "event": "table_file_deletion", "file_number": 77740} 2018/11/30-06:20:50.875671 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850875665, "job": 3, "event": "table_file_deletion", "file_number": 77739} 2018/11/30-06:20:50.893222 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850893214, "job": 3, "event": "table_file_deletion", "file_number": 77738} 2018/11/30-06:20:50.910556 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850910541, "job": 3, "event": "table_file_deletion", "file_number": 77737} 2018/11/30-06:20:50.927495 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850927487, "job": 3, "event": "table_file_deletion", "file_number": 77736} 2018/11/30-06:20:50.944773 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850944766, "job": 3, "event": "table_file_deletion", "file_number": 77735} 2018/11/30-06:20:50.957816 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850957810, "job": 3, "event": "table_file_deletion", "file_number": 77734} 2018/11/30-06:20:50.970168 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850970163, "job": 3, "event": "table_file_deletion", "file_number": 77733} 2018/11/30-06:20:50.982643 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850982638, "job": 3, "event": "table_file_deletion", "file_number": 77732} 2018/11/30-06:20:50.994541 7f35b77fe700 EVENT_LOG_v1 {"time_micros": 1543558850994535, "job": 3, "event": "table_file_deletion", "file_number": 77731} 2018/11/30-06:23:07.231705 7f35b7fff700 (Original Log Time 2018/11/30-06:23:07.231695) [db/compaction_picker_universal.cc:279] [default] Universal: sorted runs files(4): files[0 0 0 11 68 159 189] max score 1.00
Correction: I do see some 100 MB files now, though. May be it was my mistake. It is possible that we did not have enough data when I checked last. Is there a tool to rewrite existing data with the new options?
Also, is there any known option that must not be changed after data has been written to the db, or everything is allowed to be changed after data is written? What about block_size
Expected behavior
If I change target_file_size_base, new data should be written with the newer value.
Actual behavior
Seems like the file sizes stay the same as before.
Steps to reproduce the behavior
While we are at this, I would also like to confirm the behavior of changing other params after the DB has some data (like block_size for example)