Actions
Bug #18224
closedMass OSD failure with Bluestore
Status:
Can't reproduce
Priority:
Normal
Assignee:
-
Category:
OSD
Target version:
-
% Done:
0%
Source:
Tags:
kraken, bluestore, osd, crash
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
Hello,
We've been testing Ceph Kraken + bluestore recently on our 4-node cluster with 96 OSDs. Suddenly we noticed that almost all OSDs went down according to monitors, but their processes stayed up (see attached graph for cluster status).
2016-12-11 02:38:56.734432 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.69 out (down for 601.356632) 2016-12-11 02:52:06.860580 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.51 out (down for 602.185805) 2016-12-11 03:02:31.924243 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.22 out (down for 604.820012) 2016-12-11 03:12:51.964473 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.86 out (down for 600.029707) 2016-12-11 08:06:57.770892 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.51 out (down for 600.095756) 2016-12-11 08:17:17.824783 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.52 out (down for 600.536756) 2016-12-11 08:17:17.824841 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.68 out (down for 600.536756) 2016-12-11 08:20:42.841671 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.17 out (down for 600.894395) 2016-12-11 08:20:47.845449 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.39 out (down for 600.880928) 2016-12-11 08:27:42.877915 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.3 out (down for 604.739737) 2016-12-11 08:27:42.877998 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.33 out (down for 604.739736) 2016-12-11 08:27:42.878041 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.63 out (down for 603.715906) 2016-12-11 08:27:42.878095 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.66 out (down for 601.702021) 2016-12-11 08:27:42.878155 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.70 out (down for 604.739736) 2016-12-11 08:31:02.904964 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.57 out (down for 601.921498) 2016-12-11 08:31:12.912004 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.11 out (down for 603.797970) 2016-12-11 08:31:12.912060 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.79 out (down for 603.797969) 2016-12-11 08:38:02.948024 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.23 out (down for 601.705864) 2016-12-11 08:38:02.948091 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.60 out (down for 601.705864) 2016-12-11 08:38:02.948130 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.89 out (down for 600.054670) 2016-12-11 08:38:07.952074 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.22 out (down for 601.022400) 2016-12-11 08:38:07.952143 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.56 out (down for 604.046908) 2016-12-11 08:38:07.952216 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.72 out (down for 602.032970) 2016-12-11 08:41:22.980888 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.46 out (down for 600.877402) 2016-12-11 08:41:22.980954 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.49 out (down for 600.877402) 2016-12-11 08:41:32.988410 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.6 out (down for 600.847142) 2016-12-11 08:41:32.988467 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.14 out (down for 600.847141) 2016-12-11 08:41:37.992867 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.64 out (down for 604.051581) 2016-12-11 08:48:28.047297 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.0 out (down for 604.939531) 2016-12-11 08:48:28.047360 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.8 out (down for 600.827902) 2016-12-11 08:48:28.047399 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.18 out (down for 601.905401) 2016-12-11 08:48:28.047446 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.27 out (down for 600.827902) 2016-12-11 08:48:28.047480 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.37 out (down for 602.919092) 2016-12-11 08:48:33.056425 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.32 out (down for 602.051636) 2016-12-11 08:48:33.056516 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.87 out (down for 604.075075) 2016-12-11 08:48:33.056565 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.94 out (down for 603.062683) 2016-12-11 08:48:48.064532 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.1 out (down for 602.653615) 2016-12-11 08:48:48.064608 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.74 out (down for 600.632117) 2016-12-11 08:51:43.097541 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.96 out (down for 603.073719) 2016-12-11 08:51:48.107028 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.41 out (down for 603.931911) 2016-12-11 08:51:48.107102 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.48 out (down for 600.795707) 2016-12-11 08:51:58.117308 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.47 out (down for 603.995153) 2016-12-11 08:52:03.126041 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.13 out (down for 600.101105) 2016-12-11 08:52:03.126136 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.55 out (down for 603.816885) 2016-12-11 08:52:08.133279 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.58 out (down for 601.673135) 2016-12-11 08:58:48.218654 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.31 out (down for 600.515754) 2016-12-11 08:58:48.218733 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.35 out (down for 600.515754) 2016-12-11 08:58:48.218783 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.71 out (down for 600.515753) 2016-12-11 08:58:53.230407 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.7 out (down for 603.079602) 2016-12-11 08:58:53.230470 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.15 out (down for 603.079602) 2016-12-11 08:58:53.230512 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.28 out (down for 603.079601) 2016-12-11 08:58:53.230570 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.30 out (down for 603.079600) 2016-12-11 08:58:53.230617 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.40 out (down for 604.127899) 2016-12-11 08:58:53.230719 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.73 out (down for 604.127897) 2016-12-11 08:58:53.230767 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.95 out (down for 603.079598) 2016-12-11 08:58:58.248923 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.26 out (down for 603.764603) 2016-12-11 08:59:13.336434 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.19 out (down for 603.616749) 2016-12-11 08:59:13.336507 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.54 out (down for 600.578905) 2016-12-11 08:59:13.336548 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.59 out (down for 603.616747) 2016-12-11 08:59:18.349427 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.43 out (down for 602.109370) 2016-12-11 09:02:03.375043 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.91 out (down for 601.007010) 2016-12-11 09:02:08.384249 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.67 out (down for 600.224936) 2016-12-11 09:02:13.392412 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.50 out (down for 601.975234) 2016-12-11 09:02:23.401983 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.65 out (down for 600.216345) 2016-12-11 09:02:28.411493 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.61 out (down for 600.735307) 2016-12-11 09:02:28.411554 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.93 out (down for 601.763907) 2016-12-11 09:02:33.424856 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.90 out (down for 602.572448) 2016-12-11 09:02:38.435351 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.86 out (down for 604.405833) 2016-12-11 09:09:13.487424 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.44 out (down for 604.030902) 2016-12-11 09:09:18.504027 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.16 out (down for 603.091040) 2016-12-11 09:09:18.504074 7f729f3a0700 0 log_channel(cluster) log [INF] : osd.80 out (down for 604.120863)
Log for OSD 51:
-32> 2016-12-11 07:42:25.463805 7fa4d0417700 10 monclient(hunting): picked mon.node03 con 0x7fa520d3a800 addr 192.168.36.7:6789/0 -31> 2016-12-11 07:42:25.463840 7fa4d0417700 10 monclient(hunting): _send_mon_message to mon.node03 at 192.168.36.7:6789/0 -30> 2016-12-11 07:42:25.463848 7fa4d0417700 1 -- 192.168.36.7:6829/1947980 --> 192.168.36.7:6789/0 -- auth(proto 0 27 bytes epoch 1) v1 -- 0x7fa517a02640 con 0 -29> 2016-12-11 07:42:25.463870 7fa4d0417700 10 monclient(hunting): renew_subs -28> 2016-12-11 07:42:55.463985 7fa4d0417700 10 monclient(hunting): tick -27> 2016-12-11 07:42:55.464015 7fa4d0417700 1 monclient(hunting): continuing hunt -26> 2016-12-11 07:42:55.464019 7fa4d0417700 10 monclient(hunting): _reopen_session rank -1 name -25> 2016-12-11 07:42:55.464030 7fa4d0417700 1 -- 192.168.36.7:6829/1947980 >> 192.168.36.7:6789/0 conn(0x7fa520d3a800 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=1).mark_down -24> 2016-12-11 07:42:55.464054 7fa4d0417700 2 -- 192.168.36.7:6829/1947980 >> 192.168.36.7:6789/0 conn(0x7fa520d3a800 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=1)._stop -23> 2016-12-11 07:42:55.464120 7fa4d0417700 10 monclient(hunting): picked mon.node02 con 0x7fa520d48000 addr 192.168.36.6:6789/0 -22> 2016-12-11 07:42:55.464137 7fa4d0417700 10 monclient(hunting): _send_mon_message to mon.node02 at 192.168.36.6:6789/0 -21> 2016-12-11 07:42:55.464143 7fa4d0417700 1 -- 192.168.36.7:6829/1947980 --> 192.168.36.6:6789/0 -- auth(proto 0 27 bytes epoch 1) v1 -- 0x7fa517a02640 con 0 -20> 2016-12-11 07:42:55.464168 7fa4d0417700 10 monclient(hunting): renew_subs -19> 2016-12-11 07:43:25.464258 7fa4d0417700 10 monclient(hunting): tick -18> 2016-12-11 07:43:25.464284 7fa4d0417700 1 monclient(hunting): continuing hunt -17> 2016-12-11 07:43:25.464288 7fa4d0417700 10 monclient(hunting): _reopen_session rank -1 name -16> 2016-12-11 07:43:25.464314 7fa4d0417700 1 -- 192.168.36.7:6829/1947980 >> 192.168.36.6:6789/0 conn(0x7fa520d48000 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=1).mark_down -15> 2016-12-11 07:43:25.464338 7fa4d0417700 2 -- 192.168.36.7:6829/1947980 >> 192.168.36.6:6789/0 conn(0x7fa520d48000 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=1)._stop -14> 2016-12-11 07:43:25.464391 7fa4d0417700 10 monclient(hunting): picked mon.node03 con 0x7fa520d49800 addr 192.168.36.7:6789/0 -13> 2016-12-11 07:43:25.464410 7fa4d0417700 10 monclient(hunting): _send_mon_message to mon.node03 at 192.168.36.7:6789/0 -12> 2016-12-11 07:43:25.464417 7fa4d0417700 1 -- 192.168.36.7:6829/1947980 --> 192.168.36.7:6789/0 -- auth(proto 0 27 bytes epoch 1) v1 -- 0x7fa517a02640 con 0 -11> 2016-12-11 07:43:25.464435 7fa4d0417700 10 monclient(hunting): renew_subs -10> 2016-12-11 07:43:55.464520 7fa4d0417700 10 monclient(hunting): tick -9> 2016-12-11 07:43:55.464542 7fa4d0417700 1 monclient(hunting): continuing hunt -8> 2016-12-11 07:43:55.464546 7fa4d0417700 10 monclient(hunting): _reopen_session rank -1 name -7> 2016-12-11 07:43:55.464558 7fa4d0417700 1 -- 192.168.36.7:6829/1947980 >> 192.168.36.7:6789/0 conn(0x7fa520d49800 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=1).mark_down -6> 2016-12-11 07:43:55.464579 7fa4d0417700 2 -- 192.168.36.7:6829/1947980 >> 192.168.36.7:6789/0 conn(0x7fa520d49800 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=1)._stop -5> 2016-12-11 07:43:55.464638 7fa4d0417700 10 monclient(hunting): picked mon.node02 con 0x7fa520d4b000 addr 192.168.36.6:6789/0 -4> 2016-12-11 07:43:55.464660 7fa4d0417700 10 monclient(hunting): _send_mon_message to mon.node02 at 192.168.36.6:6789/0 -3> 2016-12-11 07:43:55.464668 7fa4d0417700 1 -- 192.168.36.7:6829/1947980 --> 192.168.36.6:6789/0 -- auth(proto 0 27 bytes epoch 1) v1 -- 0x7fa517a02640 con 0 -2> 2016-12-11 07:43:55.464688 7fa4d0417700 10 monclient(hunting): renew_subs -1> 2016-12-11 07:44:11.650749 7fa4d241b700 -1 bdev(/var/lib/ceph/osd/ceph-51/block.wal) aio submit got (22) Invalid argument 0> 2016-12-11 07:44:11.655085 7fa4d241b700 -1 /mnt/jenkins/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/11.0.2/rpm/el7/BUILD/ceph-11.0.2/src/os/bluestore/KernelDevice.cc: In function 'virtual void KernelDevice::aio_submit(IOContext*)' thread 7fa4d241b700 time 2016-12-11 07:44:11.650793 /mnt/jenkins/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/11.0.2/rpm/el7/BUILD/ceph-11.0.2/src/os/bluestore/KernelDevice.cc: 370: FAILED assert(r == 0) ceph version v11.0.2 (697fe64f9f106252c49a2c4fe4d79aea29363be7) 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x85) [0x7fa4e90c8b35] 2: (KernelDevice::aio_submit(IOContext*)+0x799) [0x7fa4e8f18d59] 3: (BlueFS::_flush_range(BlueFS::FileWriter*, unsigned long, unsigned long)+0xdad) [0x7fa4e8ef547d] 4: (BlueFS::_flush(BlueFS::FileWriter*, bool)+0x119) [0x7fa4e8ef6529] 5: (BlueRocksWritableFile::Flush()+0x3a) [0x7fa4e8f0fcca] 6: (rocksdb::WritableFileWriter::Flush()+0xab) [0x7fa4e901058b] 7: (rocksdb::log::Writer::EmitPhysicalRecord(rocksdb::log::RecordType, char const*, unsigned long)+0x136) [0x7fa4e8f9bc56] 8: (rocksdb::log::Writer::AddRecord(rocksdb::Slice const&)+0x110) [0x7fa4e8f9be20] 9: (rocksdb::DBImpl::WriteImpl(rocksdb::WriteOptions const&, rocksdb::WriteBatch*, rocksdb::WriteCallback*, unsigned long*, unsigned long, bool)+0x1290) [0x7fa4e8f629d0] 10: (rocksdb::DBImpl::Write(rocksdb::WriteOptions const&, rocksdb::WriteBatch*)+0x27) [0x7fa4e8f63717] 11: (RocksDBStore::submit_transaction(std::shared_ptr<KeyValueDB::TransactionImpl>)+0xc7) [0x7fa4e8e934b7] 12: (BlueStore::_kv_sync_thread()+0xbd1) [0x7fa4e8e5dcb1] 13: (BlueStore::KVSyncThread::entry()+0xd) [0x7fa4e8e6cced] 14: (()+0x7dc5) [0x7fa4e5344dc5] 15: (clone()+0x6d) [0x7fa4e422bced] NOTE: a copy of the executable, or `objdump -rdS <executable>` 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 0/ 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 newstore 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 -2/-2 (syslog threshold) -1/-1 (stderr threshold) max_recent 10000 max_new 1000 log_file /var/log/ceph/ceph-osd.51.log --- end dump of recent events --- 2016-12-11 07:44:11.700910 7fa4d241b700 -1 *** Caught signal (Aborted) ** in thread 7fa4d241b700 thread_name:bstore_kv_sync ceph version v11.0.2 (697fe64f9f106252c49a2c4fe4d79aea29363be7) 1: (()+0x89c39a) [0x7fa4e8f3a39a] 2: (()+0xf100) [0x7fa4e534c100] 3: (gsignal()+0x37) [0x7fa4e416a5f7] 4: (abort()+0x148) [0x7fa4e416bce8] 5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x267) [0x7fa4e90c8d17] 6: (KernelDevice::aio_submit(IOContext*)+0x799) [0x7fa4e8f18d59] 7: (BlueFS::_flush_range(BlueFS::FileWriter*, unsigned long, unsigned long)+0xdad) [0x7fa4e8ef547d] 8: (BlueFS::_flush(BlueFS::FileWriter*, bool)+0x119) [0x7fa4e8ef6529] 9: (BlueRocksWritableFile::Flush()+0x3a) [0x7fa4e8f0fcca] 10: (rocksdb::WritableFileWriter::Flush()+0xab) [0x7fa4e901058b] 11: (rocksdb::log::Writer::EmitPhysicalRecord(rocksdb::log::RecordType, char const*, unsigned long)+0x136) [0x7fa4e8f9bc56] 12: (rocksdb::log::Writer::AddRecord(rocksdb::Slice const&)+0x110) [0x7fa4e8f9be20] 13: (rocksdb::DBImpl::WriteImpl(rocksdb::WriteOptions const&, rocksdb::WriteBatch*, rocksdb::WriteCallback*, unsigned long*, unsigned long, bool)+0x1290) [0x7fa4e8f629d0] 14: (rocksdb::DBImpl::Write(rocksdb::WriteOptions const&, rocksdb::WriteBatch*)+0x27) [0x7fa4e8f63717] 15: (RocksDBStore::submit_transaction(std::shared_ptr<KeyValueDB::TransactionImpl>)+0xc7) [0x7fa4e8e934b7] 16: (BlueStore::_kv_sync_thread()+0xbd1) [0x7fa4e8e5dcb1] 17: (BlueStore::KVSyncThread::entry()+0xd) [0x7fa4e8e6cced] 18: (()+0x7dc5) [0x7fa4e5344dc5] 19: (clone()+0x6d) [0x7fa4e422bced] NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. --- begin dump of recent events --- 0> 2016-12-11 07:44:11.700910 7fa4d241b700 -1 *** Caught signal (Aborted) ** in thread 7fa4d241b700 thread_name:bstore_kv_sync ceph version v11.0.2 (697fe64f9f106252c49a2c4fe4d79aea29363be7) 1: (()+0x89c39a) [0x7fa4e8f3a39a] 2: (()+0xf100) [0x7fa4e534c100] 3: (gsignal()+0x37) [0x7fa4e416a5f7] 4: (abort()+0x148) [0x7fa4e416bce8] 5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x267) [0x7fa4e90c8d17] 6: (KernelDevice::aio_submit(IOContext*)+0x799) [0x7fa4e8f18d59] 7: (BlueFS::_flush_range(BlueFS::FileWriter*, unsigned long, unsigned long)+0xdad) [0x7fa4e8ef547d] 8: (BlueFS::_flush(BlueFS::FileWriter*, bool)+0x119) [0x7fa4e8ef6529] 9: (BlueRocksWritableFile::Flush()+0x3a) [0x7fa4e8f0fcca] 10: (rocksdb::WritableFileWriter::Flush()+0xab) [0x7fa4e901058b] 11: (rocksdb::log::Writer::EmitPhysicalRecord(rocksdb::log::RecordType, char const*, unsigned long)+0x136) [0x7fa4e8f9bc56] 12: (rocksdb::log::Writer::AddRecord(rocksdb::Slice const&)+0x110) [0x7fa4e8f9be20] 13: (rocksdb::DBImpl::WriteImpl(rocksdb::WriteOptions const&, rocksdb::WriteBatch*, rocksdb::WriteCallback*, unsigned long*, unsigned long, bool)+0x1290) [0x7fa4e8f629d0] 14: (rocksdb::DBImpl::Write(rocksdb::WriteOptions const&, rocksdb::WriteBatch*)+0x27) [0x7fa4e8f63717] 15: (RocksDBStore::submit_transaction(std::shared_ptr<KeyValueDB::TransactionImpl>)+0xc7) [0x7fa4e8e934b7] 16: (BlueStore::_kv_sync_thread()+0xbd1) [0x7fa4e8e5dcb1] 17: (BlueStore::KVSyncThread::entry()+0xd) [0x7fa4e8e6cced] 18: (()+0x7dc5) [0x7fa4e5344dc5] 19: (clone()+0x6d) [0x7fa4e422bced] NOTE: a copy of the executable, or `objdump -rdS <executable>` 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 0/ 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 newstore 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 -2/-2 (syslog threshold) -1/-1 (stderr threshold) max_recent 10000 max_new 1000 log_file /var/log/ceph/ceph-osd.51.log --- end dump of recent events --- 2016-12-11 07:44:11.985599 7f6d6a4e3800 -1 WARNING: the following dangerous and experimental features are enabled: bluestore,rocksdb 2016-12-11 07:44:11.985605 7f6d6a4e3800 0 set uid:gid to 167:167 (ceph:ceph) 2016-12-11 07:44:11.985622 7f6d6a4e3800 0 ceph version v11.0.2 (697fe64f9f106252c49a2c4fe4d79aea29363be7), process ceph-osd, pid 2001423 2016-12-11 07:44:11.985675 7f6d6a4e3800 -1 WARNING: experimental feature 'bluestore' is enabled Please be aware that this feature is experimental, untested, unsupported, and may result in data corruption, data loss, and/or irreparable damage to your cluster. Do not use feature with important data. 2016-12-11 07:44:11.990513 7f6d6a4e3800 0 pidfile_write: ignore empty --pid-file 2016-12-11 07:44:12.010893 7f6d6a4e3800 -1 WARNING: the following dangerous and experimental features are enabled: bluestore,rocksdb 2016-12-11 07:44:12.017812 7f6d6a4e3800 1 bluestore(/var/lib/ceph/osd/ceph-51) mount path /var/lib/ceph/osd/ceph-51 2016-12-11 07:44:12.017848 7f6d6a4e3800 1 bdev create path /var/lib/ceph/osd/ceph-51/block type kernel 2016-12-11 07:44:12.018381 7f6d6a4e3800 1 bdev(/var/lib/ceph/osd/ceph-51/block) open path /var/lib/ceph/osd/ceph-51/block 2016-12-11 07:44:12.018646 7f6d6a4e3800 1 bdev(/var/lib/ceph/osd/ceph-51/block) open size 2000091680768 (0x1d1aec11000, 1862 GB) block_size 4096 (4096 B) non-rotational 2016-12-11 07:44:12.018854 7f6d6a4e3800 1 bdev create path /var/lib/ceph/osd/ceph-51/block.db type kernel 2016-12-11 07:44:12.019359 7f6d6a4e3800 1 bdev(/var/lib/ceph/osd/ceph-51/block.db) open path /var/lib/ceph/osd/ceph-51/block.db 2016-12-11 07:44:12.019552 7f6d6a4e3800 1 bdev(/var/lib/ceph/osd/ceph-51/block.db) open size 67108864 (0x4000000, 65536 kB) block_size 4096 (4096 B) non-rotational 2016-12-11 07:44:12.019558 7f6d6a4e3800 1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-51/block.db size 65536 kB 2016-12-11 07:44:12.019700 7f6d6a4e3800 1 bdev create path /var/lib/ceph/osd/ceph-51/block type kernel 2016-12-11 07:44:12.020180 7f6d6a4e3800 1 bdev(/var/lib/ceph/osd/ceph-51/block) open path /var/lib/ceph/osd/ceph-51/block 2016-12-11 07:44:12.020355 7f6d6a4e3800 1 bdev(/var/lib/ceph/osd/ceph-51/block) open size 2000091680768 (0x1d1aec11000, 1862 GB) block_size 4096 (4096 B) non-rotational 2016-12-11 07:44:12.020361 7f6d6a4e3800 1 bluefs add_block_device bdev 2 path /var/lib/ceph/osd/ceph-51/block size 1862 GB 2016-12-11 07:44:12.020372 7f6d6a4e3800 1 bdev create path /var/lib/ceph/osd/ceph-51/block.wal type kernel 2016-12-11 07:44:12.020842 7f6d6a4e3800 1 bdev(/var/lib/ceph/osd/ceph-51/block.wal) open path /var/lib/ceph/osd/ceph-51/block.wal 2016-12-11 07:44:12.021015 7f6d6a4e3800 1 bdev(/var/lib/ceph/osd/ceph-51/block.wal) open size 134217728 (0x8000000, 128 MB) block_size 4096 (4096 B) non-rotational 2016-12-11 07:44:12.021021 7f6d6a4e3800 1 bluefs add_block_device bdev 0 path /var/lib/ceph/osd/ceph-51/block.wal size 128 MB 2016-12-11 07:44:12.021178 7f6d6a4e3800 1 bluefs mount 2016-12-11 07:44:12.392532 7f6d6a4e3800 -1 WARNING: experimental feature 'rocksdb' is enabled Please be aware that this feature is experimental, untested, unsupported, and may result in data corruption, data loss, and/or irreparable damage to your cluster. Do not use feature with important data. 2016-12-11 07:44:12.392625 7f6d6a4e3800 0 set rocksdb option compression = kNoCompression 2016-12-11 07:44:12.392633 7f6d6a4e3800 0 set rocksdb option max_write_buffer_number = 16 2016-12-11 07:44:12.392637 7f6d6a4e3800 0 set rocksdb option min_write_buffer_number_to_merge = 3 2016-12-11 07:44:12.392644 7f6d6a4e3800 0 set rocksdb option recycle_log_file_num = 16 2016-12-11 07:44:12.392690 7f6d6a4e3800 0 set rocksdb option compression = kNoCompression 2016-12-11 07:44:12.392696 7f6d6a4e3800 0 set rocksdb option max_write_buffer_number = 16 2016-12-11 07:44:12.392700 7f6d6a4e3800 0 set rocksdb option min_write_buffer_number_to_merge = 3 2016-12-11 07:44:12.392703 7f6d6a4e3800 0 set rocksdb option recycle_log_file_num = 16 2016-12-11 07:44:12.392832 7f6d6a4e3800 4 rocksdb: RocksDB version: 4.12.0 2016-12-11 07:44:12.392841 7f6d6a4e3800 4 rocksdb: Git sha rocksdb_build_git_sha: 2016-12-11 07:44:12.392843 7f6d6a4e3800 4 rocksdb: Compile date Oct 17 2016 2016-12-11 07:44:12.392846 7f6d6a4e3800 4 rocksdb: DB SUMMARY 2016-12-11 07:44:12.392862 7f6d6a4e3800 4 rocksdb: CURRENT file: CURRENT 2016-12-11 07:44:12.392864 7f6d6a4e3800 4 rocksdb: IDENTITY file: IDENTITY 2016-12-11 07:44:12.392872 7f6d6a4e3800 4 rocksdb: MANIFEST file: MANIFEST-000064 size: 1776 Bytes 2016-12-11 07:44:12.392876 7f6d6a4e3800 4 rocksdb: SST files in db dir, Total Num: 2, files: 000062.sst 000063.sst 2016-12-11 07:44:12.392885 7f6d6a4e3800 4 rocksdb: SST files in db.slow dir, Total Num: 9, files: 000054.sst 000055.sst 000056.sst 000057.sst 000058.sst 000059.sst 000060.sst 000062.sst 000063.sst 2016-12-11 07:44:12.392893 7f6d6a4e3800 4 rocksdb: Write Ahead Log file in db.wal: 000065.log size: 65495555 ; 000068.log size: 8837163 ; 2016-12-11 07:44:12.392895 7f6d6a4e3800 4 rocksdb: Options.error_if_exists: 0 2016-12-11 07:44:12.392897 7f6d6a4e3800 4 rocksdb: Options.create_if_missing: 0 2016-12-11 07:44:12.392897 7f6d6a4e3800 4 rocksdb: Options.paranoid_checks: 1 2016-12-11 07:44:12.392899 7f6d6a4e3800 4 rocksdb: Options.env: 0x7f6d757a2920 2016-12-11 07:44:12.392900 7f6d6a4e3800 4 rocksdb: Options.info_log: 0x7f6d757a2c20 2016-12-11 07:44:12.392901 7f6d6a4e3800 4 rocksdb: Options.max_open_files: -1 2016-12-11 07:44:12.392902 7f6d6a4e3800 4 rocksdb: Options.max_file_opening_threads: 16 2016-12-11 07:44:12.392903 7f6d6a4e3800 4 rocksdb: Options.max_total_wal_size: 0 2016-12-11 07:44:12.392904 7f6d6a4e3800 4 rocksdb: Options.disableDataSync: 0 2016-12-11 07:44:12.392905 7f6d6a4e3800 4 rocksdb: Options.use_fsync: 0 2016-12-11 07:44:12.392906 7f6d6a4e3800 4 rocksdb: Options.max_log_file_size: 0 2016-12-11 07:44:12.392907 7f6d6a4e3800 4 rocksdb: Options.max_manifest_file_size: 18446744073709551615 2016-12-11 07:44:12.392908 7f6d6a4e3800 4 rocksdb: Options.log_file_time_to_roll: 0 2016-12-11 07:44:12.392910 7f6d6a4e3800 4 rocksdb: Options.keep_log_file_num: 1000 2016-12-11 07:44:12.392910 7f6d6a4e3800 4 rocksdb: Options.recycle_log_file_num: 16 2016-12-11 07:44:12.392911 7f6d6a4e3800 4 rocksdb: Options.allow_os_buffer: 1 2016-12-11 07:44:12.392912 7f6d6a4e3800 4 rocksdb: Options.allow_mmap_reads: 0 2016-12-11 07:44:12.392913 7f6d6a4e3800 4 rocksdb: Options.allow_fallocate: 1 2016-12-11 07:44:12.392915 7f6d6a4e3800 4 rocksdb: Options.allow_mmap_writes: 0 2016-12-11 07:44:12.392916 7f6d6a4e3800 4 rocksdb: Options.create_missing_column_families: 0 2016-12-11 07:44:12.392917 7f6d6a4e3800 4 rocksdb: Options.db_log_dir: 2016-12-11 07:44:12.392918 7f6d6a4e3800 4 rocksdb: Options.wal_dir: db.wal 2016-12-11 07:44:12.392919 7f6d6a4e3800 4 rocksdb: Options.table_cache_numshardbits: 6 2016-12-11 07:44:12.392920 7f6d6a4e3800 4 rocksdb: Options.delete_obsolete_files_period_micros: 21600000000 2016-12-11 07:44:12.392920 7f6d6a4e3800 4 rocksdb: Options.base_background_compactions: 1 2016-12-11 07:44:12.392922 7f6d6a4e3800 4 rocksdb: Options.max_background_compactions: 1 2016-12-11 07:44:12.392922 7f6d6a4e3800 4 rocksdb: Options.max_subcompactions: 1 2016-12-11 07:44:12.392923 7f6d6a4e3800 4 rocksdb: Options.max_background_flushes: 1 2016-12-11 07:44:12.392924 7f6d6a4e3800 4 rocksdb: Options.WAL_ttl_seconds: 0 2016-12-11 07:44:12.392925 7f6d6a4e3800 4 rocksdb: Options.WAL_size_limit_MB: 0 2016-12-11 07:44:12.392925 7f6d6a4e3800 4 rocksdb: Options.manifest_preallocation_size: 4194304 2016-12-11 07:44:12.392926 7f6d6a4e3800 4 rocksdb: Options.allow_os_buffer: 1 2016-12-11 07:44:12.392927 7f6d6a4e3800 4 rocksdb: Options.allow_mmap_reads: 0 2016-12-11 07:44:12.392927 7f6d6a4e3800 4 rocksdb: Options.allow_mmap_writes: 0 2016-12-11 07:44:12.392928 7f6d6a4e3800 4 rocksdb: Options.is_fd_close_on_exec: 1 2016-12-11 07:44:12.392929 7f6d6a4e3800 4 rocksdb: Options.stats_dump_period_sec: 600 2016-12-11 07:44:12.392930 7f6d6a4e3800 4 rocksdb: Options.advise_random_on_open: 1 2016-12-11 07:44:12.392931 7f6d6a4e3800 4 rocksdb: Options.db_write_buffer_size: 0d 2016-12-11 07:44:12.392932 7f6d6a4e3800 4 rocksdb: Options.access_hint_on_compaction_start: NORMAL 2016-12-11 07:44:12.392932 7f6d6a4e3800 4 rocksdb: Options.new_table_reader_for_compaction_inputs: 0 2016-12-11 07:44:12.392951 7f6d6a4e3800 4 rocksdb: Options.compaction_readahead_size: 0d 2016-12-11 07:44:12.392953 7f6d6a4e3800 4 rocksdb: Options.random_access_max_buffer_size: 1048576d 2016-12-11 07:44:12.392954 7f6d6a4e3800 4 rocksdb: Options.writable_file_max_buffer_size: 1048576d 2016-12-11 07:44:12.392955 7f6d6a4e3800 4 rocksdb: Options.use_adaptive_mutex: 0 2016-12-11 07:44:12.392955 7f6d6a4e3800 4 rocksdb: Options.rate_limiter: (nil) 2016-12-11 07:44:12.392957 7f6d6a4e3800 4 rocksdb: Options.sst_file_manager.rate_bytes_per_sec: 0 2016-12-11 07:44:12.392957 7f6d6a4e3800 4 rocksdb: Options.bytes_per_sync: 0 2016-12-11 07:44:12.392958 7f6d6a4e3800 4 rocksdb: Options.wal_bytes_per_sync: 0 2016-12-11 07:44:12.392959 7f6d6a4e3800 4 rocksdb: Options.wal_recovery_mode: 0 2016-12-11 07:44:12.392959 7f6d6a4e3800 4 rocksdb: Options.enable_thread_tracking: 0 2016-12-11 07:44:12.392960 7f6d6a4e3800 4 rocksdb: Options.allow_concurrent_memtable_write: 0 2016-12-11 07:44:12.392960 7f6d6a4e3800 4 rocksdb: Options.enable_write_thread_adaptive_yield: 0 2016-12-11 07:44:12.392961 7f6d6a4e3800 4 rocksdb: Options.write_thread_max_yield_usec: 100 2016-12-11 07:44:12.392962 7f6d6a4e3800 4 rocksdb: Options.write_thread_slow_yield_usec: 3 2016-12-11 07:44:12.392962 7f6d6a4e3800 4 rocksdb: Options.row_cache: None 2016-12-11 07:44:12.392963 7f6d6a4e3800 4 rocksdb: Options.wal_filter: None 2016-12-11 07:44:12.392964 7f6d6a4e3800 4 rocksdb: Options.avoid_flush_during_recovery: 0 2016-12-11 07:44:12.392965 7f6d6a4e3800 4 rocksdb: Compression algorithms supported: 2016-12-11 07:44:12.392966 7f6d6a4e3800 4 rocksdb: Snappy supported: 1 2016-12-11 07:44:12.392967 7f6d6a4e3800 4 rocksdb: Zlib supported: 1 2016-12-11 07:44:12.392968 7f6d6a4e3800 4 rocksdb: Bzip supported: 0 2016-12-11 07:44:12.392968 7f6d6a4e3800 4 rocksdb: LZ4 supported: 0 2016-12-11 07:44:12.392969 7f6d6a4e3800 4 rocksdb: Fast CRC32 supported: 0 2016-12-11 07:44:12.400573 7f6d6a4e3800 4 rocksdb: Recovering from manifest file: MANIFEST-000064 2016-12-11 07:44:12.400650 7f6d6a4e3800 4 rocksdb: --------------- Options for column family [default]: 2016-12-11 07:44:12.400661 7f6d6a4e3800 4 rocksdb: Options.comparator: rocksdb.InternalKeyComparator:leveldb.BytewiseComparator 2016-12-11 07:44:12.400687 7f6d6a4e3800 4 rocksdb: Options.merge_operator: .T:int64_array.b:bitwise_xor 2016-12-11 07:44:12.400692 7f6d6a4e3800 4 rocksdb: Options.compaction_filter: None 2016-12-11 07:44:12.400693 7f6d6a4e3800 4 rocksdb: Options.compaction_filter_factory: None 2016-12-11 07:44:12.400693 7f6d6a4e3800 4 rocksdb: Options.memtable_factory: SkipListFactory 2016-12-11 07:44:12.400694 7f6d6a4e3800 4 rocksdb: Options.table_factory: BlockBasedTable 2016-12-11 07:44:12.400710 7f6d6a4e3800 4 rocksdb: table_factory options: flush_block_policy_factory: FlushBlockBySizePolicyFactory (0x7f6d755a2118) cache_index_and_filter_blocks: 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: 0x7f6d755dc318 block_cache_size: 134217728 block_cache_compressed: (nil) block_size: 4096 block_size_deviation: 10 block_restart_interval: 16 index_block_restart_interval: 1 filter_policy: nullptr whole_key_filtering: 1 skip_table_builder_flush: 0 format_version: 2 2016-12-11 07:44:12.400714 7f6d6a4e3800 4 rocksdb: Options.write_buffer_size: 67108864 2016-12-11 07:44:12.400715 7f6d6a4e3800 4 rocksdb: Options.max_write_buffer_number: 16 2016-12-11 07:44:12.400718 7f6d6a4e3800 4 rocksdb: Options.compression: NoCompression 2016-12-11 07:44:12.400719 7f6d6a4e3800 4 rocksdb: Options.bottommost_compression: Disabled 2016-12-11 07:44:12.400720 7f6d6a4e3800 4 rocksdb: Options.prefix_extractor: nullptr 2016-12-11 07:44:12.400721 7f6d6a4e3800 4 rocksdb: Options.num_levels: 7 2016-12-11 07:44:12.400722 7f6d6a4e3800 4 rocksdb: Options.min_write_buffer_number_to_merge: 3 2016-12-11 07:44:12.400723 7f6d6a4e3800 4 rocksdb: Options.max_write_buffer_number_to_maintain: 0 2016-12-11 07:44:12.400724 7f6d6a4e3800 4 rocksdb: Options.compression_opts.window_bits: -14 2016-12-11 07:44:12.400725 7f6d6a4e3800 4 rocksdb: Options.compression_opts.level: -1 2016-12-11 07:44:12.400726 7f6d6a4e3800 4 rocksdb: Options.compression_opts.strategy: 0 2016-12-11 07:44:12.400726 7f6d6a4e3800 4 rocksdb: Options.compression_opts.max_dict_bytes: 0 2016-12-11 07:44:12.400727 7f6d6a4e3800 4 rocksdb: Options.level0_file_num_compaction_trigger: 4 2016-12-11 07:44:12.400727 7f6d6a4e3800 4 rocksdb: Options.level0_slowdown_writes_trigger: 20 2016-12-11 07:44:12.400728 7f6d6a4e3800 4 rocksdb: Options.level0_stop_writes_trigger: 24 2016-12-11 07:44:12.400729 7f6d6a4e3800 4 rocksdb: Options.target_file_size_base: 67108864 2016-12-11 07:44:12.400730 7f6d6a4e3800 4 rocksdb: Options.target_file_size_multiplier: 1 2016-12-11 07:44:12.400731 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_base: 268435456 2016-12-11 07:44:12.400731 7f6d6a4e3800 4 rocksdb: Options.level_compaction_dynamic_level_bytes: 0 2016-12-11 07:44:12.400732 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_multiplier: 10 2016-12-11 07:44:12.400732 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[0]: 1 2016-12-11 07:44:12.400733 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[1]: 1 2016-12-11 07:44:12.400734 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[2]: 1 2016-12-11 07:44:12.400735 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[3]: 1 2016-12-11 07:44:12.400736 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[4]: 1 2016-12-11 07:44:12.400737 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[5]: 1 2016-12-11 07:44:12.400737 7f6d6a4e3800 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[6]: 1 2016-12-11 07:44:12.400738 7f6d6a4e3800 4 rocksdb: Options.max_sequential_skip_in_iterations: 8 2016-12-11 07:44:12.400739 7f6d6a4e3800 4 rocksdb: Options.max_compaction_bytes: 1677721600 2016-12-11 07:44:12.400739 7f6d6a4e3800 4 rocksdb: Options.arena_block_size: 8388608 2016-12-11 07:44:12.400740 7f6d6a4e3800 4 rocksdb: Options.soft_pending_compaction_bytes_limit: 68719476736 2016-12-11 07:44:12.400741 7f6d6a4e3800 4 rocksdb: Options.hard_pending_compaction_bytes_limit: 274877906944 2016-12-11 07:44:12.400743 7f6d6a4e3800 4 rocksdb: Options.rate_limit_delay_max_milliseconds: 1000 2016-12-11 07:44:12.400749 7f6d6a4e3800 4 rocksdb: Options.disable_auto_compactions: 0 2016-12-11 07:44:12.400750 7f6d6a4e3800 4 rocksdb: Options.verify_checksums_in_compaction: 1 2016-12-11 07:44:12.400750 7f6d6a4e3800 4 rocksdb: Options.compaction_style: 0 2016-12-11 07:44:12.400751 7f6d6a4e3800 4 rocksdb: Options.compaction_pri: 0 2016-12-11 07:44:12.400751 7f6d6a4e3800 4 rocksdb: Options.compaction_options_universal.size_ratio: 1 2016-12-11 07:44:12.400752 7f6d6a4e3800 4 rocksdb: Options.compaction_options_universal.min_merge_width: 2 2016-12-11 07:44:12.400753 7f6d6a4e3800 4 rocksdb: Options.compaction_options_universal.max_merge_width: 4294967295 2016-12-11 07:44:12.400754 7f6d6a4e3800 4 rocksdb: Options.compaction_options_universal.max_size_amplification_percent: 200 2016-12-11 07:44:12.400755 7f6d6a4e3800 4 rocksdb: Options.compaction_options_universal.compression_size_percent: -1 2016-12-11 07:44:12.400755 7f6d6a4e3800 4 rocksdb: Options.compaction_options_fifo.max_table_files_size: 1073741824 2016-12-11 07:44:12.400756 7f6d6a4e3800 4 rocksdb: Options.table_properties_collectors: 2016-12-11 07:44:12.400757 7f6d6a4e3800 4 rocksdb: Options.inplace_update_support: 0 2016-12-11 07:44:12.400757 7f6d6a4e3800 4 rocksdb: Options.inplace_update_num_locks: 10000 2016-12-11 07:44:12.400758 7f6d6a4e3800 4 rocksdb: Options.min_partial_merge_operands: 2 2016-12-11 07:44:12.400759 7f6d6a4e3800 4 rocksdb: Options.memtable_prefix_bloom_size_ratio: 0.000000 2016-12-11 07:44:12.400767 7f6d6a4e3800 4 rocksdb: Options.memtable_huge_page_size: 0 2016-12-11 07:44:12.400775 7f6d6a4e3800 4 rocksdb: Options.bloom_locality: 0 2016-12-11 07:44:12.400777 7f6d6a4e3800 4 rocksdb: Options.max_successive_merges: 0 2016-12-11 07:44:12.400777 7f6d6a4e3800 4 rocksdb: Options.optimize_filters_for_hits: 0 2016-12-11 07:44:12.400778 7f6d6a4e3800 4 rocksdb: Options.paranoid_file_checks: 0 2016-12-11 07:44:12.400778 7f6d6a4e3800 4 rocksdb: Options.report_bg_io_stats: 0 2016-12-11 07:44:12.582803 7f6d6a4e3800 4 rocksdb: Recovered from manifest file:db/MANIFEST-000064 succeeded,manifest_file_number is 64, next_file_number is 66, last_sequence is 2601688, log_number is 0,prev_log_number is 0,max_column_family is 0 2016-12-11 07:44:12.582817 7f6d6a4e3800 4 rocksdb: Column family [default] (ID 0), log number is 62 2016-12-11 07:44:12.582900 7f6d6a4e3800 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431452582890, "job": 1, "event": "recovery_started", "log_files": [65, 68]} 2016-12-11 07:44:12.582904 7f6d6a4e3800 4 rocksdb: Recovering log #65 mode 0 2016-12-11 07:44:13.519285 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.534418 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.540922 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.546150 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.553405 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.568758 7f6d6a4e3800 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431453568738, "cf_name": "default", "job": 1, "event": "table_file_creation", "file_number": 66, "file_size": 39871603, "table_properties": {"data_size": 39184879, "index_size": 685813, "filter_size": 0, "raw_key_size": 28505469, "raw_average_key_size": 67, "raw_value_size": 28008401, "raw_average_value_size": 66, "num_data_blocks": 9892, "num_entries": 421391, "filter_policy_name": "", "kDeletedKeys": "320106", "kMergeOperands": "3122"}} 2016-12-11 07:44:13.572518 7f6d6a4e3800 4 rocksdb: Recovering log #68 mode 0 2016-12-11 07:44:13.647788 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.651586 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.655448 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.659634 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.663766 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.676266 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.681993 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.688478 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.696017 7f6d6a4e3800 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431453696000, "cf_name": "default", "job": 1, "event": "table_file_creation", "file_number": 69, "file_size": 7988661, "table_properties": {"data_size": 7844044, "index_size": 143710, "filter_size": 0, "raw_key_size": 1801132, "raw_average_key_size": 68, "raw_value_size": 7108665, "raw_average_value_size": 268, "num_data_blocks": 2032, "num_entries": 26483, "filter_policy_name": "", "kDeletedKeys": "101", "kMergeOperands": "3"}} 2016-12-11 07:44:13.696945 7f6d6a4e3800 4 rocksdb: Creating manifest 70 2016-12-11 07:44:13.697012 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.697285 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.697566 7f6d6a4e3800 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431453697562, "job": 1, "event": "recovery_finished"} 2016-12-11 07:44:13.697622 7f6d6a4e3800 4 rocksdb: Unrecognized log file . 2016-12-11 07:44:13.697625 7f6d6a4e3800 4 rocksdb: Unrecognized log file .. 2016-12-11 07:44:13.697939 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.698343 7f6d6a4e3800 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-11 07:44:13.699168 7f6d6a4e3800 4 rocksdb: DB pointer 0x7f6d756dca00 2016-12-11 07:44:13.699204 7f6d6a4e3800 1 bluestore(/var/lib/ceph/osd/ceph-51) _open_db opened rocksdb path db options compression=kNoCompression,max_write_buffer_number=16,min_write_buffer_number_to_merge=3,recycle_log_file_num=16 2016-12-11 07:44:13.699458 7f6d53a7e700 3 rocksdb: ------- DUMPING STATS ------- 2016-12-11 07:44:13.699479 7f6d53a7e700 3 rocksdb: ** Compaction Stats [default] ** Level Files Size(MB) 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 4/0 142.56 1.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 99.7 0 2 0.229 0 0 L1 4/0 228.97 0.9 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0 L2 3/0 193.94 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 11/0 565.46 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 99.7 0 2 0.229 0 0 Int 0/0 0.00 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 99.7 0 2 0.229 0 0 Uptime(secs): 1.3 total, 1.3 interval AddFile(GB): cumulative 0.000, interval 0.000 Cumulative compaction: 0.04 GB write, 35.14 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.5 seconds Interval compaction: 0.04 GB write, 35.14 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.5 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 ** 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 2016-12-11 07:44:13.699644 7f6d53a7e700 4 rocksdb: [default] [JOB 3] Compacting 4@0 + 4@1 files to L1, score 1.00 2016-12-11 07:44:13.699665 7f6d53a7e700 4 rocksdb: [default] Compaction start summary: Base version 2 Base level 0, inputs: [69(7801KB) 66(38MB) 63(45MB) 62(51MB)], [54(64MB) 56(64MB) 57(64MB) 58(34MB)] 2016-12-11 07:44:13.699738 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431453699673, "job": 3, "event": "compaction_started", "files_L0": [69, 66, 63, 62], "files_L1": [54, 56, 57, 58], "score": 1, "input_data_size": 389573215} 2016-12-11 07:44:13.761158 7f6d6a4e3800 1 freelist init 2016-12-11 07:44:14.720220 7f6d6a4e3800 0 <cls> /mnt/jenkins/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/11.0.2/rpm/el7/BUILD/ceph-11.0.2/src/cls/hello/cls_hello.cc:305: loading cls_hello 2016-12-11 07:44:14.720343 7f6d6a4e3800 0 <cls> /mnt/jenkins/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/11.0.2/rpm/el7/BUILD/ceph-11.0.2/src/cls/cephfs/cls_cephfs.cc:202: loading cephfs_size_scan 2016-12-11 07:44:14.720780 7f6d6a4e3800 0 _get_class not permitted to load kvs 2016-12-11 07:44:14.720787 7f6d6a4e3800 0 _get_class not permitted to load lua 2016-12-11 07:44:14.742686 7f6d6a4e3800 0 osd.51 524 crush map has features 2200130813952, adjusting msgr requires for clients 2016-12-11 07:44:14.742696 7f6d6a4e3800 0 osd.51 524 crush map has features 2200130813952 was 8705, adjusting msgr requires for mons 2016-12-11 07:44:14.742702 7f6d6a4e3800 0 osd.51 524 crush map has features 2200130813952, adjusting msgr requires for osds 2016-12-11 07:44:20.152148 7f6d6a4e3800 0 osd.51 524 load_pgs 2016-12-11 07:44:21.985634 7f6d53a7e700 4 rocksdb: [default] [JOB 3] Generated table #74: 469289 keys, 68253805 bytes 2016-12-11 07:44:21.985667 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431461985648, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 74, "file_size": 68253805, "table_properties": {"data_size": 67113187, "index_size": 1139707, "filter_size": 0, "raw_key_size": 32865246, "raw_average_key_size": 70, "raw_value_size": 53624938, "raw_average_value_size": 114, "num_data_blocks": 16520, "num_entries": 469289, "filter_policy_name": "", "kDeletedKeys": "320681", "kMergeOperands": "0"}} 2016-12-11 07:44:25.341365 7f6d53a7e700 4 rocksdb: [default] [JOB 3] Generated table #75: 58446 keys, 68143723 bytes 2016-12-11 07:44:25.341398 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431465341382, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 75, "file_size": 68143723, "table_properties": {"data_size": 67111957, "index_size": 1030858, "filter_size": 0, "raw_key_size": 7743349, "raw_average_key_size": 132, "raw_value_size": 62120816, "raw_average_value_size": 1062, "num_data_blocks": 15179, "num_entries": 58446, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2016-12-11 07:44:28.695943 7f6d53a7e700 4 rocksdb: [default] [JOB 3] Generated table #76: 58337 keys, 68140865 bytes 2016-12-11 07:44:28.695976 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431468695960, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 76, "file_size": 68140865, "table_properties": {"data_size": 67113639, "index_size": 1026318, "filter_size": 0, "raw_key_size": 7733501, "raw_average_key_size": 132, "raw_value_size": 62131020, "raw_average_value_size": 1065, "num_data_blocks": 15175, "num_entries": 58337, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2016-12-11 07:44:31.149222 7f6d53a7e700 4 rocksdb: [default] [JOB 3] Generated table #77: 58861 keys, 68145852 bytes 2016-12-11 07:44:31.149271 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431471149241, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 77, "file_size": 68145852, "table_properties": {"data_size": 67113770, "index_size": 1031174, "filter_size": 0, "raw_key_size": 7802753, "raw_average_key_size": 132, "raw_value_size": 62116898, "raw_average_value_size": 1055, "num_data_blocks": 15169, "num_entries": 58861, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2016-12-11 07:44:32.034725 7f6d53a7e700 4 rocksdb: [default] [JOB 3] Generated table #78: 253917 keys, 19631295 bytes 2016-12-11 07:44:32.034756 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431472034741, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 78, "file_size": 19631295, "table_properties": {"data_size": 19395540, "index_size": 234845, "filter_size": 0, "raw_key_size": 5752553, "raw_average_key_size": 22, "raw_value_size": 14896527, "raw_average_value_size": 58, "num_data_blocks": 4531, "num_entries": 253917, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "79826"}} 2016-12-11 07:44:32.034816 7f6d53a7e700 4 rocksdb: [default] [JOB 3] Compacted 4@0 + 4@1 files to L1 => 292315540 bytes 2016-12-11 07:44:32.035486 7f6d53a7e700 4 rocksdb: (Original Log Time 2016/12/11-07:44:32.035367) [default] compacted to: base level 1 max bytes base 268435456 files[0 5 3 0 0 0 0] max score 1.57, MB/sec: 21.2 rd, 15.9 wr, level 1, files in(4, 4) out(5) MB in(142.6, 229.0) out(278.8), read-write-amplify(4.6) write-amplify(2.0) OK, records in: 1221704, records dropped: 322846 2016-12-11 07:44:32.035500 7f6d53a7e700 4 rocksdb: (Original Log Time 2016/12/11-07:44:32.035389) EVENT_LOG_v1 {"time_micros": 1481431472035378, "job": 3, "event": "compaction_finished", "compaction_time_micros": 18335027, "output_level": 1, "num_output_files": 5, "total_output_size": 292315540, "num_input_records": 1221696, "num_output_records": 898850, "num_subcompactions": 1, "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [0, 5, 3, 0, 0, 0, 0]} 2016-12-11 07:44:32.035542 7f6d53a7e700 4 rocksdb: [default] [JOB 4] Compacting 1@1 + 2@2 files to L2, score 1.57 2016-12-11 07:44:32.035549 7f6d53a7e700 4 rocksdb: [default] Compaction start summary: Base version 3 Base level 1, inputs: [74(65MB)], [59(65MB) 60(63MB)] 2016-12-11 07:44:32.035562 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431472035553, "job": 4, "event": "compaction_started", "files_L1": [74], "files_L2": [59, 60], "score": 1.57485, "input_data_size": 203456179} 2016-12-11 07:44:34.167062 7f6d6a4e3800 0 osd.51 524 load_pgs opened 289 pgs 2016-12-11 07:44:34.167540 7f6d6a4e3800 0 osd.51 524 using 1 op queue with priority op cut off at 64. 2016-12-11 07:44:34.168372 7f6d6a4e3800 -1 osd.51 524 log_to_monitors {default=true} 2016-12-11 07:44:34.184162 7f6d6a4e3800 0 osd.51 524 done with init, starting boot process 2016-12-11 07:44:34.470355 7f6d621dc700 -1 osd.51 544 OSD::ms_get_authorizer build_authorizer returned 0x7f6d755d3f40 2016-12-11 07:44:35.150608 7f6d53a7e700 4 rocksdb: [default] [JOB 4] Generated table #79: 270407 keys, 68168318 bytes 2016-12-11 07:44:35.150639 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431475150624, "cf_name": "default", "job": 4, "event": "table_file_creation", "file_number": 79, "file_size": 68168318, "table_properties": {"data_size": 67111259, "index_size": 1056150, "filter_size": 0, "raw_key_size": 13488738, "raw_average_key_size": 49, "raw_value_size": 62617933, "raw_average_value_size": 231, "num_data_blocks": 16870, "num_entries": 270407, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2016-12-11 07:44:35.419877 7f6d621dc700 -1 osd.51 545 OSD::ms_get_authorizer build_authorizer returned 0x7f6d97389ac0 2016-12-11 07:44:35.455153 7f6d621dc700 -1 osd.51 545 OSD::ms_get_authorizer build_authorizer returned 0x7f6d97389b60 2016-12-11 07:44:35.455290 7f6d619db700 -1 osd.51 545 OSD::ms_get_authorizer build_authorizer returned 0x7f6d755d5c00 2016-12-11 07:44:35.455625 7f6d621dc700 -1 osd.51 545 OSD::ms_get_authorizer build_authorizer returned 0x7f6d97389b60 2016-12-11 07:44:35.455790 7f6d619db700 -1 osd.51 545 OSD::ms_get_authorizer build_authorizer returned 0x7f6d755d5c00 2016-12-11 07:44:35.456666 7f6d629dd700 0 -- 192.168.36.7:6859/2001423 >> :/0 conn(0x7f6d96731800 :6859 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).fault with nothing to send and in the half accept state just closed 2016-12-11 07:44:35.460996 7f6d619db700 0 -- 192.168.36.7:6859/2001423 >> :/0 conn(0x7f6d7db40800 :6859 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).fault with nothing to send and in the half accept state just closed 2016-12-11 07:44:35.462096 7f6d629dd700 -1 osd.51 545 OSD::ms_get_authorizer build_authorizer returned 0x7f6d97387a40 2016-12-11 07:44:35.462185 7f6d629dd700 0 -- 192.168.36.7:6859/2001423 >> 192.168.36.7:6881/572077 conn(0x7f6d96733000 :6859 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connect_seq 0 vs existing csq=0 existing_state=STATE_CONNECTING_WAIT_CONNECT_REPLY 2016-12-11 07:44:35.462446 7f6d629dd700 0 -- 192.168.36.7:6859/2001423 >> 192.168.36.7:6881/572077 conn(0x7f6d96733000 :6859 s=STATE_ACCEPTING_WAIT_CONNECT_MSG pgs=0 cs=0 l=0).fault with nothing to send and in the half accept state just closed 2016-12-11 07:44:35.462509 7f6d629dd700 -1 osd.51 545 OSD::ms_get_authorizer build_authorizer returned 0x7f6d97387a40 2016-12-11 07:44:39.480616 7f6d53a7e700 4 rocksdb: [default] [JOB 4] Generated table #80: 189781 keys, 68240173 bytes 2016-12-11 07:44:39.480650 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431479480635, "cf_name": "default", "job": 4, "event": "table_file_creation", "file_number": 80, "file_size": 68240173, "table_properties": {"data_size": 67111623, "index_size": 1127641, "filter_size": 0, "raw_key_size": 12861998, "raw_average_key_size": 67, "raw_value_size": 61413015, "raw_average_value_size": 323, "num_data_blocks": 16624, "num_entries": 189781, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2016-12-11 07:44:41.289937 7f6d53a7e700 4 rocksdb: [default] [JOB 4] Generated table #81: 50661 keys, 58152239 bytes 2016-12-11 07:44:41.289968 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431481289954, "cf_name": "default", "job": 4, "event": "table_file_creation", "file_number": 81, "file_size": 58152239, "table_properties": {"data_size": 57265197, "index_size": 886134, "filter_size": 0, "raw_key_size": 6715867, "raw_average_key_size": 132, "raw_value_size": 52992189, "raw_average_value_size": 1046, "num_data_blocks": 12950, "num_entries": 50661, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}} 2016-12-11 07:44:41.290126 7f6d53a7e700 4 rocksdb: [default] [JOB 4] Compacted 1@1 + 2@2 files to L2 => 194560730 bytes 2016-12-11 07:44:41.290832 7f6d53a7e700 4 rocksdb: (Original Log Time 2016/12/11-07:44:41.290562) [default] compacted to: base level 1 max bytes base 268435456 files[0 4 4 0 0 0 0] max score 0.83, MB/sec: 22.0 rd, 21.0 wr, level 2, files in(1, 2) out(3) MB in(65.1, 128.9) out(185.5), read-write-amplify(5.8) write-amplify(2.9) OK, records in: 833070, records dropped: 322221 2016-12-11 07:44:41.290843 7f6d53a7e700 4 rocksdb: (Original Log Time 2016/12/11-07:44:41.290585) EVENT_LOG_v1 {"time_micros": 1481431481290576, "job": 4, "event": "compaction_finished", "compaction_time_micros": 9254547, "output_level": 2, "num_output_files": 3, "total_output_size": 194560730, "num_input_records": 833070, "num_output_records": 510849, "num_subcompactions": 1, "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [0, 4, 4, 0, 0, 0, 0]} 2016-12-11 07:44:41.290882 7f6d53a7e700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1481431481290878, "job": 4, "event": "table_file_deletion", "file_number": 74} 2016-12-11 07:51:35.828760 7f6d629dd700 -1 osd.51 549 OSD::ms_get_authorizer build_authorizer returned 0x7f6d9785ad00 2016-12-11 07:56:41.205313 7f6d54a80700 1 bluefs _allocate failed to allocate 0x100000 on bdev 0, free 0xff000; fallback to bdev 1 2016-12-11 07:56:41.205323 7f6d54a80700 1 bluefs _allocate failed to allocate 0x100000 on bdev 1, free 0xfe000; fallback to bdev 2 2016-12-12 00:01:01.399164 7f6d46263700 -1 received signal: Hangup from PID: 2173364 task name: killall -q -1 ceph-mon ceph-mds ceph-osd ceph-fuse radosgw UID: 0 <pre> I've also attached the log for OSD 52 which failed next.
Files
Actions