Hi,
Since about 2 week master is crashing on one of my new test servers.
And I can't seem to figure out why.
It looks even like it crashes before ceph-mon starts to fork off
threads, when I'm using vstart.sh to get a test cluster?
Log dump is below, but the last message stems from:
./src/mon/OSDMonitor.cc:859
creating_pgs_t
OSDMonitor::update_pending_pgs() {
........
........
dout(10) << __func__ << " queue remaining: " <<
pending_creatings.queue.size()
<< " pools" << dendl;
dout(10) << __func__
<< " " << (pending_creatings.pgs.size() - total)
<< "/" << pending_creatings.pgs.size()
<< " pgs added from queued pools" << dendl;
return pending_creatings;
}
Continue from there gives:
Thread 1 received signal SIGSEGV, Segmentation fault.
0x0000000803a2587b in OSDMap::check_health (this=0x7fffffff3c68,
checks=0x7fffffff3778)
at /home/wjw/wip/src/osd/OSDMap.cc:4999
4999 float fsr = g_conf()->osd_failsafe_full_ratio;
Which is on the lines:
4995 // OSD_OUT_OF_ORDER_FULL
4996 {
4997 // An osd could configure failsafe ratio, to something different
4998 // but for now assume it is the same here.
4999 float fsr = g_conf()->osd_failsafe_full_ratio;
5000 if (fsr > 1.0) fsr /= 100;
5001 float fr = get_full_ratio();
5002 float br = get_backfillfull_ratio();
5003 float nr = get_nearfull_ratio();
And in the end the debugger tells me it crashed like:
#0 0x0000000803a2587b in OSDMap::check_health (this=0x7fffffff3c68,
checks=0x7fffffff3778)
at /home/wjw/wip/src/osd/OSDMap.cc:4999
#1 0x0000000000de2c71 in OSDMonitor::encode_pending (this=0x2e24000,
t=...) at /home/wjw/wip/src/mon/OSDMonitor.cc:1459
#2 0x00000000010399cf in PaxosService::propose_pending (this=0x2e24000)
at /home/wjw/wip/src/mon/PaxosService.cc:213
#3 0x000000000103b8b2 in PaxosService::_active (this=0x2e24000) at
/home/wjw/wip/src/mon/PaxosService.cc:334
#4 0x000000000103af96 in PaxosService::election_finished
(this=0x2e24000) at /home/wjw/wip/src/mon/PaxosService.cc:290
#5 0x0000000000bc5969 in Monitor::_finish_svc_election (this=0x2e11000)
at /home/wjw/wip/src/mon/Monitor.cc:1960
#6 0x0000000000bc4af7 in Monitor::win_election (this=0x2e11000,
epoch=7, active=..., features=4611087854031142911,
mon_features=..., metadata=...) at
/home/wjw/wip/src/mon/Monitor.cc:1994
#7 0x0000000000bb5e28 in Monitor::win_standalone_election
(this=0x2e11000) at /home/wjw/wip/src/mon/Monitor.cc:1935
#8 0x0000000000bb3360 in Monitor::bootstrap (this=0x2e11000) at
/home/wjw/wip/src/mon/Monitor.cc:1033
#9 0x0000000000bb28ed in Monitor::init (this=0x2e11000) at
/home/wjw/wip/src/mon/Monitor.cc:838
#10 0x0000000000b29898 in main (argc=10, argv=0x7fffffffe818) at
/home/wjw/wip/src/ceph_mon.cc:794
Suggesting that g_conf() return a pointer that is is not valid...????
And it is consistently at the location that it crashes...
As usual, any suggestions are welcome.
--WjW
--- begin dump of recent events ---
-415> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command abort hook 0x29201a0
-414> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command perfcounters_dump hook 0x29201a0
-413> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command 1 hook 0x29201a0
-412> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command perf dump hook 0x29201a0
-411> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command perfcounters_schema hook 0x29201a0
-410> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command perf histogram dump hook 0x29201a0
-409> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command 2 hook 0x29201a0
-408> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command perf schema hook 0x29201a0
-407> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command perf histogram schema hook 0x29201a0
-406> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command perf reset hook 0x29201a0
-405> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command config show hook 0x29201a0
-404> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command config help hook 0x29201a0
-403> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command config set hook 0x29201a0
-402> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command config unset hook 0x29201a0
-401> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command config get hook 0x29201a0
-400> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command config diff hook 0x29201a0
-399> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command config diff get hook 0x29201a0
-398> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command log flush hook 0x29201a0
-397> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command log dump hook 0x29201a0
-396> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command log reopen hook 0x29201a0
-395> 2018-09-03 15:30:23.572 2912480 5 asok(0x2bf8000)
register_command dump_mempools hook 0x2c66068
-394> 2018-09-03 15:30:23.589 2912480 1 lockdep start
-393> 2018-09-03 15:30:23.590 2912480 0 ceph version Development
(no_version) nautilus (dev), process ceph-mon, pid 14324
-392> 2018-09-03 15:30:23.595 2912480 1 lockdep using id 0
-391> 2018-09-03 15:30:23.595 2912480 5 asok(0x2bf8000) init
/tmp/ceph-asok.FBIxXs/mon.a.asok
-390> 2018-09-03 15:30:23.595 2912480 5 asok(0x2bf8000)
bind_and_listen /tmp/ceph-asok.FBIxXs/mon.a.asok
-389> 2018-09-03 15:30:23.595 2912480 5 asok(0x2bf8000)
register_command 0 hook 0x291f3e0
-388> 2018-09-03 15:30:23.595 2912480 5 asok(0x2bf8000)
register_command version hook 0x291f3e0
-387> 2018-09-03 15:30:23.595 2912480 5 asok(0x2bf8000)
register_command git_version hook 0x291f3e0
-386> 2018-09-03 15:30:23.595 2912480 5 asok(0x2bf8000)
register_command help hook 0x29202a0
-385> 2018-09-03 15:30:23.595 2912480 5 asok(0x2bf8000)
register_command get_command_descriptions hook 0x29202b0
-384> 2018-09-03 15:30:23.595 2912480 1 lockdep using id 1
-383> 2018-09-03 15:30:23.595 2bd6d00 5 asok(0x2bf8000) entry start
-382> 2018-09-03 15:30:23.647 2912480 1 lockdep using id 2
-381> 2018-09-03 15:30:23.647 2912480 0 load: jerasure load: lrc
load: isa
-380> 2018-09-03 15:30:23.647 2912480 1 lockdep using id 3
-379> 2018-09-03 15:30:23.647 2912480 1 lockdep using id 4
-378> 2018-09-03 15:30:23.647 2912480 1 lockdep using id 5
-377> 2018-09-03 15:30:23.647 2912480 1 lockdep using id 6
-376> 2018-09-03 15:30:23.647 2912480 1 lockdep using id 7
-375> 2018-09-03 15:30:23.647 2912480 0 set rocksdb option
compression = kNoCompression
-374> 2018-09-03 15:30:23.647 2912480 0 set rocksdb option
level_compaction_dynamic_level_bytes = true
-373> 2018-09-03 15:30:23.647 2912480 0 set rocksdb option
write_buffer_size = 33554432
-372> 2018-09-03 15:30:23.647 2912480 0 set rocksdb option
compression = kNoCompression
-371> 2018-09-03 15:30:23.647 2912480 0 set rocksdb option
level_compaction_dynamic_level_bytes = true
-370> 2018-09-03 15:30:23.647 2912480 0 set rocksdb option
write_buffer_size = 33554432
-369> 2018-09-03 15:30:23.648 2912480 1 rocksdb: do_open column
families: [default]
-368> 2018-09-03 15:30:23.648 2912480 4 rocksdb: RocksDB version: 5.14.0
-367> 2018-09-03 15:30:23.648 2912480 4 rocksdb: Git sha
rocksdb_build_git_sha:@bc7e8d472e7d37a33f3f45dec393769011ec1e08@
-366> 2018-09-03 15:30:23.648 2912480 4 rocksdb: Compile date Sep 2
2018
-365> 2018-09-03 15:30:23.648 2912480 4 rocksdb: DB SUMMARY
-364> 2018-09-03 15:30:23.648 2912480 4 rocksdb: CURRENT file: CURRENT
-363> 2018-09-03 15:30:23.648 2912480 4 rocksdb: IDENTITY file:
IDENTITY
-362> 2018-09-03 15:30:23.648 2912480 4 rocksdb: MANIFEST file:
MANIFEST-000001 size: 13 Bytes
-361> 2018-09-03 15:30:23.648 2912480 4 rocksdb: SST files in
/home/wjw/wip/build/dev/mon.a/store.db dir, Total Num: 0, files:
-360> 2018-09-03 15:30:23.648 2912480 4 rocksdb: Write Ahead Log
file in /home/wjw/wip/build/dev/mon.a/store.db: 000003.log size: 855 ;
-359> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.error_if_exists: 0
-358> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.create_if_missing: 0
-357> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.paranoid_checks: 1
-356> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.env: 0x2110398
-355> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.info_log: 0x2c7e760
-354> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_file_opening_threads: 16
-353> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.statistics: 0x0
-352> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.use_fsync: 0
-351> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_log_file_size: 0
-350> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_manifest_file_size: 1073741824
-349> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.log_file_time_to_roll: 0
-348> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.keep_log_file_num: 1000
-347> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.recycle_log_file_num: 0
-346> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.allow_fallocate: 1
-345> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.allow_mmap_reads: 0
-344> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.allow_mmap_writes: 0
-343> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.use_direct_reads: 0
-342> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.use_direct_io_for_flush_and_compaction: 0
-341> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.create_missing_column_families: 0
-340> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.db_log_dir:
-339> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.wal_dir: /home/wjw/wip/build/dev/mon.a/store.db
-338> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.table_cache_numshardbits: 6
-337> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_subcompactions: 1
-336> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_background_flushes: -1
-335> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.WAL_ttl_seconds: 0
-334> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.WAL_size_limit_MB: 0
-333> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.manifest_preallocation_size: 4194304
-332> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.is_fd_close_on_exec: 1
-331> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.advise_random_on_open: 1
-330> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.db_write_buffer_size: 0
-329> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.write_buffer_manager: 0x2c1def0
-328> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.access_hint_on_compaction_start: 1
-327> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.new_table_reader_for_compaction_inputs: 0
-326> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.random_access_max_buffer_size: 1048576
-325> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.use_adaptive_mutex: 0
-324> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.rate_limiter: 0x0
-323> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.sst_file_manager.rate_bytes_per_sec: 0
-322> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.wal_recovery_mode: 2
-321> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.enable_thread_tracking: 0
-320> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.enable_pipelined_write: 0
-319> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.allow_concurrent_memtable_write: 1
-318> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.enable_write_thread_adaptive_yield: 1
-317> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.write_thread_max_yield_usec: 100
-316> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.write_thread_slow_yield_usec: 3
-315> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.row_cache: None
-314> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.wal_filter: None
-313> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.avoid_flush_during_recovery: 0
-312> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.allow_ingest_behind: 0
-311> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.preserve_deletes: 0
-310> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.two_write_queues: 0
-309> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.manual_wal_flush: 0
-308> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_background_jobs: 2
-307> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_background_compactions: -1
-306> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.avoid_flush_during_shutdown: 0
-305> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.writable_file_max_buffer_size: 1048576
-304> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.delayed_write_rate : 16777216
-303> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_total_wal_size: 0
-302> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.delete_obsolete_files_period_micros: 21600000000
-301> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.stats_dump_period_sec: 600
-300> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.max_open_files: -1
-299> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.bytes_per_sync: 0
-298> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.wal_bytes_per_sync: 0
-297> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
Options.compaction_readahead_size: 0
-296> 2018-09-03 15:30:23.648 2912480 4 rocksdb: Compression
algorithms supported:
-295> 2018-09-03 15:30:23.648 2912480 4 rocksdb: kZSTD supported: 0
-294> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
kZlibCompression supported: 1
-293> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
kXpressCompression supported: 0
-292> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
kSnappyCompression supported: 1
-291> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
kZSTDNotFinalCompression supported: 0
-290> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
kLZ4HCCompression supported: 1
-289> 2018-09-03 15:30:23.648 2912480 4 rocksdb: kLZ4Compression
supported: 1
-288> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
kBZip2Compression supported: 0
-287> 2018-09-03 15:30:23.648 2912480 4 rocksdb: Fast CRC32
supported: Supported on x86
-286> 2018-09-03 15:30:23.648 2912480 4 rocksdb:
[/home/wjw/wip/src/rocksdb/db/version_set.cc:3096] Recovering from
manifest file: MANIFEST-000001
-285> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
[/home/wjw/wip/src/rocksdb/db/column_family.cc:475] ---------------
Options for column family [default]:
-284> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.comparator: leveldb.BytewiseComparator
-283> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.merge_operator:
-282> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_filter: None
-281> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_filter_factory: None
-280> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.memtable_factory: SkipListFactory
-279> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.table_factory: BlockBasedTable
-278> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
table_factory options: flush_block_policy_factory:
FlushBlockBySizePolicyFactory (0x291f3e8)
cache_index_and_filter_blocks: 1
cache_index_and_filter_blocks_with_high_priority: 1
pin_l0_filter_and_index_blocks_in_cache: 1
index_type: 0
hash_index_allow_collision: 1
checksum: 1
no_block_cache: 0
block_cache: 0x2cd34b8
block_cache_name: BinnedLRUCache
block_cache_options:
capacity : 134217728
num_shard_bits : 4
strict_capacity_limit : 0
high_pri_pool_ratio: 0.000
block_cache_compressed: 0x0
persistent_cache: 0x0
block_size: 4096
block_size_deviation: 10
block_restart_interval: 16
index_block_restart_interval: 1
metadata_block_size: 4096
partition_filters: 0
use_delta_encoding: 1
filter_policy: rocksdb.BuiltinBloomFilter
whole_key_filtering: 1
verify_compression: 0
read_amp_bytes_per_bit: 0
format_version: 2
enable_index_compression: 1
block_align: 0
-277> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.write_buffer_size: 33554432
-276> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_write_buffer_number: 2
-275> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compression: NoCompression
-274> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.bottommost_compression: Disabled
-273> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.prefix_extractor: nullptr
-272> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.memtable_insert_with_hint_prefix_extractor: nullptr
-271> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.num_levels: 7
-270> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.min_write_buffer_number_to_merge: 1
-269> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_write_buffer_number_to_maintain: 0
-268> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compression_opts.window_bits: -14
-267> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compression_opts.level: 32767
-266> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compression_opts.strategy: 0
-265> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compression_opts.max_dict_bytes: 0
-264> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compression_opts.zstd_max_train_bytes: 0
-263> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.level0_file_num_compaction_trigger: 4
-262> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.level0_slowdown_writes_trigger: 20
-261> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.level0_stop_writes_trigger: 36
-260> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.target_file_size_base: 67108864
-259> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.target_file_size_multiplier: 1
-258> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_base: 268435456
-257> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.level_compaction_dynamic_level_bytes: 1
-256> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_multiplier: 10.000000
-255> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_multiplier_addtl[0]: 1
-254> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_multiplier_addtl[1]: 1
-253> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_multiplier_addtl[2]: 1
-252> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_multiplier_addtl[3]: 1
-251> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_multiplier_addtl[4]: 1
-250> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_multiplier_addtl[5]: 1
-249> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_bytes_for_level_multiplier_addtl[6]: 1
-248> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_sequential_skip_in_iterations: 8
-247> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_compaction_bytes: 1677721600
-246> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.arena_block_size: 4194304
-245> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.soft_pending_compaction_bytes_limit: 68719476736
-244> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.hard_pending_compaction_bytes_limit: 274877906944
-243> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.rate_limit_delay_max_milliseconds: 100
-242> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.disable_auto_compactions: 0
-241> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_style: kCompactionStyleLevel
-240> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_pri: kByCompensatedSize
-239> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_universal.size_ratio: 1
-238> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_universal.min_merge_width: 2
-237> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_universal.max_merge_width: 4294967295
-236> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_universal.max_size_amplification_percent: 200
-235> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_universal.compression_size_percent: -1
-234> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_universal.stop_style:
kCompactionStopStyleTotalSize
-233> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_fifo.max_table_files_size: 1073741824
-232> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_fifo.allow_compaction: 0
-231> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.compaction_options_fifo.ttl: 0
-230> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.table_properties_collectors:
-229> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.inplace_update_support: 0
-228> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.inplace_update_num_locks: 10000
-227> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.memtable_prefix_bloom_size_ratio: 0.000000
-226> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.memtable_huge_page_size: 0
-225> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.bloom_locality: 0
-224> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.max_successive_merges: 0
-223> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.optimize_filters_for_hits: 0
-222> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.paranoid_file_checks: 0
-221> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.force_consistency_checks: 0
-220> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.report_bg_io_stats: 0
-219> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
Options.ttl: 0
-218> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
[/home/wjw/wip/src/rocksdb/db/version_set.cc:3374] Recovered from
manifest file:/home/wjw/wip/build/dev/mon.a/store.db/MANIFEST-000001
succeeded,manifest_file_number is 1, next_file_number is 3,
last_sequence is 0, log_number is 0,prev_log_number is
0,max_column_family is 0,min_log_number_to_keep is 0
-217> 2018-09-03 15:30:23.649 2912480 4 rocksdb:
[/home/wjw/wip/src/rocksdb/db/version_set.cc:3382] Column family
[default] (ID 0), log number is 0
-216> 2018-09-03 15:30:23.650 2912480 4 rocksdb: EVENT_LOG_v1
{"time_micros": 1535981423650028, "job": 1, "event": "recovery_started",
"log_files": [3]}
-215> 2018-09-03 15:30:23.650 2912480 4 rocksdb:
[/home/wjw/wip/src/rocksdb/db/db_impl_open.cc:551] Recovering log #3 mode 2
-214> 2018-09-03 15:30:23.650 2912480 4 rocksdb: EVENT_LOG_v1
{"time_micros": 1535981423650866, "cf_name": "default", "job": 1,
"event": "table_file_creation", "file_number": 4, "file_size": 1891,
"table_properties": {"data_size": 867, "index_size": 28, "filter_size":
23, "raw_key_size": 115, "raw_average_key_size": 23, "raw_value_size":
744, "raw_average_value_size": 148, "num_data_blocks": 1, "num_entries":
5, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys":
"0", "kMergeOperands": "0"}}
-213> 2018-09-03 15:30:23.650 2912480 4 rocksdb:
[/home/wjw/wip/src/rocksdb/db/version_set.cc:2858] Creating manifest 5
-212> 2018-09-03 15:30:23.651 2912480 4 rocksdb: EVENT_LOG_v1
{"time_micros": 1535981423651578, "job": 1, "event": "recovery_finished"}
-211> 2018-09-03 15:30:23.656 2912480 4 rocksdb:
[/home/wjw/wip/src/rocksdb/db/db_impl_open.cc:1219] DB pointer 0x2b12c00
-210> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 8
-209> 2018-09-03 15:30:23.656 2912480 10 obtain_monmap
-208> 2018-09-03 15:30:23.656 2912480 10 obtain_monmap found mkfs monmap
-207> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 9
-206> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 10
-205> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 11
-204> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 12
-203> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 13
-202> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 14
-201> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 15
-200> 2018-09-03 15:30:23.656 2912480 1 lockdep using id 16
-199> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 17
-198> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 18
-197> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 19
-196> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 20
-195> 2018-09-03 15:30:23.657 2912480 0 starting mon.a rank 0 at
public addr 192.168.10.78:40238/0 at bind addr 192.168.10.78:40238/0
mon_data /home/wjw/wip/build/dev/mon.a fsid
6bb4547f-eb61-463d-a7c2-0ca77db4c76f
-194> 2018-09-03 15:30:23.657 2912480 1 -- 192.168.10.78:40238/0
learned_addr learned my addr 192.168.10.78:40238/0 (peer_addr_for_me
192.168.10.78:40238/0)
-193> 2018-09-03 15:30:23.657 2912480 1 -- 192.168.10.78:40238/0
_finish_bind bind my_addrs is 192.168.10.78:40238/0
-192> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 21
-191> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 22
-190> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 23
-189> 2018-09-03 15:30:23.657 2912480 0 starting mon.a rank 0 at
192.168.10.78:40238/0 mon_data /home/wjw/wip/build/dev/mon.a fsid
6bb4547f-eb61-463d-a7c2-0ca77db4c76f
-188> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 24
-187> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 25
-186> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 26
-185> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 27
-184> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 28
-183> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 29
-182> 2018-09-03 15:30:23.657 2912480 5 adding auth protocol: cephx
-181> 2018-09-03 15:30:23.657 2912480 5 adding auth protocol: cephx
-180> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 30
-179> 2018-09-03 15:30:23.657 2912480 1 lockdep using id 31
-178> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 32
-177> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 33
-176> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 34
-175> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 35
-174> 2018-09-03 15:30:23.658 2912480 10 log_channel(cluster)
update_config to_monitors: true to_syslog: false syslog_facility: daemon
prio: info to_graylog: false graylog_host: 127.0.0.1 graylog_port: 12201)
-173> 2018-09-03 15:30:23.658 2912480 10 log_channel(audit)
update_config to_monitors: true to_syslog: false syslog_facility: local0
prio: info to_graylog: false graylog_host: 127.0.0.1 graylog_port: 12201)
-172> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 36
-171> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 37
-170> 2018-09-03 15:30:23.658 2912480 1 mon.a@-1(probing) e0 preinit
fsid 6bb4547f-eb61-463d-a7c2-0ca77db4c76f
-169> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 38
-168> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 39
-167> 2018-09-03 15:30:23.658 2912480 1 lockdep using id 40
-166> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0
check_fsid cluster_uuid contains '6bb4547f-eb61-463d-a7c2-0ca77db4c76f'
-165> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0
features compat={},rocompat={},incompat={1=initial feature set
(~v.18),3=single paxos with k/v store (v0.?)}
-164> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0
calc_quorum_requirements required_features 0
-163> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0
required_features 0
-162> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0
has_ever_joined = 0
-161> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0
sync_last_committed_floor 0
-160> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0 init_paxos
-159> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxos(paxos recovering c 0..0) init last_pn: 0
accepted_pn: 0 last_committed: 0 first_committed: 0
-158> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxos(paxos recovering c 0..0) init
-157> 2018-09-03 15:30:23.659 2912480 1 mon.a@-1(probing).mds e0
Unable to load 'last_metadata'
-156> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing).health init
-155> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing).config init
-154> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0
refresh_from_paxos
-153> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0
refresh_from_paxos no cluster_fingerprint
-152> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(mdsmap 0..0) refresh
-151> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(osdmap 0..0) refresh
-150> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(logm 0..0) refresh
-149> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing).log v0
update_from_paxos
-148> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing).log v0
update_from_paxos version 0 summary v 0
-147> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(monmap 0..0) refresh
-146> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(auth 0..0) refresh
-145> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing).auth v0
update_from_paxos
-144> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(mgr 0..0) refresh
-143> 2018-09-03 15:30:23.659 2912480 20 mgrc handle_mgr_map mgrmap(e
0) v1
-142> 2018-09-03 15:30:23.659 2912480 4 mgrc handle_mgr_map Got map
version 0
-141> 2018-09-03 15:30:23.659 2912480 4 mgrc handle_mgr_map Active
mgr is now
-140> 2018-09-03 15:30:23.659 2912480 4 mgrc reconnect No active mgr
available yet
-139> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(mgrstat 0..0) refresh
-138> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing).mgrstat 0
-137> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing).mgrstat
check_subs
-136> 2018-09-03 15:30:23.659 2912480 20 mon.a@-1(probing).mgrstat
update_logger
-135> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(health 0..0) refresh
-134> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing).health
update_from_paxos
-133> 2018-09-03 15:30:23.659 2912480 20 mon.a@-1(probing).health dump:{
"quorum_health": {},
"leader_health": {}
}
-132> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(config 0..0) refresh
-131> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(mdsmap 0..0) post_refresh
-130> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(osdmap 0..0) post_refresh
-129> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(logm 0..0) post_refresh
-128> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(monmap 0..0) post_refresh
-127> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(auth 0..0) post_refresh
-126> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(mgr 0..0) post_refresh
-125> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(mgrstat 0..0) post_refresh
-124> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(health 0..0) post_refresh
-123> 2018-09-03 15:30:23.659 2912480 10
mon.a@-1(probing).paxosservice(config 0..0) post_refresh
-122> 2018-09-03 15:30:23.659 2912480 10 mon.a@-1(probing) e0 loading
initial keyring to bootstrap authentication for mkfs
-121> 2018-09-03 15:30:23.660 2912480 2 auth: KeyRing::load: loaded
key file /home/wjw/wip/build/dev/mon.a/keyring
-120> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command mon_status hook 0x29204c0
-119> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command quorum_status hook 0x29204c0
-118> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command sync_force hook 0x29204c0
-117> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command add_bootstrap_peer_hint hook 0x29204c0
-116> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command quorum enter hook 0x29204c0
-115> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command quorum exit hook 0x29204c0
-114> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command ops hook 0x29204c0
-113> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command sessions hook 0x29204c0
-112> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command dump_historic_ops hook 0x29204c0
-111> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command dump_historic_ops_by_duration hook 0x29204c0
-110> 2018-09-03 15:30:23.660 2912480 5 asok(0x2bf8000)
register_command dump_historic_slow_ops hook 0x29204c0
-109> 2018-09-03 15:30:23.660 2912480 1 finished global_init_daemonize
-108> 2018-09-03 15:30:23.660 2912480 1 -- 192.168.10.78:40238/0
start start
-107> 2018-09-03 15:30:23.660 2912480 1 -- start start
-106> 2018-09-03 15:30:23.660 2912480 2 mon.a@-1(probing) e0 init
-105> 2018-09-03 15:30:23.660 2912480 1 Processor -- start
-104> 2018-09-03 15:30:23.660 2db2880 1 lockdep using id 41
-103> 2018-09-03 15:30:23.660 2912480 1 Processor -- start
-102> 2018-09-03 15:30:23.660 2912480 10 mon.a@-1(probing) e0 bootstrap
-101> 2018-09-03 15:30:23.660 2912480 10 mon.a@-1(probing) e0
sync_reset_requester
-100> 2018-09-03 15:30:23.660 2912480 10 mon.a@-1(probing) e0
unregister_cluster_logger - not registered
-99> 2018-09-03 15:30:23.660 2912480 10 mon.a@-1(probing) e0
cancel_probe_timeout (none scheduled)
-98> 2018-09-03 15:30:23.660 2912480 10 mon.a@-1(probing) e0
reverting to legacy ranks for seed monmap (epoch 0)
-97> 2018-09-03 15:30:23.660 2912480 10 mon.a@-1(probing) e0 monmap
e0: 1 mons at {a=192.168.10.78:40238/0}
-96> 2018-09-03 15:30:23.660 2912480 0 mon.a@-1(probing) e0 my
rank is now 0 (was -1)
-95> 2018-09-03 15:30:23.660 2912480 1 -- 192.168.10.78:40238/0
shutdown_connections
-94> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0 _reset
-93> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0
cancel_probe_timeout (none scheduled)
-92> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0
timecheck_finish
-91> 2018-09-03 15:30:23.660 2912480 15 mon.a@0(probing) e0
health_tick_stop
-90> 2018-09-03 15:30:23.660 2912480 15 mon.a@0(probing) e0
health_interval_stop
-89> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0
scrub_event_cancel
-88> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0 scrub_reset
-87> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing).paxos(paxos
recovering c 0..0) restart -- canceling timeouts
-86> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(mdsmap 0..0) restart
-85> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(osdmap 0..0) restart
-84> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(logm 0..0) restart
-83> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(monmap 0..0) restart
-82> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(auth 0..0) restart
-81> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(mgr 0..0) restart
-80> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(mgrstat 0..0) restart
-79> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(health 0..0) restart
-78> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(config 0..0) restart
-77> 2018-09-03 15:30:23.660 2912480 1 mon.a@0(probing) e0
win_standalone_election
-76> 2018-09-03 15:30:23.660 2912480 1 mon.a@0(probing).elector(0)
init, first boot, initializing epoch at 1
-75> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing).elector(1)
bump_epoch 1 to 2
-74> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0
join_election
-73> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0 _reset
-72> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0
cancel_probe_timeout (none scheduled)
-71> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0
timecheck_finish
-70> 2018-09-03 15:30:23.660 2912480 15 mon.a@0(probing) e0
health_tick_stop
-69> 2018-09-03 15:30:23.660 2912480 15 mon.a@0(probing) e0
health_interval_stop
-68> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0
scrub_event_cancel
-67> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing) e0 scrub_reset
-66> 2018-09-03 15:30:23.660 2912480 10 mon.a@0(probing).paxos(paxos
recovering c 0..0) restart -- canceling timeouts
-65> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(mdsmap 0..0) restart
-64> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(osdmap 0..0) restart
-63> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(logm 0..0) restart
-62> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(monmap 0..0) restart
-61> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(auth 0..0) restart
-60> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(mgr 0..0) restart
-59> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(mgrstat 0..0) restart
-58> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(health 0..0) restart
-57> 2018-09-03 15:30:23.660 2912480 10
mon.a@0(probing).paxosservice(config 0..0) restart
-56> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(electing) e0
win_election epoch 2 quorum 0 features 4611087854031142911 mon_features
mon_feature_t([kraken,luminous,mimic,osdmap-prune,nautilus])
-55> 2018-09-03 15:30:23.661 2912480 0 log_channel(cluster) log
[INF] : mon.a is new leader, mons a in quorum (ranks 0)
-54> 2018-09-03 15:30:23.661 2912480 10 log_client _send_to_mon log
to self
-53> 2018-09-03 15:30:23.661 2912480 10 log_client log_queue is 1
last_log 1 sent 0 num 1 unsent 1 sending 1
-52> 2018-09-03 15:30:23.661 2912480 10 log_client will send
2018-09-03 15:30:23.661188 mon.a (mon.0) 1 : cluster [INF] mon.a is new
leader, mons a in quorum (ranks 0)
-51> 2018-09-03 15:30:23.661 2912480 1 -- 192.168.10.78:40238/0 -->
192.168.10.78:40238/0 -- log(1 entries from seq 1 at 2018-09-03
15:30:23.661188) v1 -- 0x2948900 con 0x0
-50> 2018-09-03 15:30:23.661 2912480 10
mon.a@0(leader).paxosservice(monmap 0..0) election_finished
-49> 2018-09-03 15:30:23.661 2db3a80 1 -- 192.168.10.78:40238/0 <==
mon.0 192.168.10.78:40238/0 0 ==== log(1 entries from seq 1 at
2018-09-03 15:30:23.661188) v1 ==== 0+0+0 (0 0 0) 0x2948900 con 0x2be9600
-48> 2018-09-03 15:30:23.661 2912480 10
mon.a@0(leader).paxosservice(monmap 0..0) _active
-47> 2018-09-03 15:30:23.661 2912480 7
mon.a@0(leader).paxosservice(monmap 0..0) _active creating new pending
-46> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).monmap v0
create_pending monmap epoch 1
-45> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).monmap v0
create_initial using current monmap
-44> 2018-09-03 15:30:23.661 2912480 10
mon.a@0(leader).paxosservice(monmap 0..0) propose_pending
-43> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).monmap v0
encode_pending epoch 1
-42> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader) e0
prepare_new_fingerprint proposing cluster_fingerprint
223aa142-2f70-455b-91ae-e044447e77f0
-41> 2018-09-03 15:30:23.661 2912480 5 mon.a@0(leader).paxos(paxos
active c 0..0) queue_pending_finisher 0x29204d0
-40> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).paxos(paxos
active c 0..0) trigger_propose active, proposing now
-39> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).paxos(paxos
active c 0..0) propose_pending 1 360 bytes
-38> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).paxos(paxos
updating c 0..0) begin for 1 360 bytes
-37> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).paxos(paxos
updating c 0..0) commit_start 1
-36> 2018-09-03 15:30:23.661 2912480 10
mon.a@0(leader).paxosservice(mdsmap 0..0) election_finished
-35> 2018-09-03 15:30:23.661 2912480 10
mon.a@0(leader).paxosservice(mdsmap 0..0) _active
-34> 2018-09-03 15:30:23.661 2912480 7
mon.a@0(leader).paxosservice(mdsmap 0..0) _active creating new pending
-33> 2018-09-03 15:30:23.661 2912480 5 mon.a@0(leader).paxos(paxos
writing c 0..0) is_readable = 0 - now=2018-09-03 15:30:23.661796
lease_expire=0.000000 has v0 lc 0
-32> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).mds e0
create_pending e1
-31> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).mds e0
create_initial
-30> 2018-09-03 15:30:23.661 2912480 10
mon.a@0(leader).paxosservice(mdsmap 0..0) propose_pending
-29> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).mds e0
encode_pending e1
-28> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader) e0
log_health updated 0 previous 0
-27> 2018-09-03 15:30:23.661 2912480 5 mon.a@0(leader).paxos(paxos
writing c 0..0) queue_pending_finisher 0x29205d0
-26> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).paxos(paxos
writing c 0..0) trigger_propose not active, will propose later
-25> 2018-09-03 15:30:23.661 2912480 10
mon.a@0(leader).paxosservice(osdmap 0..0) election_finished
-24> 2018-09-03 15:30:23.661 2912480 10
mon.a@0(leader).paxosservice(osdmap 0..0) _active
-23> 2018-09-03 15:30:23.661 2912480 7
mon.a@0(leader).paxosservice(osdmap 0..0) _active creating new pending
-22> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).osd e0
create_pending e 1
-21> 2018-09-03 15:30:23.661 2912480 10 mon.a@0(leader).osd e0
create_pending did clean_temps
-20> 2018-09-03 15:30:23.661 2912480 1 mon.a@0(leader).osd e0
create_pending setting backfillfull_ratio = 0.99
-19> 2018-09-03 15:30:23.662 2912480 1 mon.a@0(leader).osd e0
create_pending setting full_ratio = 0.99
-18> 2018-09-03 15:30:23.662 2912480 1 mon.a@0(leader).osd e0
create_pending setting nearfull_ratio = 0.99
-17> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
create_initial for 6bb4547f-eb61-463d-a7c2-0ca77db4c76f
-16> 2018-09-03 15:30:23.662 2912480 20 mon.a@0(leader).osd e0 full
crc 768081425
-15> 2018-09-03 15:30:23.662 2912480 10
mon.a@0(leader).paxosservice(osdmap 0..0) propose_pending
-14> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
encode_pending e 1
-13> 2018-09-03 15:30:23.662 2912480 1 mon.a@0(leader).osd e0
do_prune osdmap full prune enabled
-12> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
should_prune currently holding only 0 epochs (min osdmap epochs: 500);
do not prune.
-11> 2018-09-03 15:30:23.662 2912480 1 mon.a@0(leader).osd e0
encode_pending skipping prime_pg_temp; mapping job did not start
-10> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
encode_pending first mimic+ epoch
-9> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
encode_pending first nautilus+ epoch
-8> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
encode_pending encoding full map with nautilus features 1080873256688298500
-7> 2018-09-03 15:30:23.662 2912480 20 mon.a@0(leader).osd e0
full_crc 768081425 inc_crc 3165708973
-6> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
update_pending_pgs
-5> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
update_pending_pgs 0 pools queued
-4> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
update_pending_pgs 0 pgs removed because they're created
-3> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
update_pending_pgs queue remaining: 0 pools
-2> 2018-09-03 15:30:23.662 2912480 10 mon.a@0(leader).osd e0
update_pending_pgs 0/0 pgs added from queued pools
-1> 2018-09-03 15:30:23.687 2912480 -1 *** Caught signal
(Segmentation fault) **
in thread 2912480 thread_name:
ceph version Development (no_version) nautilus (dev)
1: <handle_fatal_signal(int)+0xc8> at /home/wjw/wip/build/bin/ceph-mon
2: <pthread_sigmask()+0x536> at /lib/libthr.so.3
3: <pthread_getspecific()+0xe12> at /lib/libthr.so.3
NOTE: a copy of the executable, or `objdump -rdS <executable>` is
needed to interpret this.
