Bug #20856: osd: luminous osd bluestore crashes with jemalloc enabled on debian 9 - Ceph - Ceph

Actions

Copy link

Bug #20856

closed

osd: luminous osd bluestore crashes with jemalloc enabled on debian 9

Added by Tom Myny over 6 years ago. Updated over 6 years ago.

Status:

Duplicate

Priority:

Normal

Assignee:

Category:

OSD

Target version:

v12.1.0

% Done:

Source:

Community (user)

Tags:

Backport:

Regression:

Severity:

2 - major

Reviewed:

Affected Versions:

v12.1.0

ceph-qa-suite:

Pull request ID:

Crash signature (v1):

Crash signature (v2):

Description

Hello,

When I enable jemalloc on debian 9 we see osd crashes when creating load on the cluster.

We enable jemalloc by uncommenting

LD_PRELOAD=/usr/lib/x86_64-linux-gnu/libjemalloc.so.1

in /etc/default/ceph (libjemalloc is installed as package).

We see the following in the osd log:

7> 2017-07-30 20:35:36.405417 7fdce23fe700  1 - 10.10.14.100:6823/4789 <== osd.4 10.10.14.101:6819/4059 3639 ==== osd_repop_reply(client.5237.0:359825 3.1bf e10309/327) v2 ==== 111+0+0 (1382998248 0 0) 0x563a76171b80 con 0x563a78419800
    6> 2017-07-30 20:35:36.405697 7fdce23fe700  5 - 10.10.14.100:6823/4789 >> 10.10.14.101:6819/4059 conn(0x563a78419800 :6823 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=6 cs=1 l=0). rx osd.4 seq 3640 0x563a76170f00 osd_repop_reply(client.5237.0:359826 3.1bf e10309/327) v2
    5> 2017-07-30 20:35:36.405709 7fdce23fe700  1 - 10.10.14.100:6823/4789 <== osd.4 10.10.14.101:6819/4059 3640 ==== osd_repop_reply(client.5237.0:359826 3.1bf e10309/327) v2 ==== 111+0+0 (3148751318 0 0) 0x563a76170f00 con 0x563a78419800
    4> 2017-07-30 20:35:36.408137 7fdce23fe700  5 - 10.10.14.100:6823/4789 >> 10.10.14.101:6819/4059 conn(0x563a78419800 :6823 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=6 cs=1 l=0). rx osd.4 seq 3641 0x563a76170500 osd_repop_reply(client.5237.0:359827 3.1bf e10309/327) v2
    3> 2017-07-30 20:35:36.408153 7fdce23fe700  1 - 10.10.14.100:6823/4789 <== osd.4 10.10.14.101:6819/4059 3641 ==== osd_repop_reply(client.5237.0:359827 3.1bf e10309/327) v2 ==== 111+0+0 (601649758 0 0) 0x563a76170500 con 0x563a78419800
    2> 2017-07-30 20:35:36.411901 7fdce23fe700  5 - 10.10.14.100:6823/4789 >> 10.10.14.101:6819/4059 conn(0x563a78419800 :6823 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=6 cs=1 l=0). rx osd.4 seq 3642 0x563a76173980 osd_repop_reply(client.5237.0:359828 3.1bf e10309/327) v2
    1> 2017-07-30 20:35:36.411915 7fdce23fe700  1 - 10.10.14.100:6823/4789 <== osd.4 10.10.14.101:6819/4059 3642 ==== osd_repop_reply(client.5237.0:359828 3.1bf e10309/327) v2 ==== 111+0+0 (533428633 0 0) 0x563a76173980 con 0x563a78419800
     0> 2017-07-30 20:35:36.419527 7fdcccbe8700 -1 ** Caught signal (Segmentation fault) *
 in thread 7fdcccbe8700 thread_name:tp_osd_tp

ceph version 12.1.1 (f3e663a190bf2ed12c7e3cda288b9a159572c800) luminous (rc)
 1: (()+0x9dedf4) [0x563a6a65bdf4]
 2: (()+0x110c0) [0x7fdce6dd10c0]
 3: (()+0x1ff2f) [0x7fdce93d3f2f]
 4: (rocksdb::BlockBasedTable::PutDataBlockToCache(rocksdb::Slice const&, rocksdb::Slice const&, rocksdb::Cache*, rocksdb::Cache*, rocksdb::ReadOptions const&, rocksdb::ImmutableCFOptions const&, rocksdb::BlockBasedTable::CachableEntry&lt;rocksdb::Block&gt;*, rocksdb::Block*, unsigned int, rocksdb::Slice const&, unsigned long, bool, rocksdb::Cache::Priority)+0x1a5) [0x563a6a992ba5]
 5: (rocksdb::BlockBasedTable::MaybeLoadDataBlockToCache(rocksdb::BlockBasedTable::Rep*, rocksdb::ReadOptions const&, rocksdb::BlockHandle const&, rocksdb::Slice, rocksdb::BlockBasedTable::CachableEntry&lt;rocksdb::Block&gt;*, bool)+0x36f) [0x563a6a99445f]
 6: (rocksdb::BlockBasedTable::NewDataBlockIterator(rocksdb::BlockBasedTable::Rep*, rocksdb::ReadOptions const&, rocksdb::BlockHandle const&, rocksdb::BlockIter*, bool, rocksdb::Status)+0x29c) [0x563a6a99478c]
 7: (rocksdb::BlockBasedTable::NewDataBlockIterator(rocksdb::BlockBasedTable::Rep*, rocksdb::ReadOptions const&, rocksdb::Slice const&, rocksdb::BlockIter*, bool)+0x89) [0x563a6a994bf9]
 8: (rocksdb::BlockBasedTable::Get(rocksdb::ReadOptions const&, rocksdb::Slice const&, rocksdb::GetContext*, bool)+0x554) [0x563a6a996da4]
 9: (rocksdb::TableCache::Get(rocksdb::ReadOptions const&, rocksdb::InternalKeyComparator const&, rocksdb::FileDescriptor const&, rocksdb::Slice const&, rocksdb::GetContext*, rocksdb::HistogramImpl*, bool, int)+0x13a) [0x563a6aa762fa]
 10: (rocksdb::Version::Get(rocksdb::ReadOptions const&, rocksdb::LookupKey const&, rocksdb::PinnableSlice*, rocksdb::Status*, rocksdb::MergeContext*, rocksdb::RangeDelAggregator*, bool*, bool*, unsigned long*)+0x3f8) [0x563a6a957d98]
 11: (rocksdb::DBImpl::GetImpl(rocksdb::ReadOptions const&, rocksdb::ColumnFamilyHandle*, rocksdb::Slice const&, rocksdb::PinnableSlice*, bool*)+0x552) [0x563a6aa1c7f2]
 12: (rocksdb::DBImpl::Get(rocksdb::ReadOptions const&, rocksdb::ColumnFamilyHandle*, rocksdb::Slice const&, rocksdb::PinnableSlice*)+0x13) [0x563a6aa1cc23]
 13: (rocksdb::DB::Get(rocksdb::ReadOptions const&, rocksdb::Slice const&, std::__cxx11::basic_string&lt;char, std::char_traits&lt;char&gt;, std::allocator&lt;char&gt; >)+0xc1) [0x563a6a5a4db1]
 14: (RocksDBStore::get(std::__cxx11::basic_string&lt;char, std::char_traits&lt;char&gt;, std::allocator&lt;char&gt; > const&, char const, unsigned long, ceph::buffer::list*)+0x158) [0x563a6a59c168]
 15: (BlueStore::Collection::get_onode(ghobject_t const&, bool)+0x5ae) [0x563a6a52232e]
 16: (BlueStore::_txc_add_transaction(BlueStore::TransContext*, ObjectStore::Transaction*)+0xa54) [0x563a6a5582b4]
 17: (BlueStore::queue_transactions(ObjectStore::Sequencer*, std::vector&lt;ObjectStore::Transaction, std::allocator&lt;ObjectStore::Transaction&gt; >&, boost::intrusive_ptr&lt;TrackedOp&gt;, ThreadPool::TPHandle*)+0x536) [0x563a6a55a406]
 18: (PrimaryLogPG::queue_transactions(std::vector&lt;ObjectStore::Transaction, std::allocator&lt;ObjectStore::Transaction&gt; >&, boost::intrusive_ptr&lt;OpRequest&gt;)+0x66) [0x563a6a287a06]
 19: (ReplicatedBackend::do_repop(boost::intrusive_ptr&lt;OpRequest&gt;)+0xbd9) [0x563a6a3ab469]
 20: (ReplicatedBackend::handle_message(boost::intrusive_ptr&lt;OpRequest&gt;)+0x2b7) [0x563a6a3ae237]
 21: (PrimaryLogPG::do_request(boost::intrusive_ptr&lt;OpRequest&gt;&, ThreadPool::TPHandle&)+0x4e7) [0x563a6a22a287]
 22: (OSD::dequeue_op(boost::intrusive_ptr&lt;PG&gt;, boost::intrusive_ptr&lt;OpRequest&gt;, ThreadPool::TPHandle&)+0x3ab) [0x563a6a0ba57b]
 23: (PGQueueable::RunVis::operator()(boost::intrusive_ptr&lt;OpRequest&gt; const&)+0x5a) [0x563a6a33e3ea]
 24: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x103d) [0x563a6a0e0f8d]
 25: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x9b0) [0x563a6a6a7ab0]
 26: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x563a6a6aafd0]
 27: (()+0x7494) [0x7fdce6dc7494]
 28: (clone()+0x3f) [0x7fdce5e4eaff]
 NOTE: a copy of the executable, or `objdump -rdS &lt;executable&gt;` is needed to interpret this.

--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
1/ 5 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 rbd_mirror
0/ 5 rbd_replay
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
1/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 ms
1/ 5 mon
0/10 monc
1/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/10 civetweb
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
0/ 0 refs
1/ 5 xio
1/ 5 compressor
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
4/ 5 rocksdb
4/ 5 leveldb
4/ 5 memdb
1/ 5 kinetic
1/ 5 fuse
1/ 5 mgr
1/ 5 mgrc
1/ 5 dpdk
1/ 5 eventtrace
2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-osd.7.log
-- end dump of recent events ---
2017-07-30 20:35:56.800721 7f1331415cc0 0 set uid:gid to 64045:64045 (ceph:ceph)
2017-07-30 20:35:56.800738 7f1331415cc0 0 ceph version 12.1.1 (f3e663a190bf2ed12c7e3cda288b9a159572c800) luminous (rc), process (unknown), pid 15510
2017-07-30 20:35:56.804335 7f1331415cc0 0 pidfile_write: ignore empty --pid-file
2017-07-30 20:35:56.814592 7f1331415cc0 0 load: jerasure load: lrc load: isa
2017-07-30 20:35:56.814666 7f1331415cc0 1 bdev create path /var/lib/ceph/osd/ceph-7/block type kernel
2017-07-30 20:35:56.814672 7f1331415cc0 1 bdev(0x564646c2a6c0 /var/lib/ceph/osd/ceph-7/block) open path /var/lib/ceph/osd/ceph-7/block
2017-07-30 20:35:56.814925 7f1331415cc0 1 bdev(0x564646c2a6c0 /var/lib/ceph/osd/ceph-7/block) open size 1919610236928 (0x1bef1afb000, 1787 GB) block_size 4096 (4096 B) rotational
2017-07-30 20:35:56.815254 7f1331415cc0 1 bluestore(/var/lib/ceph/osd/ceph-7) _set_cache_sizes max 0.5 < ratio 0.99
2017-07-30 20:35:56.815294 7f1331415cc0 1 bluestore(/var/lib/ceph/osd/ceph-7) _set_cache_sizes cache_size 1073741824 meta 0.5 kv 0.5 data 0
2017-07-30 20:35:56.815301 7f1331415cc0 1 bdev(0x564646c2a6c0 /var/lib/ceph/osd/ceph-7/block) close
2017-07-30 20:35:57.112892 7f1331415cc0 1 bluestore(/var/lib/ceph/osd/ceph-7) _mount path /var/lib/ceph/osd/ceph-7
2017-07-30 20:35:57.112917 7f1331415cc0 1 bdev create path /var/lib/ceph/osd/ceph-7/block type kernel
2017-07-30 20:35:57.112922 7f1331415cc0 1 bdev(0x564646c2a900 /var/lib/ceph/osd/ceph-7/block) open path /var/lib/ceph/osd/ceph-7/block
2017-07-30 20:35:57.113077 7f1331415cc0 1 bdev(0x564646c2a900 /var/lib/ceph/osd/ceph-7/block) open size 1919610236928 (0x1bef1afb000, 1787 GB) block_size 4096 (4096 B) rotational
2017-07-30 20:35:57.113352 7f1331415cc0 1 bluestore(/var/lib/ceph/osd/ceph-7) _set_cache_sizes max 0.5 < ratio 0.99
2017-07-30 20:35:57.113366 7f1331415cc0 1 bluestore(/var/lib/ceph/osd/ceph-7) _set_cache_sizes cache_size 1073741824 meta 0.5 kv 0.5 data 0
2017-07-30 20:35:57.113413 7f1331415cc0 1 bdev create path /var/lib/ceph/osd/ceph-7/block type kernel
2017-07-30 20:35:57.113417 7f1331415cc0 1 bdev(0x564646c2ab40 /var/lib/ceph/osd/ceph-7/block) open path /var/lib/ceph/osd/ceph-7/block
2017-07-30 20:35:57.113542 7f1331415cc0 1 bdev(0x564646c2ab40 /var/lib/ceph/osd/ceph-7/block) open size 1919610236928 (0x1bef1afb000, 1787 GB) block_size 4096 (4096 B) rotational
2017-07-30 20:35:57.113546 7f1331415cc0 1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-7/block size 1787 GB
2017-07-30 20:35:57.113577 7f1331415cc0 1 bluefs mount
2017-07-30 20:35:57.243313 7f1331415cc0 0 set rocksdb option compaction_readahead_size = 2097152
2017-07-30 20:35:57.243386 7f1331415cc0 0 set rocksdb option compression = kNoCompression
2017-07-30 20:35:57.243410 7f1331415cc0 0 set rocksdb option max_write_buffer_number = 4
2017-07-30 20:35:57.243426 7f1331415cc0 0 set rocksdb option min_write_buffer_number_to_merge = 1
2017-07-30 20:35:57.243440 7f1331415cc0 0 set rocksdb option recycle_log_file_num = 4
2017-07-30 20:35:57.243454 7f1331415cc0 0 set rocksdb option writable_file_max_buffer_size = 0
2017-07-30 20:35:57.243469 7f1331415cc0 0 set rocksdb option write_buffer_size = 268435456
2017-07-30 20:35:57.243505 7f1331415cc0 0 set rocksdb option compaction_readahead_size = 2097152
2017-07-30 20:35:57.243522 7f1331415cc0 0 set rocksdb option compression = kNoCompression
2017-07-30 20:35:57.243538 7f1331415cc0 0 set rocksdb option max_write_buffer_number = 4
2017-07-30 20:35:57.243552 7f1331415cc0 0 set rocksdb option min_write_buffer_number_to_merge = 1
2017-07-30 20:35:57.243565 7f1331415cc0 0 set rocksdb option recycle_log_file_num = 4
2017-07-30 20:35:57.243582 7f1331415cc0 0 set rocksdb option writable_file_max_buffer_size = 0
2017-07-30 20:35:57.243596 7f1331415cc0 0 set rocksdb option write_buffer_size = 268435456
2017-07-30 20:35:57.243734 7f1331415cc0 4 rocksdb: RocksDB version: 5.4.0

2017-07-30 20:35:57.243758 7f1331415cc0 4 rocksdb: Git sha rocksdb_build_git_sha:0
2017-07-30 20:35:57.243769 7f1331415cc0 4 rocksdb: Compile date Jul 17 2017
2017-07-30 20:35:57.243781 7f1331415cc0 4 rocksdb: DB SUMMARY

2017-07-30 20:35:57.243812 7f1331415cc0 4 rocksdb: CURRENT file: CURRENT

2017-07-30 20:35:57.243824 7f1331415cc0 4 rocksdb: IDENTITY file: IDENTITY

2017-07-30 20:35:57.243836 7f1331415cc0 4 rocksdb: MANIFEST file: MANIFEST-000047 size: 292 Bytes

2017-07-30 20:35:57.243848 7f1331415cc0 4 rocksdb: SST files in db dir, Total Num: 4, files: 000044.sst 000046.sst 000052.sst 000054.sst

2017-07-30 20:35:57.243860 7f1331415cc0 4 rocksdb: Write Ahead Log file in db: 000051.log size: 231336402 ; 000053.log size: 105535122 ;

2017-07-30 20:35:57.243871 7f1331415cc0 4 rocksdb: Options.error_if_exists: 0
2017-07-30 20:35:57.243881 7f1331415cc0 4 rocksdb: Options.create_if_missing: 0
2017-07-30 20:35:57.243891 7f1331415cc0 4 rocksdb: Options.paranoid_checks: 1
2017-07-30 20:35:57.243901 7f1331415cc0 4 rocksdb: Options.env: 0x564646d23a60
2017-07-30 20:35:57.243912 7f1331415cc0 4 rocksdb: Options.info_log: 0x564646d23fc0
2017-07-30 20:35:57.243923 7f1331415cc0 4 rocksdb: Options.max_open_files: -1
2017-07-30 20:35:57.243933 7f1331415cc0 4 rocksdb: Options.max_file_opening_threads: 16
2017-07-30 20:35:57.243943 7f1331415cc0 4 rocksdb: Options.use_fsync: 0
2017-07-30 20:35:57.243953 7f1331415cc0 4 rocksdb: Options.max_log_file_size: 0
2017-07-30 20:35:57.243963 7f1331415cc0 4 rocksdb: Options.max_manifest_file_size: 18446744073709551615
2017-07-30 20:35:57.243973 7f1331415cc0 4 rocksdb: Options.log_file_time_to_roll: 0
2017-07-30 20:35:57.243983 7f1331415cc0 4 rocksdb: Options.keep_log_file_num: 1000
2017-07-30 20:35:57.243994 7f1331415cc0 4 rocksdb: Options.recycle_log_file_num: 4
2017-07-30 20:35:57.244003 7f1331415cc0 4 rocksdb: Options.allow_fallocate: 1
2017-07-30 20:35:57.244013 7f1331415cc0 4 rocksdb: Options.allow_mmap_reads: 0
2017-07-30 20:35:57.244023 7f1331415cc0 4 rocksdb: Options.allow_mmap_writes: 0
2017-07-30 20:35:57.244033 7f1331415cc0 4 rocksdb: Options.use_direct_reads: 0
2017-07-30 20:35:57.244043 7f1331415cc0 4 rocksdb: Options.use_direct_io_for_flush_and_compaction: 0
2017-07-30 20:35:57.244063 7f1331415cc0 4 rocksdb: Options.create_missing_column_families: 0
2017-07-30 20:35:57.244074 7f1331415cc0 4 rocksdb: Options.db_log_dir:
2017-07-30 20:35:57.244084 7f1331415cc0 4 rocksdb: Options.wal_dir: db
2017-07-30 20:35:57.244096 7f1331415cc0 4 rocksdb: Options.table_cache_numshardbits: 6
2017-07-30 20:35:57.244106 7f1331415cc0 4 rocksdb: Options.max_subcompactions: 1
2017-07-30 20:35:57.244115 7f1331415cc0 4 rocksdb: Options.max_background_flushes: 1
2017-07-30 20:35:57.244125 7f1331415cc0 4 rocksdb: Options.WAL_ttl_seconds: 0
2017-07-30 20:35:57.244134 7f1331415cc0 4 rocksdb: Options.WAL_size_limit_MB: 0
2017-07-30 20:35:57.244145 7f1331415cc0 4 rocksdb: Options.manifest_preallocation_size: 4194304
2017-07-30 20:35:57.244161 7f1331415cc0 4 rocksdb: Options.is_fd_close_on_exec: 1
2017-07-30 20:35:57.244171 7f1331415cc0 4 rocksdb: Options.advise_random_on_open: 1
2017-07-30 20:35:57.244181 7f1331415cc0 4 rocksdb: Options.db_write_buffer_size: 0
2017-07-30 20:35:57.244191 7f1331415cc0 4 rocksdb: Options.access_hint_on_compaction_start: 1
2017-07-30 20:35:57.244200 7f1331415cc0 4 rocksdb: Options.new_table_reader_for_compaction_inputs: 1
2017-07-30 20:35:57.244210 7f1331415cc0 4 rocksdb: Options.compaction_readahead_size: 2097152
2017-07-30 20:35:57.244227 7f1331415cc0 4 rocksdb: Options.random_access_max_buffer_size: 1048576
2017-07-30 20:35:57.244236 7f1331415cc0 4 rocksdb: Options.writable_file_max_buffer_size: 0
2017-07-30 20:35:57.244246 7f1331415cc0 4 rocksdb: Options.use_adaptive_mutex: 0
2017-07-30 20:35:57.244256 7f1331415cc0 4 rocksdb: Options.rate_limiter: (nil)
2017-07-30 20:35:57.244267 7f1331415cc0 4 rocksdb: Options.sst_file_manager.rate_bytes_per_sec: 0
2017-07-30 20:35:57.244283 7f1331415cc0 4 rocksdb: Options.bytes_per_sync: 0
2017-07-30 20:35:57.244292 7f1331415cc0 4 rocksdb: Options.wal_bytes_per_sync: 0
2017-07-30 20:35:57.244302 7f1331415cc0 4 rocksdb: Options.wal_recovery_mode: 0
2017-07-30 20:35:57.244311 7f1331415cc0 4 rocksdb: Options.enable_thread_tracking: 0
2017-07-30 20:35:57.244321 7f1331415cc0 4 rocksdb: Options.allow_concurrent_memtable_write: 1
2017-07-30 20:35:57.244331 7f1331415cc0 4 rocksdb: Options.enable_write_thread_adaptive_yield: 1
2017-07-30 20:35:57.244348 7f1331415cc0 4 rocksdb: Options.write_thread_max_yield_usec: 100
2017-07-30 20:35:57.244357 7f1331415cc0 4 rocksdb: Options.write_thread_slow_yield_usec: 3
2017-07-30 20:35:57.244366 7f1331415cc0 4 rocksdb: Options.row_cache: None
2017-07-30 20:35:57.244376 7f1331415cc0 4 rocksdb: Options.wal_filter: None
2017-07-30 20:35:57.244386 7f1331415cc0 4 rocksdb: Options.avoid_flush_during_recovery: 0
2017-07-30 20:35:57.244397 7f1331415cc0 4 rocksdb: Options.base_background_compactions: 1
2017-07-30 20:35:57.244413 7f1331415cc0 4 rocksdb: Options.max_background_compactions: 1
2017-07-30 20:35:57.244422 7f1331415cc0 4 rocksdb: Options.avoid_flush_during_shutdown: 0
2017-07-30 20:35:57.244432 7f1331415cc0 4 rocksdb: Options.delayed_write_rate : 16777216
2017-07-30 20:35:57.244441 7f1331415cc0 4 rocksdb: Options.max_total_wal_size: 0
2017-07-30 20:35:57.244450 7f1331415cc0 4 rocksdb: Options.delete_obsolete_files_period_micros: 21600000000
2017-07-30 20:35:57.244460 7f1331415cc0 4 rocksdb: Options.stats_dump_period_sec: 600
2017-07-30 20:35:57.244474 7f1331415cc0 4 rocksdb: Compression algorithms supported:
2017-07-30 20:35:57.244487 7f1331415cc0 4 rocksdb: Snappy supported: 0
2017-07-30 20:35:57.244497 7f1331415cc0 4 rocksdb: Zlib supported: 0
2017-07-30 20:35:57.244507 7f1331415cc0 4 rocksdb: Bzip supported: 0
2017-07-30 20:35:57.244517 7f1331415cc0 4 rocksdb: LZ4 supported: 0
2017-07-30 20:35:57.244526 7f1331415cc0 4 rocksdb: ZSTD supported: 0
2017-07-30 20:35:57.244545 7f1331415cc0 4 rocksdb: Fast CRC32 supported: 1
2017-07-30 20:35:57.244779 7f1331415cc0 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/version_set.cc:2609] Recovering from manifest file: MANIFEST-000047

2017-07-30 20:35:57.244885 7f1331415cc0 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/column_family.cc:407] --------------- Options for column family [default]:

2017-07-30 20:35:57.244904 7f1331415cc0 4 rocksdb: Options.comparator: leveldb.BytewiseComparator
2017-07-30 20:35:57.244928 7f1331415cc0 4 rocksdb: Options.merge_operator: .T:int64_array.b:bitwise_xor
2017-07-30 20:35:57.244938 7f1331415cc0 4 rocksdb: Options.compaction_filter: None
2017-07-30 20:35:57.244948 7f1331415cc0 4 rocksdb: Options.compaction_filter_factory: None
2017-07-30 20:35:57.244960 7f1331415cc0 4 rocksdb: Options.memtable_factory: SkipListFactory
2017-07-30 20:35:57.244970 7f1331415cc0 4 rocksdb: Options.table_factory: BlockBasedTable
2017-07-30 20:35:57.244999 7f1331415cc0 4 rocksdb: table_factory options: flush_block_policy_factory: FlushBlockBySizePolicyFactory (0x564646ae4120)
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: 0x564646afa310
block_cache_name: LRUCache
block_cache_options:
capacity : 536870912
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-07-30 20:35:57.245145 7f1331415cc0 4 rocksdb: Options.write_buffer_size: 268435456
2017-07-30 20:35:57.245162 7f1331415cc0 4 rocksdb: Options.max_write_buffer_number: 4
2017-07-30 20:35:57.245173 7f1331415cc0 4 rocksdb: Options.compression: NoCompression
2017-07-30 20:35:57.245183 7f1331415cc0 4 rocksdb: Options.bottommost_compression: Disabled
2017-07-30 20:35:57.245193 7f1331415cc0 4 rocksdb: Options.prefix_extractor: nullptr
2017-07-30 20:35:57.245204 7f1331415cc0 4 rocksdb: Options.memtable_insert_with_hint_prefix_extractor: nullptr
2017-07-30 20:35:57.245221 7f1331415cc0 4 rocksdb: Options.num_levels: 7
2017-07-30 20:35:57.245232 7f1331415cc0 4 rocksdb: Options.min_write_buffer_number_to_merge: 1
2017-07-30 20:35:57.245242 7f1331415cc0 4 rocksdb: Options.max_write_buffer_number_to_maintain: 0
2017-07-30 20:35:57.245252 7f1331415cc0 4 rocksdb: Options.compression_opts.window_bits: -14
2017-07-30 20:35:57.245262 7f1331415cc0 4 rocksdb: Options.compression_opts.level: -1
2017-07-30 20:35:57.245273 7f1331415cc0 4 rocksdb: Options.compression_opts.strategy: 0
2017-07-30 20:35:57.245283 7f1331415cc0 4 rocksdb: Options.compression_opts.max_dict_bytes: 0
2017-07-30 20:35:57.245293 7f1331415cc0 4 rocksdb: Options.level0_file_num_compaction_trigger: 4
2017-07-30 20:35:57.245303 7f1331415cc0 4 rocksdb: Options.level0_slowdown_writes_trigger: 20
2017-07-30 20:35:57.245313 7f1331415cc0 4 rocksdb: Options.level0_stop_writes_trigger: 36
2017-07-30 20:35:57.245322 7f1331415cc0 4 rocksdb: Options.target_file_size_base: 67108864
2017-07-30 20:35:57.245332 7f1331415cc0 4 rocksdb: Options.target_file_size_multiplier: 1
2017-07-30 20:35:57.245343 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_base: 268435456
2017-07-30 20:35:57.245357 7f1331415cc0 4 rocksdb: Options.level_compaction_dynamic_level_bytes: 0
2017-07-30 20:35:57.245368 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_multiplier: 10.000000
2017-07-30 20:35:57.245380 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl⁰: 1
2017-07-30 20:35:57.245390 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl¹: 1
2017-07-30 20:35:57.245400 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl²: 1
2017-07-30 20:35:57.245410 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl³: 1
2017-07-30 20:35:57.245421 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl⁴: 1
2017-07-30 20:35:57.245431 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl⁵: 1
2017-07-30 20:35:57.245441 7f1331415cc0 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl⁶: 1
2017-07-30 20:35:57.245453 7f1331415cc0 4 rocksdb: Options.max_sequential_skip_in_iterations: 8
2017-07-30 20:35:57.245468 7f1331415cc0 4 rocksdb: Options.max_compaction_bytes: 1677721600
2017-07-30 20:35:57.245479 7f1331415cc0 4 rocksdb: Options.arena_block_size: 33554432
2017-07-30 20:35:57.245489 7f1331415cc0 4 rocksdb: Options.soft_pending_compaction_bytes_limit: 68719476736
2017-07-30 20:35:57.245499 7f1331415cc0 4 rocksdb: Options.hard_pending_compaction_bytes_limit: 274877906944
2017-07-30 20:35:57.245508 7f1331415cc0 4 rocksdb: Options.rate_limit_delay_max_milliseconds: 100
2017-07-30 20:35:57.245519 7f1331415cc0 4 rocksdb: Options.disable_auto_compactions: 0
2017-07-30 20:35:57.245530 7f1331415cc0 4 rocksdb: Options.compaction_style: kCompactionStyleLevel
2017-07-30 20:35:57.245541 7f1331415cc0 4 rocksdb: Options.compaction_pri: kByCompensatedSize
2017-07-30 20:35:57.245551 7f1331415cc0 4 rocksdb: Options.compaction_options_universal.size_ratio: 1
2017-07-30 20:35:57.245560 7f1331415cc0 4 rocksdb: Options.compaction_options_universal.min_merge_width: 2
2017-07-30 20:35:57.245573 7f1331415cc0 4 rocksdb: Options.compaction_options_universal.max_merge_width: 4294967295
2017-07-30 20:35:57.245583 7f1331415cc0 4 rocksdb: Options.compaction_options_universal.max_size_amplification_percent: 200
2017-07-30 20:35:57.245593 7f1331415cc0 4 rocksdb: Options.compaction_options_universal.compression_size_percent: -1
2017-07-30 20:35:57.245603 7f1331415cc0 4 rocksdb: Options.compaction_options_fifo.max_table_files_size: 1073741824
2017-07-30 20:35:57.245613 7f1331415cc0 4 rocksdb: Options.table_properties_collectors:
2017-07-30 20:35:57.245626 7f1331415cc0 4 rocksdb: Options.inplace_update_support: 0
2017-07-30 20:35:57.245636 7f1331415cc0 4 rocksdb: Options.inplace_update_num_locks: 10000
2017-07-30 20:35:57.245646 7f1331415cc0 4 rocksdb: Options.memtable_prefix_bloom_size_ratio: 0.000000
2017-07-30 20:35:57.245657 7f1331415cc0 4 rocksdb: Options.memtable_huge_page_size: 0
2017-07-30 20:35:57.245667 7f1331415cc0 4 rocksdb: Options.bloom_locality: 0
2017-07-30 20:35:57.245677 7f1331415cc0 4 rocksdb: Options.max_successive_merges: 0
2017-07-30 20:35:57.245687 7f1331415cc0 4 rocksdb: Options.optimize_filters_for_hits: 0
2017-07-30 20:35:57.245703 7f1331415cc0 4 rocksdb: Options.paranoid_file_checks: 0
2017-07-30 20:35:57.245713 7f1331415cc0 4 rocksdb: Options.force_consistency_checks: 0
2017-07-30 20:35:57.245723 7f1331415cc0 4 rocksdb: Options.report_bg_io_stats: 0
2017-07-30 20:35:57.253625 7f1331415cc0 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/version_set.cc:2859] Recovered from manifest file:db/MANIFEST-000047 succeeded,manifest_file_number is 47, next_file_number is 56, last_sequence is 524027, log_number is 0,prev_log_number is 0,max_column_family is 0

2017-07-30 20:35:57.253640 7f1331415cc0 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/version_set.cc:2867] Column family [default] (ID 0), log number is 53

2017-07-30 20:35:57.253704 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446957253697, "job": 1, "event": "recovery_started", "log_files": [51, 53]}
2017-07-30 20:35:57.253710 7f1331415cc0 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/db_impl_open.cc:482] Recovering log #51 mode 0
2017-07-30 20:35:57.854379 7f1331415cc0 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/db_impl_open.cc:482] Recovering log #53 mode 0
2017-07-30 20:35:58.510186 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446958510170, "cf_name": "default", "job": 1, "event": "table_file_creation", "file_number": 56, "file_size": 9876037, "table_properties": {"data_size": 9676592, "index_size": 198566, "filter_size": 0, "raw_key_size": 1983837, "raw_average_key_size": 51, "raw_value_size": 8559462, "raw_average_value_size": 223, "num_data_blocks": 2412, "num_entries": 38270, "filter_policy_name": "", "kDeletedKeys": "6640", "kMergeOperands": "11908"}}
2017-07-30 20:35:58.559490 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446958559481, "cf_name": "default", "job": 1, "event": "table_file_creation", "file_number": 57, "file_size": 3102740, "table_properties": {"data_size": 3060596, "index_size": 41267, "filter_size": 0, "raw_key_size": 326822, "raw_average_key_size": 51, "raw_value_size": 2902260, "raw_average_value_size": 454, "num_data_blocks": 529, "num_entries": 6384, "filter_policy_name": "", "kDeletedKeys": "35", "kMergeOperands": "2403"}}
2017-07-30 20:35:58.559953 7f1331415cc0 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/version_set.cc:2395] Creating manifest 58

2017-07-30 20:35:58.560646 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446958560644, "job": 1, "event": "recovery_finished"}
2017-07-30 20:35:58.561970 7f1331415cc0 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/db_impl_open.cc:1063] DB pointer 0x564646db2000
2017-07-30 20:35:58.562023 7f1331415cc0 1 bluestore(/var/lib/ceph/osd/ceph-7) _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-07-30 20:35:58.562319 7f131a3fd700 3 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/db_impl.cc:447] ------- DUMPING STATS -------
2017-07-30 20:35:58.562403 7f131a3fd700 3 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/db_impl.cc:448]

DB Stats **
Uptime(secs): 1.3 total, 1.3 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 5/0 37.28 MB 1.2 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 259.6 0 2 0.024 0 0
L1 1/0 29.50 MB 0.1 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 6/0 66.79 MB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 259.6 0 2 0.024 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 259.6 0 2 0.024 0 0
Uptime(secs): 1.3 total, 1.3 interval
Flush(GB): cumulative 0.012, interval 0.012
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.01 GB write, 9.40 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds
Interval compaction: 0.01 GB write, 9.40 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] **

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 5/0 37.28 MB 1.2 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 259.6 0 2 0.024 0 0
L1 1/0 29.50 MB 0.1 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 6/0 66.79 MB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 259.6 0 2 0.024 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): 1.3 total, 1.3 interval
Flush(GB): cumulative 0.012, 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.01 GB write, 9.40 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] **

2017-07-30 20:35:58.562576 7f131a3fd700 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/compaction_job.cc:1403] [default] [JOB 3] Compacting 5@0 + 1@1 files to L1, score 1.25
2017-07-30 20:35:58.562637 7f131a3fd700 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/compaction_job.cc:1407] [default] Compaction start summary: Base version 2 Base level 0, inputs: [57(3030KB) 56(9644KB) 54(17MB) 52(6058KB) 46(1763KB)], [44(29MB)]

2017-07-30 20:35:58.562711 7f131a3fd700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446958562685, "job": 3, "event": "compaction_started", "files_L0": [57, 56, 54, 52, 46], "files_L1": [44], "score": 1.25, "input_data_size": 70031177}
2017-07-30 20:35:58.609371 7f1331415cc0 1 freelist init
2017-07-30 20:35:58.617176 7f1331415cc0 1 bluestore(/var/lib/ceph/osd/ceph-7) _open_alloc opening allocation metadata
2017-07-30 20:35:58.813408 7f1331415cc0 1 bluestore(/var/lib/ceph/osd/ceph-7) _open_alloc loaded 1749 G in 4 extents
2017-07-30 20:35:58.948887 7f1331415cc0 0 <cls> /build/ceph-12.1.1/src/cls/hello/cls_hello.cc:296: loading cls_hello
2017-07-30 20:35:58.950344 7f1331415cc0 0 <cls> /build/ceph-12.1.1/src/cls/cephfs/cls_cephfs.cc:197: loading cephfs
2017-07-30 20:35:58.950645 7f1331415cc0 0 _get_class not permitted to load kvs
2017-07-30 20:35:58.954677 7f1331415cc0 0 _get_class not permitted to load lua
2017-07-30 20:35:58.958284 7f1331415cc0 0 _get_class not permitted to load sdk
2017-07-30 20:35:58.960602 7f1331415cc0 0 osd.7 10309 crush map has features 288514051259236352, adjusting msgr requires for clients
2017-07-30 20:35:58.960661 7f1331415cc0 0 osd.7 10309 crush map has features 288514051259236352 was 8705, adjusting msgr requires for mons
2017-07-30 20:35:58.960713 7f1331415cc0 0 osd.7 10309 crush map has features 1009089991638532096, adjusting msgr requires for osds
2017-07-30 20:35:59.382471 7f131a3fd700 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #62: 211690 keys, 64471283 bytes
2017-07-30 20:35:59.382511 7f131a3fd700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446959382494, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 62, "file_size": 64471283, "table_properties": {"data_size": 63164367, "index_size": 1306038, "filter_size": 0, "raw_key_size": 11001094, "raw_average_key_size": 51, "raw_value_size": 58008012, "raw_average_value_size": 274, "num_data_blocks": 15740, "num_entries": 211690, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "1"}}
2017-07-30 20:35:59.383764 7f131a3fd700 4 rocksdb: [/build/ceph-12.1.1/src/rocksdb/db/compaction_job.cc:1173] [default] [JOB 3] Compacted 5@0 + 1@1 files to L1 => 64471283 bytes
2017-07-30 20:35:59.384233 7f131a3fd700 4 rocksdb: (Original Log Time 2017/07/30-20:35:59.384169) [/build/ceph-12.1.1/src/rocksdb/db/compaction_job.cc:621] [default] compacted to: base level 1 max bytes base 268435456 files[0 1 0 0 0 0 0] max score 0.24, MB/sec: 85.3 rd, 78.5 wr, level 1, files in(5, 1) out(1) MB in(37.3, 29.5) out(61.5), read-write-amplify(3.4) write-amplify(1.6) OK, records in: 238138, records dropped: 25362

2017-07-30 20:35:59.384244 7f131a3fd700 4 rocksdb: (Original Log Time 2017/07/30-20:35:59.384197) EVENT_LOG_v1 {"time_micros": 1501446959384184, "job": 3, "event": "compaction_finished", "compaction_time_micros": 821002, "output_level": 1, "num_output_files": 1, "total_output_size": 64471283, "num_input_records": 237052, "num_output_records": 211690, "num_subcompactions": 1, "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [0, 1, 0, 0, 0, 0, 0]}
2017-07-30 20:35:59.391119 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446959391110, "job": 0, "event": "table_file_deletion", "file_number": 57}
2017-07-30 20:35:59.391211 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446959391205, "job": 0, "event": "table_file_deletion", "file_number": 56}
2017-07-30 20:35:59.391277 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446959391274, "job": 0, "event": "table_file_deletion", "file_number": 54}
2017-07-30 20:35:59.391367 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446959391357, "job": 0, "event": "table_file_deletion", "file_number": 52}
2017-07-30 20:35:59.391431 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446959391428, "job": 0, "event": "table_file_deletion", "file_number": 46}
2017-07-30 20:35:59.391495 7f1331415cc0 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1501446959391492, "job": 0, "event": "table_file_deletion", "file_number": 44}
2017-07-30 20:36:00.094588 7f1331415cc0 0 osd.7 10309 load_pgs
2017-07-30 20:36:03.134049 7f1331415cc0 0 osd.7 10309 load_pgs opened 175 pgs
2017-07-30 20:36:03.134508 7f1331415cc0 0 osd.7 10309 using weightedpriority op queue with priority op cut off at 64.
2017-07-30 20:36:03.135485 7f1331415cc0 -1 osd.7 10309 log_to_monitors {default=true}
2017-07-30 20:36:03.170260 7f130f3ee700 1 osd.7 pg_epoch: 10309 pg[1.0( empty local-lis/les=275/276 n=0 ec=2/2 lis/c 275/275 les/c/f 276/276/0 274/275/224) [7,0,8] r=0 lpr=10279 crt=0'0 mlcod 0'0 unknown] state<Start>: transitioning to Primary
2017-07-30 20:36:03.170545 7f130f3ee700 1 osd.7 pg_epoch: 10309 pg[2.0( v 39'8 (0'0,39'8] local-lis/les=1469/1470 n=4 ec=3/3 lis/c 1469/1469 les/c/f 1470/1470/0 1468/1469/224) [7,3,11] r=0 lpr=10279 crt=39'8 lcod 0'0 mlcod 0'0 unknown] state<Start>: transitioning to Primary
2017-07-30 20:36:03.181872 7f130ebed700 1 osd.7 pg_epoch: 10309 pg[2.5( v 41'6 (0'0,41'6] local-lis/les=1083/1084 n=4 ec=3/3 lis/c 1083/1083 les/c/f 1084/1084/0 1082/1083/224) [7,17,1] r=0 lpr=10272 crt=41'6 lcod 0'0 mlcod 0'0 unknown] state<Start>: transitioning to Primary
2017-07-30 20:36:03.181923 7f1331415cc0 0 osd.7 10309 done with init, starting boot process
2017-07-30 20:36:03.181951 7f1331415cc0 1 osd.7 10309 start_boot
2017-07-30 20:36:03.442439 7f131abfe700 1 osd.7 10312 state: booting -> active
2017-07-30 20:36:03.442807 7f130f3ee700 1 osd.7 pg_epoch: 10310 pg[3.f8( v 10309'293 (0'0,10309'293] local-lis/les=327/328 n=66 ec=42/42 lis/c 327/327 les/c/f 328/355/0 10310/10310/10310) [6,4] r=-1 lpr=10310 pi=[327,10310)/1 crt=10309'293 lcod 0'0 unknown] start_peering_interval up [7,6,4] -> [6,4], acting [7,6,4] -> [6,4], acting_primary 7 -> 6, up_primary 7 -> 6, role 0 -> -1, features acting 1152323339925389307 upacting 1152323339925389307
2017-07-30 20:36:03.442928 7f130ebed700 1 osd.7 pg_epoch: 10310 pg[3.1e9( v 10309'479 (0'0,10309'479] local-lis/les=1469/1470 n=59 ec=42/42 lis/c 1469/1469 les/c/f 1470/1472/0 10310/10310/10310) [17,11] r=-1 lpr=10310 pi=[1469,10310)/1 crt=10309'479 lcod 0'0 unknown] start_peering_interval up [7,17,11] -> [17,11], acting [7,17,11] -> [17,11], acting_primary 7 -> 17, up_primary 7 -> 17, role 0 -> -1, features acting 1152323339925389307 upacting 1152323339925389307