Project

General

Profile

Bug #22944 » ceph-mon.smp-016.log

mon log - Radosław Piliszek, 02/13/2018 08:01 AM

 
2018-02-13 08:52:03.069170 7f184e9f9e40 0 set uid:gid to 167:167 (ceph:ceph)
2018-02-13 08:52:03.069200 7f184e9f9e40 0 ceph version 12.2.2 (cf0baeeeeba3b47f9427c6c97e2144b094b7e5ba) luminous (stable), process (unknown), pid 16325
2018-02-13 08:52:03.069427 7f184e9f9e40 0 pidfile_write: ignore empty --pid-file
2018-02-13 08:52:03.112586 7f184e9f9e40 0 load: jerasure load: lrc load: isa
2018-02-13 08:52:03.112774 7f184e9f9e40 0 set rocksdb option compression = kNoCompression
2018-02-13 08:52:03.112788 7f184e9f9e40 0 set rocksdb option write_buffer_size = 33554432
2018-02-13 08:52:03.112824 7f184e9f9e40 0 set rocksdb option compression = kNoCompression
2018-02-13 08:52:03.112832 7f184e9f9e40 0 set rocksdb option write_buffer_size = 33554432
2018-02-13 08:52:03.113012 7f184e9f9e40 4 rocksdb: RocksDB version: 5.4.0

2018-02-13 08:52:03.113024 7f184e9f9e40 4 rocksdb: Git sha rocksdb_build_git_sha:@0@
2018-02-13 08:52:03.113026 7f184e9f9e40 4 rocksdb: Compile date Jan 12 2018
2018-02-13 08:52:03.113031 7f184e9f9e40 4 rocksdb: DB SUMMARY

2018-02-13 08:52:03.113111 7f184e9f9e40 4 rocksdb: CURRENT file: CURRENT

2018-02-13 08:52:03.113117 7f184e9f9e40 4 rocksdb: IDENTITY file: IDENTITY

2018-02-13 08:52:03.113122 7f184e9f9e40 4 rocksdb: MANIFEST file: MANIFEST-000101 size: 214 Bytes

2018-02-13 08:52:03.113126 7f184e9f9e40 4 rocksdb: SST files in /var/lib/ceph/mon/ceph-smp-016/store.db dir, Total Num: 3, files: 000081.sst 000097.sst 000100.sst

2018-02-13 08:52:03.113128 7f184e9f9e40 4 rocksdb: Write Ahead Log file in /var/lib/ceph/mon/ceph-smp-016/store.db: 000102.log size: 18056 ;

2018-02-13 08:52:03.113131 7f184e9f9e40 4 rocksdb: Options.error_if_exists: 0
2018-02-13 08:52:03.113132 7f184e9f9e40 4 rocksdb: Options.create_if_missing: 0
2018-02-13 08:52:03.113133 7f184e9f9e40 4 rocksdb: Options.paranoid_checks: 1
2018-02-13 08:52:03.113134 7f184e9f9e40 4 rocksdb: Options.env: 0x5565f834f040
2018-02-13 08:52:03.113136 7f184e9f9e40 4 rocksdb: Options.info_log: 0x5565f98abc80
2018-02-13 08:52:03.113137 7f184e9f9e40 4 rocksdb: Options.max_open_files: -1
2018-02-13 08:52:03.113138 7f184e9f9e40 4 rocksdb: Options.max_file_opening_threads: 16
2018-02-13 08:52:03.113139 7f184e9f9e40 4 rocksdb: Options.use_fsync: 0
2018-02-13 08:52:03.113139 7f184e9f9e40 4 rocksdb: Options.max_log_file_size: 0
2018-02-13 08:52:03.113140 7f184e9f9e40 4 rocksdb: Options.max_manifest_file_size: 18446744073709551615
2018-02-13 08:52:03.113141 7f184e9f9e40 4 rocksdb: Options.log_file_time_to_roll: 0
2018-02-13 08:52:03.113142 7f184e9f9e40 4 rocksdb: Options.keep_log_file_num: 1000
2018-02-13 08:52:03.113143 7f184e9f9e40 4 rocksdb: Options.recycle_log_file_num: 0
2018-02-13 08:52:03.113144 7f184e9f9e40 4 rocksdb: Options.allow_fallocate: 1
2018-02-13 08:52:03.113145 7f184e9f9e40 4 rocksdb: Options.allow_mmap_reads: 0
2018-02-13 08:52:03.113146 7f184e9f9e40 4 rocksdb: Options.allow_mmap_writes: 0
2018-02-13 08:52:03.113147 7f184e9f9e40 4 rocksdb: Options.use_direct_reads: 0
2018-02-13 08:52:03.113149 7f184e9f9e40 4 rocksdb: Options.use_direct_io_for_flush_and_compaction: 0
2018-02-13 08:52:03.113150 7f184e9f9e40 4 rocksdb: Options.create_missing_column_families: 0
2018-02-13 08:52:03.113151 7f184e9f9e40 4 rocksdb: Options.db_log_dir:
2018-02-13 08:52:03.113152 7f184e9f9e40 4 rocksdb: Options.wal_dir: /var/lib/ceph/mon/ceph-smp-016/store.db
2018-02-13 08:52:03.113153 7f184e9f9e40 4 rocksdb: Options.table_cache_numshardbits: 6
2018-02-13 08:52:03.113154 7f184e9f9e40 4 rocksdb: Options.max_subcompactions: 1
2018-02-13 08:52:03.113155 7f184e9f9e40 4 rocksdb: Options.max_background_flushes: 1
2018-02-13 08:52:03.113155 7f184e9f9e40 4 rocksdb: Options.WAL_ttl_seconds: 0
2018-02-13 08:52:03.113156 7f184e9f9e40 4 rocksdb: Options.WAL_size_limit_MB: 0
2018-02-13 08:52:03.113157 7f184e9f9e40 4 rocksdb: Options.manifest_preallocation_size: 4194304
2018-02-13 08:52:03.113158 7f184e9f9e40 4 rocksdb: Options.is_fd_close_on_exec: 1
2018-02-13 08:52:03.113159 7f184e9f9e40 4 rocksdb: Options.advise_random_on_open: 1
2018-02-13 08:52:03.113160 7f184e9f9e40 4 rocksdb: Options.db_write_buffer_size: 0
2018-02-13 08:52:03.113161 7f184e9f9e40 4 rocksdb: Options.access_hint_on_compaction_start: 1
2018-02-13 08:52:03.113162 7f184e9f9e40 4 rocksdb: Options.new_table_reader_for_compaction_inputs: 0
2018-02-13 08:52:03.113162 7f184e9f9e40 4 rocksdb: Options.compaction_readahead_size: 0
2018-02-13 08:52:03.113163 7f184e9f9e40 4 rocksdb: Options.random_access_max_buffer_size: 1048576
2018-02-13 08:52:03.113164 7f184e9f9e40 4 rocksdb: Options.writable_file_max_buffer_size: 1048576
2018-02-13 08:52:03.113165 7f184e9f9e40 4 rocksdb: Options.use_adaptive_mutex: 0
2018-02-13 08:52:03.113165 7f184e9f9e40 4 rocksdb: Options.rate_limiter: (nil)
2018-02-13 08:52:03.113167 7f184e9f9e40 4 rocksdb: Options.sst_file_manager.rate_bytes_per_sec: 0
2018-02-13 08:52:03.113167 7f184e9f9e40 4 rocksdb: Options.bytes_per_sync: 0
2018-02-13 08:52:03.113168 7f184e9f9e40 4 rocksdb: Options.wal_bytes_per_sync: 0
2018-02-13 08:52:03.113169 7f184e9f9e40 4 rocksdb: Options.wal_recovery_mode: 2
2018-02-13 08:52:03.113170 7f184e9f9e40 4 rocksdb: Options.enable_thread_tracking: 0
2018-02-13 08:52:03.113171 7f184e9f9e40 4 rocksdb: Options.allow_concurrent_memtable_write: 1
2018-02-13 08:52:03.113172 7f184e9f9e40 4 rocksdb: Options.enable_write_thread_adaptive_yield: 1
2018-02-13 08:52:03.113172 7f184e9f9e40 4 rocksdb: Options.write_thread_max_yield_usec: 100
2018-02-13 08:52:03.113173 7f184e9f9e40 4 rocksdb: Options.write_thread_slow_yield_usec: 3
2018-02-13 08:52:03.113174 7f184e9f9e40 4 rocksdb: Options.row_cache: None
2018-02-13 08:52:03.113175 7f184e9f9e40 4 rocksdb: Options.wal_filter: None
2018-02-13 08:52:03.113176 7f184e9f9e40 4 rocksdb: Options.avoid_flush_during_recovery: 0
2018-02-13 08:52:03.113177 7f184e9f9e40 4 rocksdb: Options.base_background_compactions: 1
2018-02-13 08:52:03.113177 7f184e9f9e40 4 rocksdb: Options.max_background_compactions: 1
2018-02-13 08:52:03.113178 7f184e9f9e40 4 rocksdb: Options.avoid_flush_during_shutdown: 0
2018-02-13 08:52:03.113179 7f184e9f9e40 4 rocksdb: Options.delayed_write_rate : 16777216
2018-02-13 08:52:03.113180 7f184e9f9e40 4 rocksdb: Options.max_total_wal_size: 0
2018-02-13 08:52:03.113181 7f184e9f9e40 4 rocksdb: Options.delete_obsolete_files_period_micros: 21600000000
2018-02-13 08:52:03.113182 7f184e9f9e40 4 rocksdb: Options.stats_dump_period_sec: 600
2018-02-13 08:52:03.113183 7f184e9f9e40 4 rocksdb: Compression algorithms supported:
2018-02-13 08:52:03.113187 7f184e9f9e40 4 rocksdb: Snappy supported: 0
2018-02-13 08:52:03.113199 7f184e9f9e40 4 rocksdb: Zlib supported: 0
2018-02-13 08:52:03.113200 7f184e9f9e40 4 rocksdb: Bzip supported: 0
2018-02-13 08:52:03.113201 7f184e9f9e40 4 rocksdb: LZ4 supported: 0
2018-02-13 08:52:03.113202 7f184e9f9e40 4 rocksdb: ZSTD supported: 0
2018-02-13 08:52:03.113204 7f184e9f9e40 4 rocksdb: Fast CRC32 supported: 0
2018-02-13 08:52:03.113510 7f184e9f9e40 4 rocksdb: [/builddir/build/BUILD/ceph-12.2.2/src/rocksdb/db/version_set.cc:2609] Recovering from manifest file: MANIFEST-000101

2018-02-13 08:52:03.113648 7f184e9f9e40 4 rocksdb: [/builddir/build/BUILD/ceph-12.2.2/src/rocksdb/db/column_family.cc:407] --------------- Options for column family [default]:

2018-02-13 08:52:03.113657 7f184e9f9e40 4 rocksdb: Options.comparator: leveldb.BytewiseComparator
2018-02-13 08:52:03.113659 7f184e9f9e40 4 rocksdb: Options.merge_operator:
2018-02-13 08:52:03.113660 7f184e9f9e40 4 rocksdb: Options.compaction_filter: None
2018-02-13 08:52:03.113661 7f184e9f9e40 4 rocksdb: Options.compaction_filter_factory: None
2018-02-13 08:52:03.113662 7f184e9f9e40 4 rocksdb: Options.memtable_factory: SkipListFactory
2018-02-13 08:52:03.113662 7f184e9f9e40 4 rocksdb: Options.table_factory: BlockBasedTable
2018-02-13 08:52:03.113684 7f184e9f9e40 4 rocksdb: table_factory options: flush_block_policy_factory: FlushBlockBySizePolicyFactory (0x5565f95de158)
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: 0x5565f96009a8
block_cache_name: LRUCache
block_cache_options:
capacity : 134217728
num_shard_bits : 4
strict_capacity_limit : 0
high_pri_pool_ratio: 0.000
block_cache_compressed: (nil)
persistent_cache: (nil)
block_size: 4096
block_size_deviation: 10
block_restart_interval: 16
index_block_restart_interval: 1
filter_policy: rocksdb.BuiltinBloomFilter
whole_key_filtering: 1
format_version: 2

2018-02-13 08:52:03.113712 7f184e9f9e40 4 rocksdb: Options.write_buffer_size: 33554432
2018-02-13 08:52:03.113716 7f184e9f9e40 4 rocksdb: Options.max_write_buffer_number: 2
2018-02-13 08:52:03.113718 7f184e9f9e40 4 rocksdb: Options.compression: NoCompression
2018-02-13 08:52:03.113720 7f184e9f9e40 4 rocksdb: Options.bottommost_compression: Disabled
2018-02-13 08:52:03.113721 7f184e9f9e40 4 rocksdb: Options.prefix_extractor: nullptr
2018-02-13 08:52:03.113722 7f184e9f9e40 4 rocksdb: Options.memtable_insert_with_hint_prefix_extractor: nullptr
2018-02-13 08:52:03.113723 7f184e9f9e40 4 rocksdb: Options.num_levels: 7
2018-02-13 08:52:03.113724 7f184e9f9e40 4 rocksdb: Options.min_write_buffer_number_to_merge: 1
2018-02-13 08:52:03.113725 7f184e9f9e40 4 rocksdb: Options.max_write_buffer_number_to_maintain: 0
2018-02-13 08:52:03.113726 7f184e9f9e40 4 rocksdb: Options.compression_opts.window_bits: -14
2018-02-13 08:52:03.113727 7f184e9f9e40 4 rocksdb: Options.compression_opts.level: -1
2018-02-13 08:52:03.113728 7f184e9f9e40 4 rocksdb: Options.compression_opts.strategy: 0
2018-02-13 08:52:03.113728 7f184e9f9e40 4 rocksdb: Options.compression_opts.max_dict_bytes: 0
2018-02-13 08:52:03.113729 7f184e9f9e40 4 rocksdb: Options.level0_file_num_compaction_trigger: 4
2018-02-13 08:52:03.113730 7f184e9f9e40 4 rocksdb: Options.level0_slowdown_writes_trigger: 20
2018-02-13 08:52:03.113731 7f184e9f9e40 4 rocksdb: Options.level0_stop_writes_trigger: 36
2018-02-13 08:52:03.113732 7f184e9f9e40 4 rocksdb: Options.target_file_size_base: 67108864
2018-02-13 08:52:03.113733 7f184e9f9e40 4 rocksdb: Options.target_file_size_multiplier: 1
2018-02-13 08:52:03.113733 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_base: 268435456
2018-02-13 08:52:03.113734 7f184e9f9e40 4 rocksdb: Options.level_compaction_dynamic_level_bytes: 0
2018-02-13 08:52:03.113735 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_multiplier: 10.000000
2018-02-13 08:52:03.113741 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[0]: 1
2018-02-13 08:52:03.113742 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[1]: 1
2018-02-13 08:52:03.113744 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[2]: 1
2018-02-13 08:52:03.113745 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[3]: 1
2018-02-13 08:52:03.113746 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[4]: 1
2018-02-13 08:52:03.113747 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[5]: 1
2018-02-13 08:52:03.113748 7f184e9f9e40 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[6]: 1
2018-02-13 08:52:03.113750 7f184e9f9e40 4 rocksdb: Options.max_sequential_skip_in_iterations: 8
2018-02-13 08:52:03.113751 7f184e9f9e40 4 rocksdb: Options.max_compaction_bytes: 1677721600
2018-02-13 08:52:03.113752 7f184e9f9e40 4 rocksdb: Options.arena_block_size: 4194304
2018-02-13 08:52:03.113762 7f184e9f9e40 4 rocksdb: Options.soft_pending_compaction_bytes_limit: 68719476736
2018-02-13 08:52:03.113763 7f184e9f9e40 4 rocksdb: Options.hard_pending_compaction_bytes_limit: 274877906944
2018-02-13 08:52:03.113764 7f184e9f9e40 4 rocksdb: Options.rate_limit_delay_max_milliseconds: 100
2018-02-13 08:52:03.113765 7f184e9f9e40 4 rocksdb: Options.disable_auto_compactions: 0
2018-02-13 08:52:03.113766 7f184e9f9e40 4 rocksdb: Options.compaction_style: kCompactionStyleLevel
2018-02-13 08:52:03.113767 7f184e9f9e40 4 rocksdb: Options.compaction_pri: kByCompensatedSize
2018-02-13 08:52:03.113768 7f184e9f9e40 4 rocksdb: Options.compaction_options_universal.size_ratio: 1
2018-02-13 08:52:03.113769 7f184e9f9e40 4 rocksdb: Options.compaction_options_universal.min_merge_width: 2
2018-02-13 08:52:03.113770 7f184e9f9e40 4 rocksdb: Options.compaction_options_universal.max_merge_width: 4294967295
2018-02-13 08:52:03.113771 7f184e9f9e40 4 rocksdb: Options.compaction_options_universal.max_size_amplification_percent: 200
2018-02-13 08:52:03.113772 7f184e9f9e40 4 rocksdb: Options.compaction_options_universal.compression_size_percent: -1
2018-02-13 08:52:03.113773 7f184e9f9e40 4 rocksdb: Options.compaction_options_fifo.max_table_files_size: 1073741824
2018-02-13 08:52:03.113774 7f184e9f9e40 4 rocksdb: Options.table_properties_collectors:
2018-02-13 08:52:03.113775 7f184e9f9e40 4 rocksdb: Options.inplace_update_support: 0
2018-02-13 08:52:03.113775 7f184e9f9e40 4 rocksdb: Options.inplace_update_num_locks: 10000
2018-02-13 08:52:03.113776 7f184e9f9e40 4 rocksdb: Options.memtable_prefix_bloom_size_ratio: 0.000000
2018-02-13 08:52:03.113778 7f184e9f9e40 4 rocksdb: Options.memtable_huge_page_size: 0
2018-02-13 08:52:03.113779 7f184e9f9e40 4 rocksdb: Options.bloom_locality: 0
2018-02-13 08:52:03.113793 7f184e9f9e40 4 rocksdb: Options.max_successive_merges: 0
2018-02-13 08:52:03.113794 7f184e9f9e40 4 rocksdb: Options.optimize_filters_for_hits: 0
2018-02-13 08:52:03.113795 7f184e9f9e40 4 rocksdb: Options.paranoid_file_checks: 0
2018-02-13 08:52:03.113796 7f184e9f9e40 4 rocksdb: Options.force_consistency_checks: 0
2018-02-13 08:52:03.113796 7f184e9f9e40 4 rocksdb: Options.report_bg_io_stats: 0
2018-02-13 08:52:03.114800 7f184e9f9e40 4 rocksdb: [/builddir/build/BUILD/ceph-12.2.2/src/rocksdb/db/version_set.cc:2859] Recovered from manifest file:/var/lib/ceph/mon/ceph-smp-016/store.db/MANIFEST-000101 succeeded,manifest_file_number is 101, next_file_number is 103, last_sequence is 1427, log_number is 0,prev_log_number is 0,max_column_family is 0

2018-02-13 08:52:03.114810 7f184e9f9e40 4 rocksdb: [/builddir/build/BUILD/ceph-12.2.2/src/rocksdb/db/version_set.cc:2867] Column family [default] (ID 0), log number is 100

2018-02-13 08:52:03.114894 7f184e9f9e40 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1518508323114872, "job": 1, "event": "recovery_started", "log_files": [102]}
2018-02-13 08:52:03.114904 7f184e9f9e40 4 rocksdb: [/builddir/build/BUILD/ceph-12.2.2/src/rocksdb/db/db_impl_open.cc:482] Recovering log #102 mode 2
2018-02-13 08:52:03.133814 7f184e9f9e40 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1518508323133795, "cf_name": "default", "job": 1, "event": "table_file_creation", "file_number": 103, "file_size": 19004, "table_properties": {"data_size": 17923, "index_size": 87, "filter_size": 80, "raw_key_size": 330, "raw_average_key_size": 23, "raw_value_size": 17559, "raw_average_value_size": 1254, "num_data_blocks": 3, "num_entries": 14, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
2018-02-13 08:52:03.134044 7f184e9f9e40 4 rocksdb: [/builddir/build/BUILD/ceph-12.2.2/src/rocksdb/db/version_set.cc:2395] Creating manifest 104

2018-02-13 08:52:03.142897 7f184e9f9e40 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1518508323142892, "job": 1, "event": "recovery_finished"}
2018-02-13 08:52:03.155840 7f184e9f9e40 4 rocksdb: [/builddir/build/BUILD/ceph-12.2.2/src/rocksdb/db/db_impl_open.cc:1063] DB pointer 0x5565f99a2000
2018-02-13 08:52:03.157072 7f184e9f9e40 1 RDMAStack RDMAStack ms_async_rdma_enable_hugepage value is: 0
2018-02-13 08:52:03.157096 7f184e9f9e40 20 RDMAStack RDMAStack constructing RDMAStack...
2018-02-13 08:52:03.157126 7f184e9f9e40 20 RDMAStack creating RDMAStack:0x5565f99b4318 with dispatcher:0x5565f962a480
2018-02-13 08:52:03.157208 7f1840fac700 2 Event(0x5565f966ad00 nevent=5000 time_id=1).set_owner idx=0 owner=139742146119424
2018-02-13 08:52:03.157225 7f18417ad700 2 Event(0x5565f966b200 nevent=5000 time_id=1).set_owner idx=1 owner=139742154512128
2018-02-13 08:52:03.157234 7f1840fac700 20 Event(0x5565f966ad00 nevent=5000 time_id=1).create_file_event create event started fd=16 mask=1 original mask is 0
2018-02-13 08:52:03.157239 7f1840fac700 20 EpollDriver.add_event add event fd=16 cur_mask=0 add_mask=1 to 15
2018-02-13 08:52:03.157242 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event started fd=19 mask=1 original mask is 0
2018-02-13 08:52:03.157238 7f1841fae700 2 Event(0x5565f966b700 nevent=5000 time_id=1).set_owner idx=2 owner=139742162904832
2018-02-13 08:52:03.157246 7f18417ad700 20 EpollDriver.add_event add event fd=19 cur_mask=0 add_mask=1 to 18
2018-02-13 08:52:03.157248 7f1840fac700 20 Event(0x5565f966ad00 nevent=5000 time_id=1).create_file_event create event end fd=16 mask=1 original mask is 1
2018-02-13 08:52:03.157250 7f1840fac700 10 stack operator() starting
2018-02-13 08:52:03.157250 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event started fd=22 mask=1 original mask is 0
2018-02-13 08:52:03.157252 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event end fd=19 mask=1 original mask is 1
2018-02-13 08:52:03.157254 7f1841fae700 20 EpollDriver.add_event add event fd=22 cur_mask=0 add_mask=1 to 21
2018-02-13 08:52:03.157254 7f18417ad700 10 stack operator() starting
2018-02-13 08:52:03.157258 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event end fd=22 mask=1 original mask is 1
2018-02-13 08:52:03.157262 7f1841fae700 10 stack operator() starting
2018-02-13 08:52:03.157342 7f184e9f9e40 0 starting mon.smp-016 rank 0 at public addr 192.168.4.96:6789/0 at bind addr 192.168.4.96:6789/0 mon_data /var/lib/ceph/mon/ceph-smp-016 fsid 6de5466c-d11f-4e59-857b-b11cb0bc4d9b
2018-02-13 08:52:03.157381 7f184e9f9e40 10 -- - bind bind 192.168.4.96:6789/0
2018-02-13 08:52:03.157389 7f184e9f9e40 10 -- - bind Network Stack is not ready for bind yet - postponed
2018-02-13 08:52:03.157433 7f184e9f9e40 0 starting mon.smp-016 rank 0 at 192.168.4.96:6789/0 mon_data /var/lib/ceph/mon/ceph-smp-016 fsid 6de5466c-d11f-4e59-857b-b11cb0bc4d9b
2018-02-13 08:52:03.158216 7f184e9f9e40 1 mon.smp-016@-1(probing) e1 preinit fsid 6de5466c-d11f-4e59-857b-b11cb0bc4d9b
2018-02-13 08:52:03.159023 7f184e9f9e40 1 mon.smp-016@-1(probing).mds e0 Unable to load 'last_metadata'
2018-02-13 08:52:03.159151 7f184e9f9e40 1 mon.smp-016@-1(probing).paxosservice(pgmap 1..2) refresh upgraded, format 0 -> 1
2018-02-13 08:52:03.159162 7f184e9f9e40 1 mon.smp-016@-1(probing).pg v0 on_upgrade discarding in-core PGMap
2018-02-13 08:52:03.159379 7f184e9f9e40 0 mon.smp-016@-1(probing).mds e1 print_map
e1
enable_multiple, ever_enabled_multiple: 0,0
compat: compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object,5=mds uses versioned encoding,6=dirfrag is stored in omap,8=file layout v2}
legacy client fscid: -1
No filesystems configured

2018-02-13 08:52:03.159612 7f184e9f9e40 0 mon.smp-016@-1(probing).osd e1 crush map has features 288514050185494528, adjusting msgr requires
2018-02-13 08:52:03.159621 7f184e9f9e40 0 mon.smp-016@-1(probing).osd e1 crush map has features 288514050185494528, adjusting msgr requires
2018-02-13 08:52:03.159629 7f184e9f9e40 0 mon.smp-016@-1(probing).osd e1 crush map has features 1009089990564790272, adjusting msgr requires
2018-02-13 08:52:03.159632 7f184e9f9e40 0 mon.smp-016@-1(probing).osd e1 crush map has features 288514050185494528, adjusting msgr requires
2018-02-13 08:52:03.160162 7f184e9f9e40 1 mon.smp-016@-1(probing).paxosservice(auth 1..157) refresh upgraded, format 0 -> 2
2018-02-13 08:52:03.164059 7f184e9f9e40 1 -- - start start
2018-02-13 08:52:03.164063 7f184e9f9e40 1 -- - start start
2018-02-13 08:52:03.164227 7f184e9f9e40 10 -- - ready -
2018-02-13 08:52:03.164232 7f184e9f9e40 10 -- - bind bind 192.168.4.96:6789/0
2018-02-13 08:52:03.164239 7f184e9f9e40 10 Processor -- bind
2018-02-13 08:52:03.164243 7f184e9f9e40 20 Event(0x5565f966ad00 nevent=5000 time_id=1).wakeup
2018-02-13 08:52:03.165805 7f1840fac700 1 Infiniband binding_port found active port 1
2018-02-13 08:52:03.165823 7f1840fac700 1 Infiniband init assigning: 1024 receive buffers
2018-02-13 08:52:03.165825 7f1840fac700 1 Infiniband init assigning: 1024 send buffers
2018-02-13 08:52:03.165828 7f1840fac700 1 Infiniband init device allow 4194303 completion entries
2018-02-13 08:52:03.229871 7f1840fac700 20 Infiniband init started.
2018-02-13 08:52:03.229910 7f1840fac700 20 Infiniband init started.
2018-02-13 08:52:03.231678 7f1840fac700 20 Infiniband init successfully create cq=0x5565f962a900
2018-02-13 08:52:03.233339 7f1840fac700 20 Infiniband init successfully create cq=0x5565f962aa80
2018-02-13 08:52:03.233471 7f1844d8f700 20 RDMAStack polling going to poll tx cq: 0x5565f99eb7d0 rx cq: 0x5565f99eb800
2018-02-13 08:52:03.233503 7f1844d8f700 20 Infiniband rearm_notify started.
2018-02-13 08:52:03.233505 7f1844d8f700 20 Infiniband rearm_notify started.
2018-02-13 08:52:03.234069 7f1840fac700 20 RDMAServerSocketImpl listen bind to 192.168.4.96:6789 on port 6789
2018-02-13 08:52:03.234167 7f184e9f9e40 10 Processor -- bind bound to 192.168.4.96:6789/0
2018-02-13 08:52:03.234185 7f184e9f9e40 1 -- 192.168.4.96:6789/0 learned_addr learned my addr 192.168.4.96:6789/0
2018-02-13 08:52:03.234190 7f184e9f9e40 1 -- 192.168.4.96:6789/0 _finish_bind bind my_inst.addr is 192.168.4.96:6789/0
2018-02-13 08:52:03.234197 7f184e9f9e40 1 Processor -- start
2018-02-13 08:52:03.234199 7f184e9f9e40 20 Event(0x5565f966ad00 nevent=5000 time_id=1).wakeup
2018-02-13 08:52:03.234217 7f1840fac700 20 Event(0x5565f966ad00 nevent=5000 time_id=1).create_file_event create event started fd=28 mask=1 original mask is 0
2018-02-13 08:52:03.234223 7f1840fac700 20 EpollDriver.add_event add event fd=28 cur_mask=0 add_mask=1 to 15
2018-02-13 08:52:03.234229 7f1840fac700 20 Event(0x5565f966ad00 nevent=5000 time_id=1).create_file_event create event end fd=28 mask=1 original mask is 1
2018-02-13 08:52:03.234333 7f184e9f9e40 10 -- - ready -
2018-02-13 08:52:03.234339 7f184e9f9e40 1 Processor -- start
2018-02-13 08:52:03.234385 7f184e9f9e40 0 mon.smp-016@-1(probing) e1 my rank is now 0 (was -1)
2018-02-13 08:52:03.234393 7f184e9f9e40 1 -- 192.168.4.96:6789/0 shutdown_connections
2018-02-13 08:52:03.234431 7f184e9f9e40 1 mon.smp-016@0(probing) e1 win_standalone_election
2018-02-13 08:52:03.234465 7f184e9f9e40 1 mon.smp-016@0(probing).elector(37) init, last seen epoch 37, mid-election, bumping
2018-02-13 08:52:03.243410 7f184e9f9e40 0 log_channel(cluster) log [INF] : mon.smp-016@0 won leader election with quorum 0
2018-02-13 08:52:03.243498 7f184e9f9e40 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(1 entries from seq 1 at 2018-02-13 08:52:03.243423) v1 -- 0x5565f95e81c0 con 0
2018-02-13 08:52:03.243509 7f184e9f9e40 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(1 entries from seq 1 at 2018-02-13 08:52:03.243423) v1 local
2018-02-13 08:52:03.243560 7f184e9f9e40 0 log_channel(cluster) log [INF] : monmap e1: 1 mons at {smp-016=192.168.4.96:6789/0}
2018-02-13 08:52:03.243580 7f184e9f9e40 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(1 entries from seq 2 at 2018-02-13 08:52:03.243565) v1 -- 0x5565f95e8400 con 0
2018-02-13 08:52:03.243576 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f95e81c0 prio 196
2018-02-13 08:52:03.243589 7f184e9f9e40 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(1 entries from seq 2 at 2018-02-13 08:52:03.243565) v1 local
2018-02-13 08:52:03.243608 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f95e8400 prio 196
2018-02-13 08:52:03.243638 7f184e9f9e40 0 log_channel(cluster) log [DBG] : fsmap
2018-02-13 08:52:03.243661 7f184e9f9e40 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(1 entries from seq 3 at 2018-02-13 08:52:03.243643) v1 -- 0x5565f95e8640 con 0
2018-02-13 08:52:03.243672 7f184e9f9e40 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(1 entries from seq 3 at 2018-02-13 08:52:03.243643) v1 local
2018-02-13 08:52:03.243689 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f95e8640 prio 196
2018-02-13 08:52:03.243668 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(1 entries from seq 1 at 2018-02-13 08:52:03.243423) v1 ==== 0+0+0 (0 0 0) 0x5565f95e81c0 con 0x5565f9eb8000
2018-02-13 08:52:03.243743 7f184e9f9e40 0 log_channel(cluster) log [DBG] : osdmap e1: 0 total, 0 up, 0 in
2018-02-13 08:52:03.243775 7f184e9f9e40 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(1 entries from seq 4 at 2018-02-13 08:52:03.243748) v1 -- 0x5565f95e8880 con 0
2018-02-13 08:52:03.243784 7f184e9f9e40 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(1 entries from seq 4 at 2018-02-13 08:52:03.243748) v1 local
2018-02-13 08:52:03.243801 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f95e8880 prio 196
2018-02-13 08:52:03.243837 7f184e9f9e40 0 log_channel(cluster) log [DBG] : mgrmap e1: no daemons active
2018-02-13 08:52:03.243858 7f184e9f9e40 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(1 entries from seq 5 at 2018-02-13 08:52:03.243842) v1 -- 0x5565f95e8ac0 con 0
2018-02-13 08:52:03.243867 7f184e9f9e40 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(1 entries from seq 5 at 2018-02-13 08:52:03.243842) v1 local
2018-02-13 08:52:03.243881 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f95e8ac0 prio 196
2018-02-13 08:52:03.244177 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f95e81c0
2018-02-13 08:52:03.244193 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(1 entries from seq 2 at 2018-02-13 08:52:03.243565) v1 ==== 0+0+0 (0 0 0) 0x5565f95e8400 con 0x5565f9eb8000
2018-02-13 08:52:03.244235 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f95e8400
2018-02-13 08:52:03.244245 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(1 entries from seq 3 at 2018-02-13 08:52:03.243643) v1 ==== 0+0+0 (0 0 0) 0x5565f95e8640 con 0x5565f9eb8000
2018-02-13 08:52:03.244280 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f95e8640
2018-02-13 08:52:03.244289 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(1 entries from seq 4 at 2018-02-13 08:52:03.243748) v1 ==== 0+0+0 (0 0 0) 0x5565f95e8880 con 0x5565f9eb8000
2018-02-13 08:52:03.244337 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f95e8880
2018-02-13 08:52:03.244350 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(1 entries from seq 5 at 2018-02-13 08:52:03.243842) v1 ==== 0+0+0 (0 0 0) 0x5565f95e8ac0 con 0x5565f9eb8000
2018-02-13 08:52:03.244390 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f95e8ac0
2018-02-13 08:52:03.304374 7f18407ab700 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(last 1) v1 -- 0x5565f9a80b20 con 0
2018-02-13 08:52:03.304391 7f18407ab700 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(last 1) v1 local
2018-02-13 08:52:03.304435 7f18407ab700 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(last 2) v1 -- 0x5565f9a7ffe0 con 0
2018-02-13 08:52:03.304472 7f18407ab700 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(last 2) v1 local
2018-02-13 08:52:03.304478 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f9a80b20 prio 196
2018-02-13 08:52:03.304515 7f18407ab700 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(last 3) v1 -- 0x5565f9a801c0 con 0
2018-02-13 08:52:03.304532 7f18407ab700 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(last 3) v1 local
2018-02-13 08:52:03.304535 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f9a7ffe0 prio 196
2018-02-13 08:52:03.304543 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f9a801c0 prio 196
2018-02-13 08:52:03.304550 7f18407ab700 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(last 4) v1 -- 0x5565f9a803a0 con 0
2018-02-13 08:52:03.304555 7f18407ab700 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(last 4) v1 local
2018-02-13 08:52:03.304577 7f18407ab700 1 -- 192.168.4.96:6789/0 --> 192.168.4.96:6789/0 -- log(last 5) v1 -- 0x5565f9a7e1e0 con 0
2018-02-13 08:52:03.304580 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f9a803a0 prio 196
2018-02-13 08:52:03.304584 7f18407ab700 20 -- 192.168.4.96:6789/0 >> 192.168.4.96:6789/0 conn(0x5565f9eb8000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).send_message log(last 5) v1 local
2018-02-13 08:52:03.304578 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(last 1) v1 ==== 0+0+0 (0 0 0) 0x5565f9a80b20 con 0x5565f9eb8000
2018-02-13 08:52:03.304597 7f1843d8d700 20 -- 192.168.4.96:6789/0 queue 0x5565f9a7e1e0 prio 196
2018-02-13 08:52:03.304643 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f9a80b20
2018-02-13 08:52:03.304654 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(last 2) v1 ==== 0+0+0 (0 0 0) 0x5565f9a7ffe0 con 0x5565f9eb8000
2018-02-13 08:52:03.304681 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f9a7ffe0
2018-02-13 08:52:03.304689 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(last 3) v1 ==== 0+0+0 (0 0 0) 0x5565f9a801c0 con 0x5565f9eb8000
2018-02-13 08:52:03.304715 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f9a801c0
2018-02-13 08:52:03.304736 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(last 4) v1 ==== 0+0+0 (0 0 0) 0x5565f9a803a0 con 0x5565f9eb8000
2018-02-13 08:52:03.304770 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f9a803a0
2018-02-13 08:52:03.304781 7f184458e700 1 -- 192.168.4.96:6789/0 <== mon.0 192.168.4.96:6789/0 0 ==== log(last 5) v1 ==== 0+0+0 (0 0 0) 0x5565f9a7e1e0 con 0x5565f9eb8000
2018-02-13 08:52:03.304818 7f184458e700 20 -- 192.168.4.96:6789/0 done calling dispatch on 0x5565f9a7e1e0
2018-02-13 08:52:17.255580 7f1840fac700 10 Processor -- accept listen_fd=28
2018-02-13 08:52:17.255613 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:17.255652 7f1840fac700 20 Infiniband init started.
2018-02-13 08:52:17.255775 7f1840fac700 20 Infiniband init successfully create queue pair: qp=0x5565f966ca80
2018-02-13 08:52:17.256206 7f1840fac700 20 Infiniband init successfully change queue pair to INIT: qp=0x5565f966ca80
2018-02-13 08:52:17.256229 7f1840fac700 20 Event(0x5565f966b700 nevent=5000 time_id=1).wakeup
2018-02-13 08:52:17.256241 7f1840fac700 20 RDMAServerSocketImpl accept accepted a new QP, tcp_fd: 37
2018-02-13 08:52:17.256244 7f1840fac700 10 Processor -- accept accepted incoming on sd 38
2018-02-13 08:52:17.256283 7f1840fac700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aac000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).accept sd=38
2018-02-13 08:52:17.256296 7f1840fac700 20 Event(0x5565f966b700 nevent=5000 time_id=1).wakeup
2018-02-13 08:52:17.256291 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event started fd=37 mask=1 original mask is 0
2018-02-13 08:52:17.256300 7f1841fae700 20 EpollDriver.add_event add event fd=37 cur_mask=0 add_mask=1 to 21
2018-02-13 08:52:17.256301 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:17.256306 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event end fd=37 mask=1 original mask is 1
2018-02-13 08:52:17.256320 7f1841fae700 20 RDMAConnectedSocketImpl handle_connection QP: 262718 tcp_fd: 37 notify_fd: 38
2018-02-13 08:52:17.256342 7f1841fae700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ???A
2018-02-13 08:52:17.256351 7f1841fae700 10 Infiniband send_msg sending: 79, 262718, 0, 0, fe80000000000000f45214030035f771
2018-02-13 08:52:17.256394 7f1841fae700 20 RDMAConnectedSocketImpl activate Choosing gid_index 67, sl 3
2018-02-13 08:52:17.256456 7f1841fae700 20 RDMAConnectedSocketImpl activate transition to RTR state successfully.
2018-02-13 08:52:17.256513 7f1841fae700 20 RDMAConnectedSocketImpl activate transition to RTS state successfully.
2018-02-13 08:52:17.256517 7f1841fae700 20 RDMAConnectedSocketImpl activate QueuePair: 0x5565f9ec3030 with qp:0x5565f966ca80
2018-02-13 08:52:17.256525 7f1841fae700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aac000 :-1 s=STATE_ACCEPTING pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:17.256555 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event started fd=38 mask=1 original mask is 0
2018-02-13 08:52:17.256559 7f1841fae700 20 EpollDriver.add_event add event fd=38 cur_mask=0 add_mask=1 to 21
2018-02-13 08:52:17.256562 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event end fd=38 mask=1 original mask is 1
2018-02-13 08:52:17.256572 7f1841fae700 1 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aac000 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=38 -
2018-02-13 08:52:17.256581 7f1841fae700 20 RDMAConnectedSocketImpl send fake send to upper, QP: 262718
2018-02-13 08:52:17.256583 7f1841fae700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aac000 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._try_send sent bytes 281 remaining bytes 0
2018-02-13 08:52:17.256590 7f1841fae700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aac000 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection write banner and addr done: -
2018-02-13 08:52:17.256611 7f1841fae700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aac000 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:17.256620 7f1841fae700 20 RDMAConnectedSocketImpl read notify_fd : 0 in 262718 r = -1
2018-02-13 08:52:17.256628 7f1841fae700 20 RDMAConnectedSocketImpl handle_connection QP: 262718 tcp_fd: 37 notify_fd: 38
2018-02-13 08:52:17.256637 7f1841fae700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ???A
2018-02-13 08:52:17.256641 7f1841fae700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:21.498567 7f1841fae700 20 RDMAConnectedSocketImpl handle_connection QP: 262718 tcp_fd: 37 notify_fd: 38
2018-02-13 08:52:21.498596 7f1841fae700 10 Infiniband recv_msg got disconnect message
2018-02-13 08:52:21.498599 7f1841fae700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:21.699958 7f1840fac700 10 Processor -- accept listen_fd=28
2018-02-13 08:52:21.699980 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:21.700009 7f1840fac700 20 Infiniband init started.
2018-02-13 08:52:21.700179 7f1840fac700 20 Infiniband init successfully create queue pair: qp=0x5565f966cd00
2018-02-13 08:52:21.700843 7f1840fac700 20 Infiniband init successfully change queue pair to INIT: qp=0x5565f966cd00
2018-02-13 08:52:21.700863 7f1840fac700 20 Event(0x5565f966b200 nevent=5000 time_id=1).wakeup
2018-02-13 08:52:21.700879 7f1840fac700 20 RDMAServerSocketImpl accept accepted a new QP, tcp_fd: 39
2018-02-13 08:52:21.700883 7f1840fac700 10 Processor -- accept accepted incoming on sd 40
2018-02-13 08:52:21.700903 7f1840fac700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aad800 :-1 s=STATE_NONE pgs=0 cs=0 l=0).accept sd=40
2018-02-13 08:52:21.700919 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:21.700937 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event started fd=39 mask=1 original mask is 0
2018-02-13 08:52:21.700950 7f18417ad700 20 EpollDriver.add_event add event fd=39 cur_mask=0 add_mask=1 to 18
2018-02-13 08:52:21.700959 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event end fd=39 mask=1 original mask is 1
2018-02-13 08:52:21.700965 7f18417ad700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aad800 :-1 s=STATE_ACCEPTING pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:21.701001 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event started fd=40 mask=1 original mask is 0
2018-02-13 08:52:21.701006 7f18417ad700 20 EpollDriver.add_event add event fd=40 cur_mask=0 add_mask=1 to 18
2018-02-13 08:52:21.701012 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event end fd=40 mask=1 original mask is 1
2018-02-13 08:52:21.701043 7f18417ad700 1 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aad800 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=40 -
2018-02-13 08:52:21.701058 7f18417ad700 20 RDMAConnectedSocketImpl send fake send to upper, QP: 262720
2018-02-13 08:52:21.701062 7f18417ad700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aad800 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._try_send sent bytes 281 remaining bytes 0
2018-02-13 08:52:21.701071 7f18417ad700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aad800 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection write banner and addr done: -
2018-02-13 08:52:21.701077 7f18417ad700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aad800 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:21.701087 7f18417ad700 20 RDMAConnectedSocketImpl read notify_fd : 0 in 262720 r = -1
2018-02-13 08:52:21.701098 7f18417ad700 20 RDMAConnectedSocketImpl handle_connection QP: 262720 tcp_fd: 39 notify_fd: 40
2018-02-13 08:52:21.701117 7f18417ad700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ??zA
2018-02-13 08:52:21.701131 7f18417ad700 10 Infiniband send_msg sending: 79, 262720, 2116118, 0, fe80000000000000f45214030035f771
2018-02-13 08:52:21.701203 7f18417ad700 20 RDMAConnectedSocketImpl activate Choosing gid_index 67, sl 3
2018-02-13 08:52:21.701300 7f18417ad700 20 RDMAConnectedSocketImpl activate transition to RTR state successfully.
2018-02-13 08:52:21.701414 7f18417ad700 20 RDMAConnectedSocketImpl activate transition to RTS state successfully.
2018-02-13 08:52:21.701422 7f18417ad700 20 RDMAConnectedSocketImpl activate QueuePair: 0x5565f9ec3110 with qp:0x5565f966cd00
2018-02-13 08:52:21.701573 7f18417ad700 20 RDMAConnectedSocketImpl handle_connection QP: 262720 tcp_fd: 39 notify_fd: 40
2018-02-13 08:52:21.701593 7f18417ad700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ??zA
2018-02-13 08:52:21.701597 7f18417ad700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:25.827257 7f18417ad700 20 RDMAConnectedSocketImpl handle_connection QP: 262720 tcp_fd: 39 notify_fd: 40
2018-02-13 08:52:25.827286 7f18417ad700 10 Infiniband recv_msg got disconnect message
2018-02-13 08:52:25.827289 7f18417ad700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:26.228799 7f1840fac700 10 Processor -- accept listen_fd=28
2018-02-13 08:52:26.228821 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:26.228850 7f1840fac700 20 Infiniband init started.
2018-02-13 08:52:26.229014 7f1840fac700 20 Infiniband init successfully create queue pair: qp=0x5565f966cf80
2018-02-13 08:52:26.229480 7f1840fac700 20 Infiniband init successfully change queue pair to INIT: qp=0x5565f966cf80
2018-02-13 08:52:26.229501 7f1840fac700 20 RDMAServerSocketImpl accept accepted a new QP, tcp_fd: 41
2018-02-13 08:52:26.229505 7f1840fac700 10 Processor -- accept accepted incoming on sd 42
2018-02-13 08:52:26.229530 7f1840fac700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aaf000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).accept sd=42
2018-02-13 08:52:26.229552 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:26.229573 7f1840fac700 20 Event(0x5565f966ad00 nevent=5000 time_id=1).create_file_event create event started fd=41 mask=1 original mask is 0
2018-02-13 08:52:26.229581 7f1840fac700 20 EpollDriver.add_event add event fd=41 cur_mask=0 add_mask=1 to 15
2018-02-13 08:52:26.229590 7f1840fac700 20 Event(0x5565f966ad00 nevent=5000 time_id=1).create_file_event create event end fd=41 mask=1 original mask is 1
2018-02-13 08:52:26.229597 7f1840fac700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aaf000 :-1 s=STATE_ACCEPTING pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:26.229606 7f1840fac700 20 Event(0x5565f966ad00 nevent=5000 time_id=1).create_file_event create event started fd=42 mask=1 original mask is 0
2018-02-13 08:52:26.229609 7f1840fac700 20 EpollDriver.add_event add event fd=42 cur_mask=0 add_mask=1 to 15
2018-02-13 08:52:26.229615 7f1840fac700 20 Event(0x5565f966ad00 nevent=5000 time_id=1).create_file_event create event end fd=42 mask=1 original mask is 1
2018-02-13 08:52:26.229624 7f1840fac700 1 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aaf000 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=42 -
2018-02-13 08:52:26.229638 7f1840fac700 20 RDMAConnectedSocketImpl send fake send to upper, QP: 262722
2018-02-13 08:52:26.229640 7f1840fac700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aaf000 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._try_send sent bytes 281 remaining bytes 0
2018-02-13 08:52:26.229647 7f1840fac700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aaf000 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection write banner and addr done: -
2018-02-13 08:52:26.229654 7f1840fac700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9aaf000 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:26.229664 7f1840fac700 20 RDMAConnectedSocketImpl read notify_fd : 0 in 262722 r = -1
2018-02-13 08:52:26.229675 7f1840fac700 20 RDMAConnectedSocketImpl handle_connection QP: 262722 tcp_fd: 41 notify_fd: 42
2018-02-13 08:52:26.229716 7f1840fac700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ???@
2018-02-13 08:52:26.229732 7f1840fac700 10 Infiniband send_msg sending: 79, 262722, 5515815, 0, fe80000000000000f45214030035f771
2018-02-13 08:52:26.229802 7f1840fac700 20 RDMAConnectedSocketImpl activate Choosing gid_index 67, sl 3
2018-02-13 08:52:26.229866 7f1840fac700 20 RDMAConnectedSocketImpl activate transition to RTR state successfully.
2018-02-13 08:52:26.229919 7f1840fac700 20 RDMAConnectedSocketImpl activate transition to RTS state successfully.
2018-02-13 08:52:26.229926 7f1840fac700 20 RDMAConnectedSocketImpl activate QueuePair: 0x5565f9ec2690 with qp:0x5565f966cf80
2018-02-13 08:52:26.230103 7f1840fac700 20 RDMAConnectedSocketImpl handle_connection QP: 262722 tcp_fd: 41 notify_fd: 42
2018-02-13 08:52:26.230121 7f1840fac700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ???@
2018-02-13 08:52:26.230128 7f1840fac700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:27.176569 7f1840fac700 20 RDMAConnectedSocketImpl handle_connection QP: 262722 tcp_fd: 41 notify_fd: 42
2018-02-13 08:52:27.176598 7f1840fac700 10 Infiniband recv_msg got disconnect message
2018-02-13 08:52:27.176600 7f1840fac700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:27.177517 7f1840fac700 10 Processor -- accept listen_fd=28
2018-02-13 08:52:27.177540 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:27.177571 7f1840fac700 20 Infiniband init started.
2018-02-13 08:52:27.177735 7f1840fac700 20 Infiniband init successfully create queue pair: qp=0x5565f966d200
2018-02-13 08:52:27.178243 7f1840fac700 20 Infiniband init successfully change queue pair to INIT: qp=0x5565f966d200
2018-02-13 08:52:27.178270 7f1840fac700 20 Event(0x5565f966b700 nevent=5000 time_id=1).wakeup
2018-02-13 08:52:27.178283 7f1840fac700 20 RDMAServerSocketImpl accept accepted a new QP, tcp_fd: 43
2018-02-13 08:52:27.178286 7f1840fac700 10 Processor -- accept accepted incoming on sd 44
2018-02-13 08:52:27.178309 7f1840fac700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ab0800 :-1 s=STATE_NONE pgs=0 cs=0 l=0).accept sd=44
2018-02-13 08:52:27.178326 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:27.178368 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event started fd=43 mask=1 original mask is 0
2018-02-13 08:52:27.178390 7f1841fae700 20 EpollDriver.add_event add event fd=43 cur_mask=0 add_mask=1 to 21
2018-02-13 08:52:27.178399 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event end fd=43 mask=1 original mask is 1
2018-02-13 08:52:27.178408 7f1841fae700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ab0800 :-1 s=STATE_ACCEPTING pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:27.178426 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event started fd=44 mask=1 original mask is 0
2018-02-13 08:52:27.178433 7f1841fae700 20 EpollDriver.add_event add event fd=44 cur_mask=0 add_mask=1 to 21
2018-02-13 08:52:27.178465 7f1841fae700 20 Event(0x5565f966b700 nevent=5000 time_id=1).create_file_event create event end fd=44 mask=1 original mask is 1
2018-02-13 08:52:27.178494 7f1841fae700 1 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ab0800 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=44 -
2018-02-13 08:52:27.178509 7f1841fae700 20 RDMAConnectedSocketImpl send fake send to upper, QP: 262724
2018-02-13 08:52:27.178513 7f1841fae700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ab0800 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._try_send sent bytes 281 remaining bytes 0
2018-02-13 08:52:27.178520 7f1841fae700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ab0800 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection write banner and addr done: -
2018-02-13 08:52:27.178527 7f1841fae700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ab0800 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:27.178536 7f1841fae700 20 RDMAConnectedSocketImpl read notify_fd : 0 in 262724 r = -1
2018-02-13 08:52:27.178549 7f1841fae700 20 RDMAConnectedSocketImpl handle_connection QP: 262724 tcp_fd: 43 notify_fd: 44
2018-02-13 08:52:27.178570 7f1841fae700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ???A
2018-02-13 08:52:27.178585 7f1841fae700 10 Infiniband send_msg sending: 79, 262724, 10238434, 0, fe80000000000000f45214030035f771
2018-02-13 08:52:27.178655 7f1841fae700 20 RDMAConnectedSocketImpl activate Choosing gid_index 67, sl 3
2018-02-13 08:52:27.178723 7f1841fae700 20 RDMAConnectedSocketImpl activate transition to RTR state successfully.
2018-02-13 08:52:27.178805 7f1841fae700 20 RDMAConnectedSocketImpl activate transition to RTS state successfully.
2018-02-13 08:52:27.178811 7f1841fae700 20 RDMAConnectedSocketImpl activate QueuePair: 0x5565f9ec2fc0 with qp:0x5565f966d200
2018-02-13 08:52:27.178903 7f1841fae700 20 RDMAConnectedSocketImpl handle_connection QP: 262724 tcp_fd: 43 notify_fd: 44
2018-02-13 08:52:27.178920 7f1841fae700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ???A
2018-02-13 08:52:27.178924 7f1841fae700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:30.177084 7f1841fae700 20 RDMAConnectedSocketImpl handle_connection QP: 262724 tcp_fd: 43 notify_fd: 44
2018-02-13 08:52:30.177111 7f1841fae700 10 Infiniband recv_msg got disconnect message
2018-02-13 08:52:30.177113 7f1841fae700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:30.178099 7f1840fac700 10 Processor -- accept listen_fd=28
2018-02-13 08:52:30.178121 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:30.178152 7f1840fac700 20 Infiniband init started.
2018-02-13 08:52:30.178315 7f1840fac700 20 Infiniband init successfully create queue pair: qp=0x5565f966d480
2018-02-13 08:52:30.178833 7f1840fac700 20 Infiniband init successfully change queue pair to INIT: qp=0x5565f966d480
2018-02-13 08:52:30.178850 7f1840fac700 20 Event(0x5565f966b200 nevent=5000 time_id=1).wakeup
2018-02-13 08:52:30.178857 7f1840fac700 20 RDMAServerSocketImpl accept accepted a new QP, tcp_fd: 45
2018-02-13 08:52:30.178859 7f1840fac700 10 Processor -- accept accepted incoming on sd 46
2018-02-13 08:52:30.178887 7f1840fac700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ad6000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).accept sd=46
2018-02-13 08:52:30.178896 7f1840fac700 20 Event(0x5565f966b200 nevent=5000 time_id=1).wakeup
2018-02-13 08:52:30.178891 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event started fd=45 mask=1 original mask is 0
2018-02-13 08:52:30.178899 7f18417ad700 20 EpollDriver.add_event add event fd=45 cur_mask=0 add_mask=1 to 18
2018-02-13 08:52:30.178901 7f1840fac700 15 RDMAServerSocketImpl accept
2018-02-13 08:52:30.178904 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event end fd=45 mask=1 original mask is 1
2018-02-13 08:52:30.178912 7f18417ad700 20 RDMAConnectedSocketImpl handle_connection QP: 262726 tcp_fd: 45 notify_fd: 46
2018-02-13 08:52:30.178922 7f18417ad700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ??zA
2018-02-13 08:52:30.178934 7f18417ad700 10 Infiniband send_msg sending: 79, 262726, 11225430, 0, fe80000000000000f45214030035f771
2018-02-13 08:52:30.178974 7f18417ad700 20 RDMAConnectedSocketImpl activate Choosing gid_index 67, sl 3
2018-02-13 08:52:30.179026 7f18417ad700 20 RDMAConnectedSocketImpl activate transition to RTR state successfully.
2018-02-13 08:52:30.179099 7f18417ad700 20 RDMAConnectedSocketImpl activate transition to RTS state successfully.
2018-02-13 08:52:30.179103 7f18417ad700 20 RDMAConnectedSocketImpl activate QueuePair: 0x5565f9ec2f50 with qp:0x5565f966d480
2018-02-13 08:52:30.179107 7f18417ad700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ad6000 :-1 s=STATE_ACCEPTING pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:30.179115 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event started fd=46 mask=1 original mask is 0
2018-02-13 08:52:30.179117 7f18417ad700 20 EpollDriver.add_event add event fd=46 cur_mask=0 add_mask=1 to 18
2018-02-13 08:52:30.179120 7f18417ad700 20 Event(0x5565f966b200 nevent=5000 time_id=1).create_file_event create event end fd=46 mask=1 original mask is 1
2018-02-13 08:52:30.179126 7f18417ad700 1 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ad6000 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=46 -
2018-02-13 08:52:30.179134 7f18417ad700 20 RDMAConnectedSocketImpl send fake send to upper, QP: 262726
2018-02-13 08:52:30.179135 7f18417ad700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ad6000 :6789 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._try_send sent bytes 281 remaining bytes 0
2018-02-13 08:52:30.179140 7f18417ad700 10 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ad6000 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection write banner and addr done: -
2018-02-13 08:52:30.179145 7f18417ad700 20 -- 192.168.4.96:6789/0 >> - conn(0x5565f9ad6000 :6789 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).process prev state is STATE_ACCEPTING
2018-02-13 08:52:30.179164 7f18417ad700 20 RDMAConnectedSocketImpl read notify_fd : 0 in 262726 r = -1
2018-02-13 08:52:30.179215 7f18417ad700 20 RDMAConnectedSocketImpl handle_connection QP: 262726 tcp_fd: 45 notify_fd: 46
2018-02-13 08:52:30.179234 7f18417ad700 5 Infiniband recv_msg recevd: 4, 0, 0, 0, ??zA
2018-02-13 08:52:30.179243 7f18417ad700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:52:30.457113 7f18417ad700 20 RDMAConnectedSocketImpl handle_connection QP: 262726 tcp_fd: 45 notify_fd: 46
2018-02-13 08:52:30.457137 7f18417ad700 10 Infiniband recv_msg got disconnect message
2018-02-13 08:52:30.457139 7f18417ad700 10 RDMAConnectedSocketImpl handle_connection server is already active.
2018-02-13 08:53:03.163979 7f18477b9700 0 mon.smp-016@0(leader).data_health(39) update_stats avail 97% total 60510 MB, used 1718 MB, avail 58791 MB
2018-02-13 08:54:03.164224 7f18477b9700 0 mon.smp-016@0(leader).data_health(39) update_stats avail 97% total 60510 MB, used 1718 MB, avail 58792 MB
2018-02-13 08:55:03.164517 7f18477b9700 0 mon.smp-016@0(leader).data_health(39) update_stats avail 97% total 60510 MB, used 1718 MB, avail 58792 MB
2018-02-13 08:56:03.164748 7f18477b9700 0 mon.smp-016@0(leader).data_health(39) update_stats avail 97% total 60510 MB, used 1718 MB, avail 58792 MB
2018-02-13 08:57:03.164970 7f18477b9700 0 mon.smp-016@0(leader).data_health(39) update_stats avail 97% total 60510 MB, used 1718 MB, avail 58792 MB
2018-02-13 08:58:03.165199 7f18477b9700 0 mon.smp-016@0(leader).data_health(39) update_stats avail 97% total 60510 MB, used 1718 MB, avail 58792 MB
2018-02-13 08:59:03.165434 7f18477b9700 0 mon.smp-016@0(leader).data_health(39) update_stats avail 97% total 60510 MB, used 1718 MB, avail 58792 MB
(2-2/3)