Bug #21303
closedrocksdb get a error: "Compaction error: Corruption: block checksum mismatch"
Added by 黄 维 over 6 years ago. Updated over 6 years ago.
0%
Description
ceph --version
ceph version 12.1.0.5 (27f32562975c5fd3b785a124c818599c677b3f67) luminous (dev)
osd log:
2017-09-05 11:26:30.181778 7fd5bf317700 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rock
sdb/db/compaction_job.cc:1403] [default] [JOB 3] Compacting 4@0 + 1@1 files to L1, score 1.00
2017-09-05 11:26:30.181807 7fd5bf317700 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rock
sdb/db/compaction_job.cc:1407] [default] Compaction start summary: Base version 2 Base level 0, inputs: [563(14
88KB) 561(8590KB) 555(507KB) 552(3874KB)], [550(55MB)]
2017-09-05 11:26:30.181827 7fd5bf317700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1504581990181813, "job": 3, "e
vent": "compaction_started", "files_L0": [563, 561, 555, 552], "files_L1": [550], "score": 1, "input_data_size"
: 72834941}
2017-09-05 11:26:30.209372 7fd5d9f6bb80 1 freelist init
2017-09-05 11:26:30.317641 7fd5d9f6bb80 1 bluestore(/var/lib/ceph/osd/ceph-1) _open_alloc opening allocation m
etadata
2017-09-05 11:26:30.722914 7fd5d9f6bb80 1 bluestore(/var/lib/ceph/osd/ceph-1) _open_alloc loaded 19482 M in 74
extents
2017-09-05 11:26:30.781816 7fd5d9f6bb80 0 <cls> /clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/cls/ceph
fs/cls_cephfs.cc:197: loading cephfs
2017-09-05 11:26:30.782145 7fd5d9f6bb80 0 <cls> /clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/cls/hell
o/cls_hello.cc:296: loading cls_hello
2017-09-05 11:26:30.782457 7fd5d9f6bb80 0 _get_class not permitted to load kvs
2017-09-05 11:26:30.782794 7fd5d9f6bb80 0 _get_class not permitted to load lua
2017-09-05 11:26:30.788319 7fd5d9f6bb80 0 _get_class not permitted to load sdk
2017-09-05 11:26:30.790984 7fd5d9f6bb80 0 osd.1 3151 crush map has features 288514051259236352, adjusting msgr
requires for clients
2017-09-05 11:26:30.791000 7fd5d9f6bb80 0 osd.1 3151 crush map has features 288514051259236352 was 8705, adjus
ting msgr requires for mons
2017-09-05 11:26:30.791005 7fd5d9f6bb80 0 osd.1 3151 crush map has features 1009089991638532096, adjusting msg
r requires for osds
2017-09-05 11:26:32.079310 7fd5bf317700 3 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rock
sdb/db/db_impl_compaction_flush.cc:1591] Compaction error: Corruption: block checksum mismatch
2017-09-05 11:26:32.079310 7fd5bf317700 3 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rock
sdb/db/db_impl_compaction_flush.cc:1591] Compaction error: Corruption: block checksum mismatch
2017-09-05 11:26:32.079329 7fd5bf317700 4 rocksdb: (Original Log Time 2017/09/05-11:26:32.079244) [/clove/vm/r
enhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/compaction_job.cc:621] [default] compacted to: base level
1 max bytes base 268435456 files[4 1 0 0 0 0 0] max score 0.00, MB/sec: 38.4 rd, 32.3 wr, level 1, files in(4,
1) out(1) MB in(14.1, 55.3) out(58.4), read-write-amplify(9.1) write-amplify(4.1) Corruption: block checksum m
ismatch, records in: 434215, records dropped: 73730
2017-09-05 11:26:32.079336 7fd5bf317700 4 rocksdb: (Original Log Time 2017/09/05-11:26:32.079300) EVENT_LOG_v1
{"time_micros": 1504581992079285, "job": 3, "event": "compaction_finished", "compaction_time_micros": 1897387,
"output_level": 1, "num_output_files": 1, "total_output_size": 61278587, "num_input_records": 419816, "num_out
put_records": 346086, "num_subcompactions": 1, "num_single_delete_mismatches": 0, "num_single_delete_fallthroug
h": 4, "lsm_state": [4, 1, 0, 0, 0, 0, 0]}
2017-09-05 11:26:32.079339 7fd5bf317700 2 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rock
sdb/db/db_impl_compaction_flush.cc:1275] Waiting after background compaction error: Corruption: block checksum
mismatch, Accumulated background error counts: 1
2017-09-05 11:26:32.079965 7fd5c511d700 -1 rocksdb: submit_transaction error: Corruption: block checksum mismat
ch code = 2 Rocksdb transaction:
Delete( Prefix = O key = 0x7f7ffffffffffffffa22000000217363'rub_4.44!='0xfffffffffffffffeffffffffffffffff'o')
2017-09-05 11:26:32.081761 7fd5c511d700 -1 /clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/os/bluestore/B
lueStore.cc: In function 'void BlueStore::_kv_sync_thread()' thread 7fd5c511d700 time 2017-09-05 11:26:32.07998
8
/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/os/bluestore/BlueStore.cc: 8273: FAILED assert(r == 0)
ceph version 12.1.0.5 (27f32562975c5fd3b785a124c818599c677b3f67) luminous (dev)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x110) [0x7fd5da9e3200]
2: (BlueStore::_kv_sync_thread()+0x3787) [0x7fd5da899657]
3: (BlueStore::KVSyncThread::entry()+0xd) [0x7fd5da8de25d]
4: (()+0x7df3) [0x7fd5d75b8df3]
5: (clone()+0x6d) [0x7fd5d66ad3ed]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.env:
[root@ceph241 ~]# lsblk
NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
vda 252:0 0 200G 0 disk
?à?¤vda1 252:1 0 500M 0 part /boot
?¤vda2 252:2 0 99.5G 0 part
?à?¤zs-root 253:0 0 50G 0 lvm /
?à?¤zs-swap 253:1 0 2G 0 lvm [SWAP]
???¤zs-home 253:2 0 47.5G 0 lvm /home
vdb 252:16 0 50G 0 disk
?à?¤vdb1 252:17 0 100M 0 part /var/lib/ceph/osd/ceph-1
?à?¤vdb2 252:18 0 47.9G 0 part
?à?¤vdb3 252:19 0 1G 0 part
?¤vdb4 252:20 0 1G 0 part
vdc 252:32 0 50G 0 disk
?à?¤vdc1 252:33 0 100M 0 part /var/lib/ceph/osd/ceph-0
?à?¤vdc2 252:34 0 47.9G 0 part
?à?¤vdc3 252:35 0 1G 0 part
?¤vdc4 252:36 0 1G 0 part
vdd 252:48 0 50G 0 disk
?à?¤vdd1 252:49 0 100M 0 part /var/lib/ceph/osd/ceph-2
?à?¤vdd2 252:50 0 47.9G 0 part
?à?¤vdd3 252:51 0 1G 0 part
?¤vdd4 252:52 0 1G 0 part-3 0.14337 host ceph241
0 0.04779 osd.0 up 1.00000 1.00000
1 0.04779 osd.1 down 0 1.00000
2 0.04779 osd.2 up 1.00000 1.00000Files
Updated by 黄 维 over 6 years ago
the gdb info maybe helpful.It return null when rocsdb read metadata from the sst file
(gdb) n
rocksdb::ReadBlockContents (file=<optimized out>, footer=..., read_options=..., handle=...,
contents=contents@entry=0x7fffe71c92b0, ioptions=...,
decompression_requested=decompression_requested@entry=true, compression_dict=..., cache_options=...)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/format.cc:372
372 status = ReadBlock(file, footer, read_options, handle, &slice, used_buf);
(gdb) s
ReadBlock (options=..., buf=0x7fffe71c7ec0 "", contents=0x7fffe71c7e20, handle=..., footer=...,
file=<optimized out>) at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/format.cc:372
372 status = ReadBlock(file, footer, read_options, handle, &slice, used_buf);
(gdb) s
PerfStepTimer (for_mutex=false, metric=<optimized out>, this=0x7fffe71c7ea0)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/monitoring/perf_step_timer.h:20
20 metric_(metric) {}
(gdb) n
ReadBlock (options=..., buf=0x7fffe71c7ec0 "", contents=0x7fffe71c7e20, handle=..., footer=...,
file=<optimized out>) at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/format.cc:283
283 uint32_t value = DecodeFixed32(data + n + 1);
(gdb) n
285 switch (footer.checksum()) {
(gdb) p footer.checksum()
Cannot evaluate function -- may be inlined
(gdb) n
287 value = crc32c::Unmask(value);
(gdb) n
288 actual = crc32c::Value(data, n + 1);
(gdb) n
287 value = crc32c::Unmask(value);
(gdb) p value
$2 = 4178101027
(gdb) n
288 actual = crc32c::Value(data, n + 1);
(gdb) n
[New Thread 0x7fffe59c8700 (LWP 27686)]
[New Thread 0x7fffe51c7700 (LWP 31129)]
284 uint32_t actual = 0;
(gdb) p actual
$3 = 3961891650
(gdb) p data
$4 = 0x7fffe71c7ec0 ""
(gdb) n
296 if (s.ok() && actual != value) {
(gdb)
301 }
(gdb) p actual
$5 = <optimized out>
(gdb) p value
$6 = <optimized out>
(gdb) bt
#0 ReadBlock (options=..., buf=0x7fffe71c7ec0 "", contents=0x7fffe71c7e20, handle=..., footer=...,
file=<optimized out>) at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/format.cc:301
#1 rocksdb::ReadBlockContents (file=<optimized out>, footer=..., read_options=..., handle=...,
contents=contents@entry=0x7fffe71c92b0, ioptions=...,
decompression_requested=decompression_requested@entry=true, compression_dict=..., cache_options=...)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/format.cc:372
#2 0x000055555597b538 in rocksdb::(anonymous namespace)::ReadBlockFromFile (file=<optimized out>,
footer=..., options=..., handle=..., result=result@entry=0x7fffe71c9360, ioptions=...,
do_uncompress=do_uncompress@entry=true, compression_dict=..., cache_options=...,
global_seqno=global_seqno@entry=18446744073709551615,
read_amp_bytes_per_bit=read_amp_bytes_per_bit@entry=0)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/block_based_table_reader.cc:83
#3 0x000055555597bde6 in rocksdb::BlockBasedTable::ReadMetaBlock (rep=rep@entry=0x5555566c2380,
meta_block=meta_block@entry=0x7fffe71c94a0, iter=iter@entry=0x7fffe71c94b0)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/block_based_table_reader.cc:827
#4 0x0000555555984a0a in rocksdb::BlockBasedTable::Open(rocksdb::ImmutableCFOptions const&, rocksdb::EnvOptions const&, rocksdb::BlockBasedTableOptions const&, rocksdb::InternalKeyComparator const&, std::unique_ptr<rocksdb::RandomAccessFileReader, std::default_delete<rocksdb::RandomAccessFileReader> >&&, unsigned long, std::unique_ptr<rocksdb::TableReader, std::default_delete<rocksdb::TableReader> >, bool, bool, int) (ioptions=...,
env_options=..., table_options=..., internal_comparator=..., file=<optimized out>, file_size=1523987,
table_reader=0x7fffe71c9820,
prefetch_index_and_filter_in_cache=prefetch_index_and_filter_in_cache@entry=false, skip_filters=false,
level=0) at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/block_based_table_reader.cc:576
#5 0x0000555555979971 in rocksdb::BlockBasedTableFactory::NewTableReader(rocksdb::TableReaderOptions const&, std::unique_ptr<rocksdb::RandomAccessFileReader, std::default_delete<rocksdb::RandomAccessFileReader> >&&, unsigned long, std::unique_ptr<rocksdb::TableReader, std::default_delete<rocksdb::TableReader> >, bool) const (
this=<optimized out>, table_reader_options=..., file=<optimized out>, file_size=<optimized out>,
table_reader=<optimized out>, prefetch_index_and_filter_in_cache=false)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/table/block_based_table_factory.cc:59
#6 0x0000555555a3969e in rocksdb::TableCache::GetTableReader (this=this@entry=0x55555672c3c0,
env_options=..., internal_comparator=..., fd=..., sequential_mode=sequential_mode@entry=false,
readahead=readahead@entry=0, record_read_stats=record_read_stats@entry=true,
file_read_hist=file_read_hist@entry=0x5555568b4000, table_reader=table_reader@entry=0x7fffe71c9820,
skip_filters=skip_filters@entry=false, level=level@entry=0,
prefetch_index_and_filter_in_cache=prefetch_index_and_filter_in_cache@entry=false)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/db/table_cache.cc:111
#7 0x0000555555a39c2d in rocksdb::TableCache::FindTable (this=0x55555672c3c0, env_options=...,
---Type <return> to continue, or q <return> to quit---
internal_comparator=..., fd=..., handle=handle@entry=0x5555568a50c8, no_io=no_io@entry=false,
record_read_stats=record_read_stats@entry=true, file_read_hist=0x5555568b4000,
skip_filters=skip_filters@entry=false, level=0, prefetch_index_and_filter_in_cache=false)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/db/table_cache.cc:148
#8 0x0000555555a3ee02 in operator() (_closure=0x5555567822b0)
at /usr/src/debug/ceph-12.1.0.5/src/rocksdb/db/version_builder.cc:351
#9 std::_Function_handler<void (), rocksdb::VersionBuilder::Rep::LoadTableHandlers(rocksdb::InternalStats*, int, bool)::{lambda()#1}>::_M_invoke(std::_Any_data const&) (_functor=...)
at /usr/include/c++/4.8.2/functional:2071
#10 0x00007fffec38dda0 in ?? () from /lib64/libstdc++.so.6
#11 0x00007fffed036df3 in start_thread () from /lib64/libpthread.so.0
#12 0x00007fffebaf63ed in clone () from /lib64/libc.so.6
Updated by 黄 维 over 6 years ago
[root@ceph241 hw]# ceph-bluestore-tool --path /var/lib/ceph/osd/ceph-1 fsck
action fsck
2017-09-11 15:37:35.698119 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) fsck (shallow) start
2017-09-11 15:37:35.698139 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) _set_cache_sizes meta 0.1 kv 0.2 data 0.7
2017-09-11 15:37:35.698512 7fa40712fb80 1 bdev create path /var/lib/ceph/osd/ceph-1/block type kernel
2017-09-11 15:37:35.698525 7fa40712fb80 1 bdev(0x7fa409c34a00 /var/lib/ceph/osd/ceph-1/block) open path /var/lib/ceph/osd/ceph-1/block
2017-09-11 15:37:35.699195 7fa40712fb80 1 bdev(0x7fa409c34a00 /var/lib/ceph/osd/ceph-1/block) open size 51433676800 (0xbf9afa000, 49050 MB) block_size 4096 (4096 B) rotational
2017-09-11 15:37:35.700909 7fa40712fb80 1 bdev create path /var/lib/ceph/osd/ceph-1/block.db type kernel
2017-09-11 15:37:35.700922 7fa40712fb80 1 bdev(0x7fa409c34c00 /var/lib/ceph/osd/ceph-1/block.db) open path /var/lib/ceph/osd/ceph-1/block.db
2017-09-11 15:37:35.701085 7fa40712fb80 1 bdev(0x7fa409c34c00 /var/lib/ceph/osd/ceph-1/block.db) open size 1073741824 (0x40000000, 1024 MB) block_size 4096 (4096 B) rotational
2017-09-11 15:37:35.701096 7fa40712fb80 1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-1/block.db size 1024 MB
2017-09-11 15:37:35.701990 7fa40712fb80 1 bdev create path /var/lib/ceph/osd/ceph-1/block type kernel
2017-09-11 15:37:35.702003 7fa40712fb80 1 bdev(0x7fa409c34e00 /var/lib/ceph/osd/ceph-1/block) open path /var/lib/ceph/osd/ceph-1/block
2017-09-11 15:37:35.702159 7fa40712fb80 1 bdev(0x7fa409c34e00 /var/lib/ceph/osd/ceph-1/block) open size 51433676800 (0xbf9afa000, 49050 MB) block_size 4096 (4096 B) rotational
2017-09-11 15:37:35.702170 7fa40712fb80 1 bluefs add_block_device bdev 2 path /var/lib/ceph/osd/ceph-1/block size 49050 MB
2017-09-11 15:37:35.702190 7fa40712fb80 1 bdev create path /var/lib/ceph/osd/ceph-1/block.wal type kernel
2017-09-11 15:37:35.702194 7fa40712fb80 1 bdev(0x7fa409c35000 /var/lib/ceph/osd/ceph-1/block.wal) open path /var/lib/ceph/osd/ceph-1/block.wal
2017-09-11 15:37:35.702345 7fa40712fb80 1 bdev(0x7fa409c35000 /var/lib/ceph/osd/ceph-1/block.wal) open size 1073741824 (0x40000000, 1024 MB) block_size 4096 (4096 B) rotational
2017-09-11 15:37:35.702355 7fa40712fb80 1 bluefs add_block_device bdev 0 path /var/lib/ceph/osd/ceph-1/block.wal size 1024 MB
2017-09-11 15:37:35.703517 7fa40712fb80 1 bluefs mount
2017-09-11 15:37:35.739116 7fa40712fb80 0 set rocksdb option compaction_readahead_size = 2097152
2017-09-11 15:37:35.739139 7fa40712fb80 0 set rocksdb option compression = kNoCompression
2017-09-11 15:37:35.739147 7fa40712fb80 0 set rocksdb option max_write_buffer_number = 4
2017-09-11 15:37:35.739152 7fa40712fb80 0 set rocksdb option min_write_buffer_number_to_merge = 1
2017-09-11 15:37:35.739156 7fa40712fb80 0 set rocksdb option recycle_log_file_num = 4
2017-09-11 15:37:35.739159 7fa40712fb80 0 set rocksdb option writable_file_max_buffer_size = 0
2017-09-11 15:37:35.739164 7fa40712fb80 0 set rocksdb option write_buffer_size = 268435456
2017-09-11 15:37:35.739193 7fa40712fb80 0 set rocksdb option compaction_readahead_size = 2097152
2017-09-11 15:37:35.739197 7fa40712fb80 0 set rocksdb option compression = kNoCompression
2017-09-11 15:37:35.739201 7fa40712fb80 0 set rocksdb option max_write_buffer_number = 4
2017-09-11 15:37:35.739204 7fa40712fb80 0 set rocksdb option min_write_buffer_number_to_merge = 1
2017-09-11 15:37:35.739207 7fa40712fb80 0 set rocksdb option recycle_log_file_num = 4
2017-09-11 15:37:35.739210 7fa40712fb80 0 set rocksdb option writable_file_max_buffer_size = 0
2017-09-11 15:37:35.739213 7fa40712fb80 0 set rocksdb option write_buffer_size = 268435456
2017-09-11 15:37:35.739405 7fa40712fb80 4 rocksdb: RocksDB version: 5.4.0
2017-09-11 15:37:35.739421 7fa40712fb80 4 rocksdb: Git sha rocksdb_build_git_sha:0
2017-09-11 15:37:35.739423 7fa40712fb80 4 rocksdb: Compile date Aug 1 2017
2017-09-11 15:37:35.739426 7fa40712fb80 4 rocksdb: DB SUMMARY
2017-09-11 15:37:35.739456 7fa40712fb80 4 rocksdb: CURRENT file: CURRENT
2017-09-11 15:37:35.739458 7fa40712fb80 4 rocksdb: IDENTITY file: IDENTITY
2017-09-11 15:37:35.739466 7fa40712fb80 4 rocksdb: MANIFEST file: MANIFEST-001026 size: 3093 Bytes
2017-09-11 15:37:35.739471 7fa40712fb80 4 rocksdb: SST files in db dir, Total Num: 36, files: 000552.sst 000555.sst 000561.sst 000563.sst 000566.sst 000569.sst 000572.sst 000575.sst 000578.sst
2017-09-11 15:37:35.739492 7fa40712fb80 4 rocksdb: SST files in db.slow dir, Total Num: 37, files: 000550.sst 000552.sst 000555.sst 000561.sst 000563.sst 000566.sst 000569.sst 000572.sst 000575.sst
2017-09-11 15:37:35.739514 7fa40712fb80 4 rocksdb: Write Ahead Log file in db.wal: 001027.log size: 0 ;
2017-09-11 15:37:35.739517 7fa40712fb80 4 rocksdb: Options.error_if_exists: 0
2017-09-11 15:37:35.739519 7fa40712fb80 4 rocksdb: Options.create_if_missing: 0
2017-09-11 15:37:35.739520 7fa40712fb80 4 rocksdb: Options.paranoid_checks: 1
2017-09-11 15:37:35.739521 7fa40712fb80 4 rocksdb: Options.env: 0x7fa409ddbac0
2017-09-11 15:37:35.739523 7fa40712fb80 4 rocksdb: Options.info_log: 0x7fa409ddc380
2017-09-11 15:37:35.739524 7fa40712fb80 4 rocksdb: Options.max_open_files: -1
2017-09-11 15:37:35.739525 7fa40712fb80 4 rocksdb: Options.max_file_opening_threads: 16
2017-09-11 15:37:35.739526 7fa40712fb80 4 rocksdb: Options.use_fsync: 0
2017-09-11 15:37:35.739527 7fa40712fb80 4 rocksdb: Options.max_log_file_size: 0
2017-09-11 15:37:35.739529 7fa40712fb80 4 rocksdb: Options.max_manifest_file_size: 18446744073709551615
2017-09-11 15:37:35.739530 7fa40712fb80 4 rocksdb: Options.log_file_time_to_roll: 0
2017-09-11 15:37:35.739531 7fa40712fb80 4 rocksdb: Options.keep_log_file_num: 1000
2017-09-11 15:37:35.739533 7fa40712fb80 4 rocksdb: Options.recycle_log_file_num: 4
2017-09-11 15:37:35.739534 7fa40712fb80 4 rocksdb: Options.allow_fallocate: 1
2017-09-11 15:37:35.739535 7fa40712fb80 4 rocksdb: Options.allow_mmap_reads: 0
2017-09-11 15:37:35.739536 7fa40712fb80 4 rocksdb: Options.allow_mmap_writes: 0
2017-09-11 15:37:35.739537 7fa40712fb80 4 rocksdb: Options.use_direct_reads: 0
2017-09-11 15:37:35.739538 7fa40712fb80 4 rocksdb: Options.use_direct_io_for_flush_and_compaction: 0
2017-09-11 15:37:35.739539 7fa40712fb80 4 rocksdb: Options.create_missing_column_families: 0
2017-09-11 15:37:35.739540 7fa40712fb80 4 rocksdb: Options.db_log_dir:
2017-09-11 15:37:35.739541 7fa40712fb80 4 rocksdb: Options.wal_dir: db.wal
2017-09-11 15:37:35.739542 7fa40712fb80 4 rocksdb: Options.table_cache_numshardbits: 6
2017-09-11 15:37:35.739544 7fa40712fb80 4 rocksdb: Options.max_subcompactions: 1
2017-09-11 15:37:35.739545 7fa40712fb80 4 rocksdb: Options.max_background_flushes: 1
2017-09-11 15:37:35.739546 7fa40712fb80 4 rocksdb: Options.WAL_ttl_seconds: 0
2017-09-11 15:37:35.739547 7fa40712fb80 4 rocksdb: Options.WAL_size_limit_MB: 0
2017-09-11 15:37:35.739559 7fa40712fb80 4 rocksdb: Options.manifest_preallocation_size: 4194304
2017-09-11 15:37:35.739561 7fa40712fb80 4 rocksdb: Options.is_fd_close_on_exec: 1
2017-09-11 15:37:35.739562 7fa40712fb80 4 rocksdb: Options.advise_random_on_open: 1
2017-09-11 15:37:35.739563 7fa40712fb80 4 rocksdb: Options.db_write_buffer_size: 0
2017-09-11 15:37:35.739564 7fa40712fb80 4 rocksdb: Options.access_hint_on_compaction_start: 1
2017-09-11 15:37:35.739565 7fa40712fb80 4 rocksdb: Options.new_table_reader_for_compaction_inputs: 1
2017-09-11 15:37:35.739566 7fa40712fb80 4 rocksdb: Options.compaction_readahead_size: 2097152
2017-09-11 15:37:35.739568 7fa40712fb80 4 rocksdb: Options.random_access_max_buffer_size: 1048576
2017-09-11 15:37:35.739569 7fa40712fb80 4 rocksdb: Options.writable_file_max_buffer_size: 0
2017-09-11 15:37:35.739570 7fa40712fb80 4 rocksdb: Options.use_adaptive_mutex: 0
2017-09-11 15:37:35.739571 7fa40712fb80 4 rocksdb: Options.rate_limiter: (nil)
2017-09-11 15:37:35.739572 7fa40712fb80 4 rocksdb: Options.sst_file_manager.rate_bytes_per_sec: 0
2017-09-11 15:37:35.739573 7fa40712fb80 4 rocksdb: Options.bytes_per_sync: 0
2017-09-11 15:37:35.739574 7fa40712fb80 4 rocksdb: Options.wal_bytes_per_sync: 0
2017-09-11 15:37:35.739575 7fa40712fb80 4 rocksdb: Options.wal_recovery_mode: 0
2017-09-11 15:37:35.739576 7fa40712fb80 4 rocksdb: Options.enable_thread_tracking: 0
2017-09-11 15:37:35.739577 7fa40712fb80 4 rocksdb: Options.allow_concurrent_memtable_write: 1
2017-09-11 15:37:35.739578 7fa40712fb80 4 rocksdb: Options.enable_write_thread_adaptive_yield: 1
2017-09-11 15:37:35.739579 7fa40712fb80 4 rocksdb: Options.write_thread_max_yield_usec: 100
2017-09-11 15:37:35.739588 7fa40712fb80 4 rocksdb: Options.write_thread_slow_yield_usec: 3
2017-09-11 15:37:35.739589 7fa40712fb80 4 rocksdb: Options.row_cache: 42949676
2017-09-11 15:37:35.739590 7fa40712fb80 4 rocksdb: Options.wal_filter: None
2017-09-11 15:37:35.739591 7fa40712fb80 4 rocksdb: Options.avoid_flush_during_recovery: 0
2017-09-11 15:37:35.739592 7fa40712fb80 4 rocksdb: Options.base_background_compactions: 1
2017-09-11 15:37:35.739593 7fa40712fb80 4 rocksdb: Options.max_background_compactions: 1
2017-09-11 15:37:35.739594 7fa40712fb80 4 rocksdb: Options.avoid_flush_during_shutdown: 0
2017-09-11 15:37:35.739595 7fa40712fb80 4 rocksdb: Options.delayed_write_rate : 16777216
2017-09-11 15:37:35.739596 7fa40712fb80 4 rocksdb: Options.max_total_wal_size: 0
2017-09-11 15:37:35.739597 7fa40712fb80 4 rocksdb: Options.delete_obsolete_files_period_micros: 21600000000
2017-09-11 15:37:35.739598 7fa40712fb80 4 rocksdb: Options.stats_dump_period_sec: 600
2017-09-11 15:37:35.739600 7fa40712fb80 4 rocksdb: Compression algorithms supported:
2017-09-11 15:37:35.739602 7fa40712fb80 4 rocksdb: Snappy supported: 0
2017-09-11 15:37:35.739603 7fa40712fb80 4 rocksdb: Zlib supported: 0
2017-09-11 15:37:35.739604 7fa40712fb80 4 rocksdb: Bzip supported: 0
2017-09-11 15:37:35.739605 7fa40712fb80 4 rocksdb: LZ4 supported: 0
2017-09-11 15:37:35.739606 7fa40712fb80 4 rocksdb: ZSTD supported: 0
2017-09-11 15:37:35.739610 7fa40712fb80 4 rocksdb: Fast CRC32 supported: 1
2017-09-11 15:37:35.740498 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/version_set.cc:2609] Recovering from manifest file: MANIFEST-001026
2017-09-11 15:37:35.740579 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/column_family.cc:407] --------------- Options for column family [default]:
2017-09-11 15:37:35.740585 7fa40712fb80 4 rocksdb: Options.comparator: leveldb.BytewiseComparator
2017-09-11 15:37:35.740594 7fa40712fb80 4 rocksdb: Options.merge_operator: .T:int64_array.b:bitwise_xor
2017-09-11 15:37:35.740595 7fa40712fb80 4 rocksdb: Options.compaction_filter: None
2017-09-11 15:37:35.740597 7fa40712fb80 4 rocksdb: Options.compaction_filter_factory: None
2017-09-11 15:37:35.740598 7fa40712fb80 4 rocksdb: Options.memtable_factory: SkipListFactory
2017-09-11 15:37:35.740599 7fa40712fb80 4 rocksdb: Options.table_factory: BlockBasedTable
2017-09-11 15:37:35.740620 7fa40712fb80 4 rocksdb: table_factory options: flush_block_policy_factory: FlushBlockBySizePolicyFactory (0x7fa409c16398)
cache_index_and_filter_blocks: 0
cache_index_and_filter_blocks_with_high_priority: 0
pin_l0_filter_and_index_blocks_in_cache: 0
index_type: 0
hash_index_allow_collision: 1
checksum: 1
no_block_cache: 0
block_cache: 0x7fa409c6f048
block_cache_name: LRUCache
block_cache_options:
capacity : 171798692
num_shard_bits : 4
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
filter_policy: nullptr
whole_key_filtering: 1
format_version: 2
2017-09-11 15:37:35.740625 7fa40712fb80 4 rocksdb: Options.write_buffer_size: 268435456
2017-09-11 15:37:35.740626 7fa40712fb80 4 rocksdb: Options.max_write_buffer_number: 4
2017-09-11 15:37:35.740628 7fa40712fb80 4 rocksdb: Options.compression: NoCompression
2017-09-11 15:37:35.740629 7fa40712fb80 4 rocksdb: Options.bottommost_compression: Disabled
2017-09-11 15:37:35.740630 7fa40712fb80 4 rocksdb: Options.prefix_extractor: nullptr
2017-09-11 15:37:35.740631 7fa40712fb80 4 rocksdb: Options.memtable_insert_with_hint_prefix_extractor: nullptr
2017-09-11 15:37:35.740632 7fa40712fb80 4 rocksdb: Options.num_levels: 7
2017-09-11 15:37:35.740633 7fa40712fb80 4 rocksdb: Options.min_write_buffer_number_to_merge: 1
2017-09-11 15:37:35.740635 7fa40712fb80 4 rocksdb: Options.max_write_buffer_number_to_maintain: 0
2017-09-11 15:37:35.740636 7fa40712fb80 4 rocksdb: Options.compression_opts.window_bits: -14
2017-09-11 15:37:35.740638 7fa40712fb80 4 rocksdb: Options.compression_opts.level: -1
2017-09-11 15:37:35.740639 7fa40712fb80 4 rocksdb: Options.compression_opts.strategy: 0
2017-09-11 15:37:35.740640 7fa40712fb80 4 rocksdb: Options.compression_opts.max_dict_bytes: 0
2017-09-11 15:37:35.740642 7fa40712fb80 4 rocksdb: Options.level0_file_num_compaction_trigger: 4
2017-09-11 15:37:35.740643 7fa40712fb80 4 rocksdb: Options.level0_slowdown_writes_trigger: 20
2017-09-11 15:37:35.740644 7fa40712fb80 4 rocksdb: Options.level0_stop_writes_trigger: 36
2017-09-11 15:37:35.740645 7fa40712fb80 4 rocksdb: Options.target_file_size_base: 67108864
2017-09-11 15:37:35.740647 7fa40712fb80 4 rocksdb: Options.target_file_size_multiplier: 1
2017-09-11 15:37:35.740648 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_base: 268435456
2017-09-11 15:37:35.740649 7fa40712fb80 4 rocksdb: Options.level_compaction_dynamic_level_bytes: 0
2017-09-11 15:37:35.740650 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_multiplier: 10.000000
2017-09-11 15:37:35.740653 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl0: 1
2017-09-11 15:37:35.740655 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl1: 1
2017-09-11 15:37:35.740657 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl2: 1
2017-09-11 15:37:35.740658 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl3: 1
2017-09-11 15:37:35.740659 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl4: 1
2017-09-11 15:37:35.740660 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl5: 1
2017-09-11 15:37:35.740661 7fa40712fb80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl6: 1
2017-09-11 15:37:35.740662 7fa40712fb80 4 rocksdb: Options.max_sequential_skip_in_iterations: 8
2017-09-11 15:37:35.740663 7fa40712fb80 4 rocksdb: Options.max_compaction_bytes: 1677721600
2017-09-11 15:37:35.740664 7fa40712fb80 4 rocksdb: Options.arena_block_size: 33554432
2017-09-11 15:37:35.740676 7fa40712fb80 4 rocksdb: Options.soft_pending_compaction_bytes_limit: 68719476736
2017-09-11 15:37:35.740677 7fa40712fb80 4 rocksdb: Options.hard_pending_compaction_bytes_limit: 274877906944
2017-09-11 15:37:35.740679 7fa40712fb80 4 rocksdb: Options.rate_limit_delay_max_milliseconds: 100
2017-09-11 15:37:35.740680 7fa40712fb80 4 rocksdb: Options.disable_auto_compactions: 0
2017-09-11 15:37:35.740681 7fa40712fb80 4 rocksdb: Options.compaction_style: kCompactionStyleLevel
2017-09-11 15:37:35.740683 7fa40712fb80 4 rocksdb: Options.compaction_pri: kByCompensatedSize
2017-09-11 15:37:35.740684 7fa40712fb80 4 rocksdb: Options.compaction_options_universal.size_ratio: 1
2017-09-11 15:37:35.740685 7fa40712fb80 4 rocksdb: Options.compaction_options_universal.min_merge_width: 2
2017-09-11 15:37:35.740692 7fa40712fb80 4 rocksdb: Options.compaction_options_universal.max_merge_width: 4294967295
2017-09-11 15:37:35.740694 7fa40712fb80 4 rocksdb: Options.compaction_options_universal.max_size_amplification_percent: 200
2017-09-11 15:37:35.740695 7fa40712fb80 4 rocksdb: Options.compaction_options_universal.compression_size_percent: -1
2017-09-11 15:37:35.740696 7fa40712fb80 4 rocksdb: Options.compaction_options_fifo.max_table_files_size: 1073741824
2017-09-11 15:37:35.740697 7fa40712fb80 4 rocksdb: Options.table_properties_collectors:
2017-09-11 15:37:35.740698 7fa40712fb80 4 rocksdb: Options.inplace_update_support: 0
2017-09-11 15:37:35.740699 7fa40712fb80 4 rocksdb: Options.inplace_update_num_locks: 10000
2017-09-11 15:37:35.740700 7fa40712fb80 4 rocksdb: Options.memtable_prefix_bloom_size_ratio: 0.000000
2017-09-11 15:37:35.740702 7fa40712fb80 4 rocksdb: Options.memtable_huge_page_size: 0
2017-09-11 15:37:35.740703 7fa40712fb80 4 rocksdb: Options.bloom_locality: 0
2017-09-11 15:37:35.740704 7fa40712fb80 4 rocksdb: Options.max_successive_merges: 0
2017-09-11 15:37:35.740705 7fa40712fb80 4 rocksdb: Options.optimize_filters_for_hits: 0
2017-09-11 15:37:35.740713 7fa40712fb80 4 rocksdb: Options.paranoid_file_checks: 0
2017-09-11 15:37:35.740714 7fa40712fb80 4 rocksdb: Options.force_consistency_checks: 0
2017-09-11 15:37:35.740715 7fa40712fb80 4 rocksdb: Options.report_bg_io_stats: 0
2017-09-11 15:37:35.757892 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/version_set.cc:2859] Recovered from manifest file:db/MANIFEST-001026 succeeded,manifest_file_number is 1026, next_file_number is 1028, last_sequence is 6767041, log_number is 0,prev_log_number is 0,max_column_family is 0
2017-09-11 15:37:35.757912 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/version_set.cc:2867] Column family [default] (ID 0), log number is 1025
2017-09-11 15:37:35.758041 7fa40712fb80 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1505115455758028, "job": 1, "event": "recovery_started", "log_files": [1027]}
2017-09-11 15:37:35.758051 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/db_impl_open.cc:482] Recovering log #1027 mode 0
2017-09-11 15:37:35.758069 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/version_set.cc:2395] Creating manifest 1029
2017-09-11 15:37:35.769344 7fa40712fb80 3 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/column_family.cc:641] [default] Stopping writes because we have 36 level-0 files
2017-09-11 15:37:35.777611 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/db_impl_open.cc:1063] DB pointer 0x7fa409f3c000
2017-09-11 15:37:35.777652 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) _open_db opened rocksdb path db options compression=kNoCompression,max_write_buffer_number=4,min_write_buffer_number_to_merge=1,recycle_log_file_num=4,write_buffer_size=268435456,writable_file_max_buffer_size=0,compaction_readahead_size=2097152
2017-09-11 15:37:35.777830 7fa3eeb23700 3 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/db_impl.cc:447] ------- DUMPING STATS -------
2017-09-11 15:37:35.777841 7fa3eeb23700 3 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/db_impl.cc:448]
- DB Stats **
Uptime(secs): 0.0 total, 0.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 36/0 14.15 MB 9.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
L1 1/0 55.34 MB 0.2 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 37/0 69.49 MB 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
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): 0.0 total, 0.0 interval
Flush(GB): cumulative 0.000, 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.00 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, 1 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 1 total count
- File Read Latency Histogram By Level [default] **
- 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 36/0 14.15 MB 9.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
L1 1/0 55.34 MB 0.2 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 37/0 69.49 MB 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
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): 0.0 total, 0.0 interval
Flush(GB): cumulative 0.000, 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.00 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, 1 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] **
2017-09-11 15:37:35.777964 7fa3eeb23700 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/compaction_job.cc:1403] [default] [JOB 3] Compacting 36@0 + 1@1 files to L1, score 9.00
2017-09-11 15:37:35.777997 7fa3eeb23700 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/compaction_job.cc:1407] [default] Compaction start summary: Base version 2 Base level 0, inputs: [662(1013B) 659(1014B) 653(1014B) 650(1014B) 647(1014B) 644(1014B) 641(1014B) 638(1014B) 635(1013B) 632(1014B) 629(1014B) 626(1014B) 623(1014B) 620(1014B) 617(1014B) 614(1014B) 611(1014B) 608(1013B) 605(1014B) 602(1014B) 599(1014B) 596(1014B) 593(1014B) 590(1014B) 587(1014B) 584(1014B) 581(1014B) 578(1014B) 575(1013B) 572(1014B) 569(1014B) 566(2490B) 563(1488KB) 561(8590KB) 555(507KB) 552(3874KB)], [550(55MB)]
2017-09-11 15:37:35.778018 7fa3eeb23700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1505115455778002, "job": 3, "event": "compaction_started", "files_L0": [662, 659, 653, 650, 647, 644, 641, 638, 635, 632, 629, 626, 623, 620, 617, 614, 611, 608, 605, 602, 599, 596, 593, 590, 587, 584, 581, 578, 575, 572, 569, 566, 563, 561, 555, 552], "files_L1": [550], "score": 9, "input_data_size": 72868861}
2017-09-11 15:37:35.796529 7fa40712fb80 1 freelist init
2017-09-11 15:37:35.800106 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) _open_alloc opening allocation metadata
2017-09-11 15:37:36.278054 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) _open_alloc loaded 19482 M in 74 extents
2017-09-11 15:37:36.332514 7fa40712fb80 1 bluefs fsck
2017-09-11 15:37:36.332532 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) fsck walking object keyspace
2017-09-11 15:37:36.569070 7fa40712fb80 -1 bluestore(/var/lib/ceph/osd/ceph-1) #1:036a0e7a:::rbd_data.ac347612200854.000000000000077f:head# extent 0x63a000000~400000 or a subset is already allocated
2017-09-11 15:37:37.416898 7fa40712fb80 -1 bluestore(/var/lib/ceph/osd/ceph-1) #1:f1f324e7:::rbd_data.ac347612200854.0000000000000700:head# extent 0x5bf400000~400000 or a subset is already allocated
2017-09-11 15:37:37.682955 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) fsck checking shared_blobs
2017-09-11 15:37:37.683101 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) fsck checking for stray omap data
2017-09-11 15:37:38.531524 7fa3eeb23700 3 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/db_impl_compaction_flush.cc:1591] Compaction error: Corruption: block checksum mismatch
2017-09-11 15:37:38.531563 7fa3eeb23700 4 rocksdb: (Original Log Time 2017/09/11-15:37:38.531464) [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/compaction_job.cc:621] [default] compacted to: base level 1 max bytes base 268435456 files[36 1 0 0 0 0 0] max score 0.00, MB/sec: 26.5 rd, 22.3 wr, level 1, files in(36, 1) out(1) MB in(14.2, 55.3) out(58.4), read-write-amplify(9.0) write-amplify(4.1) Corruption: block checksum mismatch, records in: 434343, records dropped: 73922
2017-09-11 15:37:38.531579 7fa3eeb23700 4 rocksdb: (Original Log Time 2017/09/11-15:37:38.531513) EVENT_LOG_v1 {"time_micros": 1505115458531499, "job": 3, "event": "compaction_finished", "compaction_time_micros": 2753414, "output_level": 1, "num_output_files": 1, "total_output_size": 61273670, "num_input_records": 419944, "num_output_records": 346022, "num_subcompactions": 1, "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 4, "lsm_state": [36, 1, 0, 0, 0, 0, 0]}
2017-09-11 15:37:38.531583 7fa3eeb23700 2 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/db_impl_compaction_flush.cc:1275] Waiting after background compaction error: Corruption: block checksum mismatch, Accumulated background error counts: 1
2017-09-11 15:37:39.533104 7fa3eeb23700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1505115459533098, "job": 3, "event": "table_file_deletion", "file_number": 1033}
2017-09-11 15:37:46.242978 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) fsck checking deferred events
2017-09-11 15:37:46.245967 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) fsck checking freelist vs allocated
2017-09-11 15:37:46.534257 7fa40712fb80 -1 bluestore(/var/lib/ceph/osd/ceph-1) fsck error: leaked some space;3221225472 bytes leaked
2017-09-11 15:37:46.558607 7fa40712fb80 1 freelist shutdown
2017-09-11 15:37:46.558733 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/db_impl.cc:217] Shutdown: canceling all background work
2017-09-11 15:37:46.559434 7fa40712fb80 4 rocksdb: [/clove/vm/renhw/ceph/rpmbuild/BUILD/ceph-12.1.0.5/src/rocksdb/db/db_impl.cc:343] Shutdown complete
2017-09-11 15:37:46.583603 7fa40712fb80 1 bluefs umount
2017-09-11 15:37:46.651657 7fa40712fb80 1 bdev(0x7fa409c35000 /var/lib/ceph/osd/ceph-1/block.wal) close
2017-09-11 15:37:46.920146 7fa40712fb80 1 bdev(0x7fa409c34c00 /var/lib/ceph/osd/ceph-1/block.db) close
2017-09-11 15:37:47.031649 7fa40712fb80 1 bdev(0x7fa409c34e00 /var/lib/ceph/osd/ceph-1/block) close
2017-09-11 15:37:47.248674 7fa40712fb80 1 bdev(0x7fa409c34a00 /var/lib/ceph/osd/ceph-1/block) close
2017-09-11 15:37:47.461867 7fa40712fb80 1 bluestore(/var/lib/ceph/osd/ceph-1) fsck finish with 3 errors in 11.763728 seconds
Updated by Josh Durgin over 6 years ago
- Project changed from Ceph to RADOS
- Category changed from OSD to Correctness/Safety
- Priority changed from Normal to Urgent
- Component(RADOS) BlueStore added
potentially a bug in bluefs
Updated by wei qiaomiao over 6 years ago
This issue can reproduce in our cluster, we are willing to give more information if you need.
Updated by Daniel Oliveira over 6 years ago
@Wei,
Please, would you mind describing a bit more your environment? Also, how often does it happen? Can we reproduce it at will?
Thanks,
Updated by Sage Weil over 6 years ago
- Status changed from New to Need More Info
Can you please upgrade to 12.2.0 (or better yet, latest luminous branch), and then run fsck and attach the output?
CEPH_ARGS="--debug-bluestore 20 --err-to-stderr --log-file out" ceph-bluestore-tool fsck --path /var/lib/ceph/osd/ceph-NNN
And see if the issue still reproduces then?
Updated by wei qiaomiao over 6 years ago
Daniel Oliveira wrote:
@Wei,
Please, would you mind describing a bit more your environment? Also, how often does it happen? Can we reproduce it at will?
Thanks,
Hi, Daniel.
Our cluster run 12.2.0 Ceph Version with 3 nodes total, and every node run 10 OSDs （OSD run on 1TB SATA HDD，DB and WAL run on Intel 3500 800G SSD, all of disks looks fine through smart）. When we use Vdbench run 128K randwrite through nbd, OSD crash after 8～10 hours. We found all of crash SST files were in db.slow dir. We think it may be happy when the L0 SST compact to L1 SST but we found we are wrong when we check it with "options.paranoid_file_checks=true"(With options.paranoid_file_checks=true, it read all the data from the file after generating an SST file, no matter which level it is)，So this happen after an SST file generate.
Updated by 黄 维 over 6 years ago
Sage Weil wrote:
Can you please upgrade to 12.2.0 (or better yet, latest luminous branch), and then run fsck and attach the output?
CEPH_ARGS="--debug-bluestore 20 --err-to-stderr --log-file out" ceph-bluestore-tool fsck --path /var/lib/ceph/osd/ceph-NNN
And see if the issue still reproduces then?
Updated by wei qiaomiao over 6 years ago
@Sage Weil @Daniel Huang and I use the same cluster. We use xfs insteads of bluefs for some osds in our cluster, the issue was not reproduces on them.May be this is a bluefs bug or there is some thing different between xfs and bluefs when they use for db?
Updated by Daniel Oliveira over 6 years ago
@Wei,
Yes, the log file shows the same error with 12.2.0 build running on. I agree with @Josh Jones and you, it seems to be a problem with bluefs.
So, no OSD running on xfs shows the problem in question, right?
I will check it out and see if I can find something interesting on this.
Updated by wei qiaomiao over 6 years ago
@Daniel，
Yes.no OSD running on xfs shows the problem in question. I think one of different between the db based on xfs and the db based on bluefs is the db based on xfs does not contain db.slow dir, it mean all db data is located in ssd disk. To confirm that We take the db.slow dir out of bluefs, and no OSD running on bluefs hit this issue again. May be there is some wrong with our hdd disks, but all of disks looks fine through smart. Any suggestion?
Updated by Sage Weil over 6 years ago
Can you repeat the fsck with --debug-bluefs 20?
CEPH_ARGS="--debug-bluestore 20 --debug-bluefs 20 --err-to-stderr --log-file out" ceph-bluestore-tool fsck --path /var/lib/ceph/osd/ceph-NNN
Also, is it possible to reproduce this with debug bluefs = 20? I suspect if you reduce the size of the db partition it will trigger much sooner than 8 hours!
Updated by Sage Weil over 6 years ago
- Priority changed from Urgent to Immediate
Updated by 黄 维 over 6 years ago
After merged the following pacths, the error did't happend again. You can close the issue. Thanks!
pacth list:
https://github.com/ceph/ceph/pull/17698
https://github.com/ceph/ceph/pull/17610
https://github.com/ceph/ceph/pull/17511