Project

General

Profile

Bug #37282 » ceph-osd.25.log

David Sieger, 02/01/2019 01:50 PM

 
-490> 2019-02-01 12:22:28.977350 7fe08c95fd80 0 set uid:gid to 167:167 (ceph:ceph)
-489> 2019-02-01 12:22:28.977375 7fe08c95fd80 0 ceph version 12.2.9 (9e300932ef8a8916fb3fda78c58691a6ab0f4217) luminous (stable), process ceph-osd, pid 2021351
-488> 2019-02-01 12:22:28.977421 7fe08c95fd80 5 object store type is bluestore
-487> 2019-02-01 12:22:29.118212 7fe086d30700 2 Event(0x562aff1e2880 nevent=5000 time_id=1).set_owner idx=1 owner=140602311378688
-486> 2019-02-01 12:22:29.118214 7fe08652f700 2 Event(0x562aff1e2c80 nevent=5000 time_id=1).set_owner idx=2 owner=140602302985984
-485> 2019-02-01 12:22:29.118369 7fe087531700 2 Event(0x562aff1e2480 nevent=5000 time_id=1).set_owner idx=0 owner=140602319771392
-484> 2019-02-01 12:22:29.119594 7fe08c95fd80 1 -- 10.2.0.10:0/0 learned_addr learned my addr 10.2.0.10:0/0
-483> 2019-02-01 12:22:29.119620 7fe08c95fd80 1 -- 10.2.0.10:6803/2021351 _finish_bind bind my_inst.addr is 10.2.0.10:6803/2021351
-482> 2019-02-01 12:22:29.119930 7fe08c95fd80 1 -- 172.16.0.6:0/0 learned_addr learned my addr 172.16.0.6:0/0
-481> 2019-02-01 12:22:29.119949 7fe08c95fd80 1 -- 172.16.0.6:6802/2021351 _finish_bind bind my_inst.addr is 172.16.0.6:6802/2021351
-480> 2019-02-01 12:22:29.120358 7fe08c95fd80 1 -- 172.16.0.6:0/0 learned_addr learned my addr 172.16.0.6:0/0
-479> 2019-02-01 12:22:29.120385 7fe08c95fd80 1 -- 172.16.0.6:6803/2021351 _finish_bind bind my_inst.addr is 172.16.0.6:6803/2021351
-478> 2019-02-01 12:22:29.120982 7fe08c95fd80 1 -- 10.2.0.10:0/0 learned_addr learned my addr 10.2.0.10:0/0
-477> 2019-02-01 12:22:29.120999 7fe08c95fd80 1 -- 10.2.0.10:6806/2021351 _finish_bind bind my_inst.addr is 10.2.0.10:6806/2021351
-476> 2019-02-01 12:22:29.121013 7fe08c95fd80 0 pidfile_write: ignore empty --pid-file
-475> 2019-02-01 12:22:29.170780 7fe08c95fd80 5 asok(0x562afef801c0) init /var/run/ceph/ceph-osd.25.asok
-474> 2019-02-01 12:22:29.170795 7fe08c95fd80 5 asok(0x562afef801c0) bind_and_listen /var/run/ceph/ceph-osd.25.asok
-473> 2019-02-01 12:22:29.170876 7fe08c95fd80 5 asok(0x562afef801c0) register_command 0 hook 0x562afef441d8
-472> 2019-02-01 12:22:29.170885 7fe08c95fd80 5 asok(0x562afef801c0) register_command version hook 0x562afef441d8
-471> 2019-02-01 12:22:29.170889 7fe08c95fd80 5 asok(0x562afef801c0) register_command git_version hook 0x562afef441d8
-470> 2019-02-01 12:22:29.170892 7fe08c95fd80 5 asok(0x562afef801c0) register_command help hook 0x562afef46590
-469> 2019-02-01 12:22:29.170896 7fe08c95fd80 5 asok(0x562afef801c0) register_command get_command_descriptions hook 0x562afef465a0
-468> 2019-02-01 12:22:29.170938 7fe084db1700 5 asok(0x562afef801c0) entry start
-467> 2019-02-01 12:22:29.170958 7fe08c95fd80 10 monclient: build_initial_monmap
-466> 2019-02-01 12:22:29.177351 7fe08c95fd80 0 load: jerasure load: lrc load: isa
-465> 2019-02-01 12:22:29.177385 7fe08c95fd80 5 adding auth protocol: cephx
-464> 2019-02-01 12:22:29.177388 7fe08c95fd80 5 adding auth protocol: cephx
-463> 2019-02-01 12:22:29.177450 7fe08c95fd80 1 bdev create path /var/lib/ceph/osd/ceph-25/block type kernel
-462> 2019-02-01 12:22:29.177462 7fe08c95fd80 1 bdev(0x562aff2c0c00 /var/lib/ceph/osd/ceph-25/block) open path /var/lib/ceph/osd/ceph-25/block
-461> 2019-02-01 12:22:29.177676 7fe08c95fd80 1 bdev(0x562aff2c0c00 /var/lib/ceph/osd/ceph-25/block) open size 1000203091968 (0xe8e0c00000, 932GiB) block_size 4096 (4KiB) rotational
-460> 2019-02-01 12:22:29.178021 7fe08c95fd80 1 bluestore(/var/lib/ceph/osd/ceph-25) _set_cache_sizes cache_size 943718400 meta 0.4 kv 0.4 data 0.2
-459> 2019-02-01 12:22:29.178049 7fe08c95fd80 1 bdev(0x562aff2c0c00 /var/lib/ceph/osd/ceph-25/block) close
-458> 2019-02-01 12:22:29.433940 7fe08c95fd80 5 asok(0x562afef801c0) register_command objecter_requests hook 0x562afef46630
-457> 2019-02-01 12:22:29.434147 7fe08c95fd80 1 -- 10.2.0.10:6803/2021351 start start
-456> 2019-02-01 12:22:29.434161 7fe08c95fd80 1 -- - start start
-455> 2019-02-01 12:22:29.434164 7fe08c95fd80 1 -- - start start
-454> 2019-02-01 12:22:29.434166 7fe08c95fd80 1 -- 10.2.0.10:6806/2021351 start start
-453> 2019-02-01 12:22:29.434175 7fe08c95fd80 1 -- 172.16.0.6:6803/2021351 start start
-452> 2019-02-01 12:22:29.434182 7fe08c95fd80 1 -- 172.16.0.6:6802/2021351 start start
-451> 2019-02-01 12:22:29.434194 7fe08c95fd80 1 -- - start start
-450> 2019-02-01 12:22:29.434480 7fe08c95fd80 2 osd.25 0 init /var/lib/ceph/osd/ceph-25 (looks like hdd)
-449> 2019-02-01 12:22:29.434509 7fe08c95fd80 2 osd.25 0 journal /var/lib/ceph/osd/ceph-25/journal
-448> 2019-02-01 12:22:29.434541 7fe08c95fd80 1 bluestore(/var/lib/ceph/osd/ceph-25) _mount path /var/lib/ceph/osd/ceph-25
-447> 2019-02-01 12:22:29.435086 7fe08c95fd80 1 bdev create path /var/lib/ceph/osd/ceph-25/block type kernel
-446> 2019-02-01 12:22:29.435108 7fe08c95fd80 1 bdev(0x562aff2c2a00 /var/lib/ceph/osd/ceph-25/block) open path /var/lib/ceph/osd/ceph-25/block
-445> 2019-02-01 12:22:29.435578 7fe08c95fd80 1 bdev(0x562aff2c2a00 /var/lib/ceph/osd/ceph-25/block) open size 1000203091968 (0xe8e0c00000, 932GiB) block_size 4096 (4KiB) rotational
-444> 2019-02-01 12:22:29.435829 7fe08c95fd80 1 bluestore(/var/lib/ceph/osd/ceph-25) _set_cache_sizes cache_size 943718400 meta 0.4 kv 0.4 data 0.2
-443> 2019-02-01 12:22:29.436037 7fe08c95fd80 1 bdev create path /var/lib/ceph/osd/ceph-25/block.db type kernel
-442> 2019-02-01 12:22:29.436046 7fe08c95fd80 1 bdev(0x562aff1e3a00 /var/lib/ceph/osd/ceph-25/block.db) open path /var/lib/ceph/osd/ceph-25/block.db
-441> 2019-02-01 12:22:29.436538 7fe08c95fd80 1 bdev(0x562aff1e3a00 /var/lib/ceph/osd/ceph-25/block.db) open size 3463446528 (0xce700000, 3.23GiB) block_size 4096 (4KiB) non-rotational
-440> 2019-02-01 12:22:29.436566 7fe08c95fd80 1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-25/block.db size 3.23GiB
-439> 2019-02-01 12:22:29.436988 7fe08c95fd80 1 bdev create path /var/lib/ceph/osd/ceph-25/block type kernel
-438> 2019-02-01 12:22:29.437006 7fe08c95fd80 1 bdev(0x562aff2c3a00 /var/lib/ceph/osd/ceph-25/block) open path /var/lib/ceph/osd/ceph-25/block
-437> 2019-02-01 12:22:29.437435 7fe08c95fd80 1 bdev(0x562aff2c3a00 /var/lib/ceph/osd/ceph-25/block) open size 1000203091968 (0xe8e0c00000, 932GiB) block_size 4096 (4KiB) rotational
-436> 2019-02-01 12:22:29.437468 7fe08c95fd80 1 bluefs add_block_device bdev 2 path /var/lib/ceph/osd/ceph-25/block size 932GiB
-435> 2019-02-01 12:22:29.437554 7fe08c95fd80 1 bluefs mount
-434> 2019-02-01 12:22:29.578212 7fe08c95fd80 0 set rocksdb option compaction_readahead_size = 2097152
-433> 2019-02-01 12:22:29.578267 7fe08c95fd80 0 set rocksdb option compression = kNoCompression
-432> 2019-02-01 12:22:29.578278 7fe08c95fd80 0 set rocksdb option max_write_buffer_number = 4
-431> 2019-02-01 12:22:29.578286 7fe08c95fd80 0 set rocksdb option min_write_buffer_number_to_merge = 1
-430> 2019-02-01 12:22:29.578293 7fe08c95fd80 0 set rocksdb option recycle_log_file_num = 4
-429> 2019-02-01 12:22:29.578299 7fe08c95fd80 0 set rocksdb option writable_file_max_buffer_size = 0
-428> 2019-02-01 12:22:29.578307 7fe08c95fd80 0 set rocksdb option write_buffer_size = 268435456
-427> 2019-02-01 12:22:29.578381 7fe08c95fd80 0 set rocksdb option compaction_readahead_size = 2097152
-426> 2019-02-01 12:22:29.578391 7fe08c95fd80 0 set rocksdb option compression = kNoCompression
-425> 2019-02-01 12:22:29.578397 7fe08c95fd80 0 set rocksdb option max_write_buffer_number = 4
-424> 2019-02-01 12:22:29.578403 7fe08c95fd80 0 set rocksdb option min_write_buffer_number_to_merge = 1
-423> 2019-02-01 12:22:29.578409 7fe08c95fd80 0 set rocksdb option recycle_log_file_num = 4
-422> 2019-02-01 12:22:29.578414 7fe08c95fd80 0 set rocksdb option writable_file_max_buffer_size = 0
-421> 2019-02-01 12:22:29.578420 7fe08c95fd80 0 set rocksdb option write_buffer_size = 268435456
-420> 2019-02-01 12:22:29.578655 7fe08c95fd80 10 rocksdb: do_open db_path db size 3290274201
-419> 2019-02-01 12:22:29.578673 7fe08c95fd80 10 rocksdb: do_open db_path db.slow size 950192937369
-418> 2019-02-01 12:22:29.578676 7fe08c95fd80 10 rocksdb: do_open using custom Env 0x562aff2bb160
-417> 2019-02-01 12:22:29.578713 7fe08c95fd80 10 rocksdb: do_open set bloom filter bits per key to 20
-416> 2019-02-01 12:22:29.578770 7fe08c95fd80 10 rocksdb: do_open block size 4096, block_cache size 360MiB, row_cache size 0B; shards 16, type binned_lru
-415> 2019-02-01 12:22:29.579351 7fe08c95fd80 4 rocksdb: RocksDB version: 5.4.0

-414> 2019-02-01 12:22:29.579391 7fe08c95fd80 4 rocksdb: Git sha rocksdb_build_git_sha:@0@
-413> 2019-02-01 12:22:29.579395 7fe08c95fd80 4 rocksdb: Compile date Oct 24 2018
-412> 2019-02-01 12:22:29.579404 7fe08c95fd80 4 rocksdb: DB SUMMARY

-411> 2019-02-01 12:22:29.579498 7fe08c95fd80 4 rocksdb: CURRENT file: CURRENT

-410> 2019-02-01 12:22:29.579510 7fe08c95fd80 4 rocksdb: IDENTITY file: IDENTITY

-409> 2019-02-01 12:22:29.579515 7fe08c95fd80 4 rocksdb: MANIFEST file: MANIFEST-024143 size: 4356 Bytes

-408> 2019-02-01 12:22:29.579523 7fe08c95fd80 4 rocksdb: SST files in db dir, Total Num: 22, files: 023991.sst 023992.sst 023993.sst 023994.sst 023995.sst 023996.sst 023997.sst 023998.sst 023999.sst

-407> 2019-02-01 12:22:29.579531 7fe08c95fd80 4 rocksdb: SST files in db.slow dir, Total Num: 0, files:

-406> 2019-02-01 12:22:29.579535 7fe08c95fd80 4 rocksdb: Write Ahead Log file in db: 024144.log size: 1634 ;

-405> 2019-02-01 12:22:29.579538 7fe08c95fd80 4 rocksdb: Options.error_if_exists: 0
-404> 2019-02-01 12:22:29.579540 7fe08c95fd80 4 rocksdb: Options.create_if_missing: 0
-403> 2019-02-01 12:22:29.579543 7fe08c95fd80 4 rocksdb: Options.paranoid_checks: 1
-402> 2019-02-01 12:22:29.579544 7fe08c95fd80 4 rocksdb: Options.env: 0x562aff2bb160
-401> 2019-02-01 12:22:29.579547 7fe08c95fd80 4 rocksdb: Options.info_log: 0x562aff2bb820
-400> 2019-02-01 12:22:29.579549 7fe08c95fd80 4 rocksdb: Options.max_open_files: -1
-399> 2019-02-01 12:22:29.579551 7fe08c95fd80 4 rocksdb: Options.max_file_opening_threads: 16
-398> 2019-02-01 12:22:29.579553 7fe08c95fd80 4 rocksdb: Options.use_fsync: 0
-397> 2019-02-01 12:22:29.579555 7fe08c95fd80 4 rocksdb: Options.max_log_file_size: 0
-396> 2019-02-01 12:22:29.579557 7fe08c95fd80 4 rocksdb: Options.max_manifest_file_size: 18446744073709551615
-395> 2019-02-01 12:22:29.579559 7fe08c95fd80 4 rocksdb: Options.log_file_time_to_roll: 0
-394> 2019-02-01 12:22:29.579576 7fe08c95fd80 4 rocksdb: Options.keep_log_file_num: 1000
-393> 2019-02-01 12:22:29.579578 7fe08c95fd80 4 rocksdb: Options.recycle_log_file_num: 4
-392> 2019-02-01 12:22:29.579580 7fe08c95fd80 4 rocksdb: Options.allow_fallocate: 1
-391> 2019-02-01 12:22:29.579582 7fe08c95fd80 4 rocksdb: Options.allow_mmap_reads: 0
-390> 2019-02-01 12:22:29.579583 7fe08c95fd80 4 rocksdb: Options.allow_mmap_writes: 0
-389> 2019-02-01 12:22:29.579585 7fe08c95fd80 4 rocksdb: Options.use_direct_reads: 0
-388> 2019-02-01 12:22:29.579587 7fe08c95fd80 4 rocksdb: Options.use_direct_io_for_flush_and_compaction: 0
-387> 2019-02-01 12:22:29.579589 7fe08c95fd80 4 rocksdb: Options.create_missing_column_families: 0
-386> 2019-02-01 12:22:29.579591 7fe08c95fd80 4 rocksdb: Options.db_log_dir:
-385> 2019-02-01 12:22:29.579593 7fe08c95fd80 4 rocksdb: Options.wal_dir: db
-384> 2019-02-01 12:22:29.579595 7fe08c95fd80 4 rocksdb: Options.table_cache_numshardbits: 6
-383> 2019-02-01 12:22:29.579596 7fe08c95fd80 4 rocksdb: Options.max_subcompactions: 1
-382> 2019-02-01 12:22:29.579598 7fe08c95fd80 4 rocksdb: Options.max_background_flushes: 1
-381> 2019-02-01 12:22:29.579600 7fe08c95fd80 4 rocksdb: Options.WAL_ttl_seconds: 0
-380> 2019-02-01 12:22:29.579602 7fe08c95fd80 4 rocksdb: Options.WAL_size_limit_MB: 0
-379> 2019-02-01 12:22:29.579603 7fe08c95fd80 4 rocksdb: Options.manifest_preallocation_size: 4194304
-378> 2019-02-01 12:22:29.579606 7fe08c95fd80 4 rocksdb: Options.is_fd_close_on_exec: 1
-377> 2019-02-01 12:22:29.579607 7fe08c95fd80 4 rocksdb: Options.advise_random_on_open: 1
-376> 2019-02-01 12:22:29.579609 7fe08c95fd80 4 rocksdb: Options.db_write_buffer_size: 0
-375> 2019-02-01 12:22:29.579611 7fe08c95fd80 4 rocksdb: Options.access_hint_on_compaction_start: 1
-374> 2019-02-01 12:22:29.579612 7fe08c95fd80 4 rocksdb: Options.new_table_reader_for_compaction_inputs: 1
-373> 2019-02-01 12:22:29.579639 7fe08c95fd80 4 rocksdb: Options.compaction_readahead_size: 2097152
-372> 2019-02-01 12:22:29.579642 7fe08c95fd80 4 rocksdb: Options.random_access_max_buffer_size: 1048576
-371> 2019-02-01 12:22:29.579644 7fe08c95fd80 4 rocksdb: Options.writable_file_max_buffer_size: 0
-370> 2019-02-01 12:22:29.579645 7fe08c95fd80 4 rocksdb: Options.use_adaptive_mutex: 0
-369> 2019-02-01 12:22:29.579647 7fe08c95fd80 4 rocksdb: Options.rate_limiter: (nil)
-368> 2019-02-01 12:22:29.579649 7fe08c95fd80 4 rocksdb: Options.sst_file_manager.rate_bytes_per_sec: 0
-367> 2019-02-01 12:22:29.579651 7fe08c95fd80 4 rocksdb: Options.bytes_per_sync: 0
-366> 2019-02-01 12:22:29.579653 7fe08c95fd80 4 rocksdb: Options.wal_bytes_per_sync: 0
-365> 2019-02-01 12:22:29.579654 7fe08c95fd80 4 rocksdb: Options.wal_recovery_mode: 0
-364> 2019-02-01 12:22:29.579656 7fe08c95fd80 4 rocksdb: Options.enable_thread_tracking: 0
-363> 2019-02-01 12:22:29.579657 7fe08c95fd80 4 rocksdb: Options.allow_concurrent_memtable_write: 1
-362> 2019-02-01 12:22:29.579659 7fe08c95fd80 4 rocksdb: Options.enable_write_thread_adaptive_yield: 1
-361> 2019-02-01 12:22:29.579661 7fe08c95fd80 4 rocksdb: Options.write_thread_max_yield_usec: 100
-360> 2019-02-01 12:22:29.579663 7fe08c95fd80 4 rocksdb: Options.write_thread_slow_yield_usec: 3
-359> 2019-02-01 12:22:29.579665 7fe08c95fd80 4 rocksdb: Options.row_cache: None
-358> 2019-02-01 12:22:29.579667 7fe08c95fd80 4 rocksdb: Options.wal_filter: None
-357> 2019-02-01 12:22:29.579669 7fe08c95fd80 4 rocksdb: Options.avoid_flush_during_recovery: 0
-356> 2019-02-01 12:22:29.579671 7fe08c95fd80 4 rocksdb: Options.base_background_compactions: 1
-355> 2019-02-01 12:22:29.579672 7fe08c95fd80 4 rocksdb: Options.max_background_compactions: 1
-354> 2019-02-01 12:22:29.579674 7fe08c95fd80 4 rocksdb: Options.avoid_flush_during_shutdown: 0
-353> 2019-02-01 12:22:29.579675 7fe08c95fd80 4 rocksdb: Options.delayed_write_rate : 16777216
-352> 2019-02-01 12:22:29.579678 7fe08c95fd80 4 rocksdb: Options.max_total_wal_size: 0
-351> 2019-02-01 12:22:29.579680 7fe08c95fd80 4 rocksdb: Options.delete_obsolete_files_period_micros: 21600000000
-350> 2019-02-01 12:22:29.579682 7fe08c95fd80 4 rocksdb: Options.stats_dump_period_sec: 600
-349> 2019-02-01 12:22:29.579684 7fe08c95fd80 4 rocksdb: Compression algorithms supported:
-348> 2019-02-01 12:22:29.579692 7fe08c95fd80 4 rocksdb: Snappy supported: 1
-347> 2019-02-01 12:22:29.579694 7fe08c95fd80 4 rocksdb: Zlib supported: 0
-346> 2019-02-01 12:22:29.579696 7fe08c95fd80 4 rocksdb: Bzip supported: 0
-345> 2019-02-01 12:22:29.579698 7fe08c95fd80 4 rocksdb: LZ4 supported: 0
-344> 2019-02-01 12:22:29.579700 7fe08c95fd80 4 rocksdb: ZSTD supported: 0
-343> 2019-02-01 12:22:29.579702 7fe08c95fd80 4 rocksdb: Fast CRC32 supported: 1
-342> 2019-02-01 12:22:29.580008 7fe08c95fd80 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/version_set.cc:2609] Recovering from manifest file: MANIFEST-024143

-341> 2019-02-01 12:22:29.580201 7fe08c95fd80 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/column_family.cc:407] --------------- Options for column family [default]:

-340> 2019-02-01 12:22:29.580225 7fe08c95fd80 4 rocksdb: Options.comparator: leveldb.BytewiseComparator
-339> 2019-02-01 12:22:29.580257 7fe08c95fd80 4 rocksdb: Options.merge_operator: .T:int64_array.b:bitwise_xor
-338> 2019-02-01 12:22:29.580268 7fe08c95fd80 4 rocksdb: Options.compaction_filter: None
-337> 2019-02-01 12:22:29.580270 7fe08c95fd80 4 rocksdb: Options.compaction_filter_factory: None
-336> 2019-02-01 12:22:29.580272 7fe08c95fd80 4 rocksdb: Options.memtable_factory: SkipListFactory
-335> 2019-02-01 12:22:29.580283 7fe08c95fd80 4 rocksdb: Options.table_factory: BlockBasedTable
-334> 2019-02-01 12:22:29.580330 7fe08c95fd80 4 rocksdb: table_factory options: flush_block_policy_factory: FlushBlockBySizePolicyFactory (0x562afef44218)
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: 0x562aff2a3418
block_cache_name: BinnedLRUCache
block_cache_options:
capacity : 377487360
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

-333> 2019-02-01 12:22:29.580347 7fe08c95fd80 4 rocksdb: Options.write_buffer_size: 268435456
-332> 2019-02-01 12:22:29.580351 7fe08c95fd80 4 rocksdb: Options.max_write_buffer_number: 4
-331> 2019-02-01 12:22:29.580353 7fe08c95fd80 4 rocksdb: Options.compression: NoCompression
-330> 2019-02-01 12:22:29.580356 7fe08c95fd80 4 rocksdb: Options.bottommost_compression: Disabled
-329> 2019-02-01 12:22:29.580358 7fe08c95fd80 4 rocksdb: Options.prefix_extractor: nullptr
-328> 2019-02-01 12:22:29.580361 7fe08c95fd80 4 rocksdb: Options.memtable_insert_with_hint_prefix_extractor: nullptr
-327> 2019-02-01 12:22:29.580379 7fe08c95fd80 4 rocksdb: Options.num_levels: 7
-326> 2019-02-01 12:22:29.580381 7fe08c95fd80 4 rocksdb: Options.min_write_buffer_number_to_merge: 1
-325> 2019-02-01 12:22:29.580383 7fe08c95fd80 4 rocksdb: Options.max_write_buffer_number_to_maintain: 0
-324> 2019-02-01 12:22:29.580385 7fe08c95fd80 4 rocksdb: Options.compression_opts.window_bits: -14
-323> 2019-02-01 12:22:29.580387 7fe08c95fd80 4 rocksdb: Options.compression_opts.level: -1
-322> 2019-02-01 12:22:29.580389 7fe08c95fd80 4 rocksdb: Options.compression_opts.strategy: 0
-321> 2019-02-01 12:22:29.580390 7fe08c95fd80 4 rocksdb: Options.compression_opts.max_dict_bytes: 0
-320> 2019-02-01 12:22:29.580392 7fe08c95fd80 4 rocksdb: Options.level0_file_num_compaction_trigger: 4
-319> 2019-02-01 12:22:29.580393 7fe08c95fd80 4 rocksdb: Options.level0_slowdown_writes_trigger: 20
-318> 2019-02-01 12:22:29.580395 7fe08c95fd80 4 rocksdb: Options.level0_stop_writes_trigger: 36
-317> 2019-02-01 12:22:29.580397 7fe08c95fd80 4 rocksdb: Options.target_file_size_base: 67108864
-316> 2019-02-01 12:22:29.580399 7fe08c95fd80 4 rocksdb: Options.target_file_size_multiplier: 1
-315> 2019-02-01 12:22:29.580400 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_base: 268435456
-314> 2019-02-01 12:22:29.580402 7fe08c95fd80 4 rocksdb: Options.level_compaction_dynamic_level_bytes: 0
-313> 2019-02-01 12:22:29.580404 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_multiplier: 10.000000
-312> 2019-02-01 12:22:29.580410 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[0]: 1
-311> 2019-02-01 12:22:29.580412 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[1]: 1
-310> 2019-02-01 12:22:29.580414 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[2]: 1
-309> 2019-02-01 12:22:29.580416 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[3]: 1
-308> 2019-02-01 12:22:29.580418 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[4]: 1
-307> 2019-02-01 12:22:29.580420 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[5]: 1
-306> 2019-02-01 12:22:29.580421 7fe08c95fd80 4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[6]: 1
-305> 2019-02-01 12:22:29.580436 7fe08c95fd80 4 rocksdb: Options.max_sequential_skip_in_iterations: 8
-304> 2019-02-01 12:22:29.580439 7fe08c95fd80 4 rocksdb: Options.max_compaction_bytes: 1677721600
-303> 2019-02-01 12:22:29.580458 7fe08c95fd80 4 rocksdb: Options.arena_block_size: 33554432
-302> 2019-02-01 12:22:29.580460 7fe08c95fd80 4 rocksdb: Options.soft_pending_compaction_bytes_limit: 68719476736
-301> 2019-02-01 12:22:29.580462 7fe08c95fd80 4 rocksdb: Options.hard_pending_compaction_bytes_limit: 274877906944
-300> 2019-02-01 12:22:29.580464 7fe08c95fd80 4 rocksdb: Options.rate_limit_delay_max_milliseconds: 100
-299> 2019-02-01 12:22:29.580466 7fe08c95fd80 4 rocksdb: Options.disable_auto_compactions: 0
-298> 2019-02-01 12:22:29.580468 7fe08c95fd80 4 rocksdb: Options.compaction_style: kCompactionStyleLevel
-297> 2019-02-01 12:22:29.580472 7fe08c95fd80 4 rocksdb: Options.compaction_pri: kByCompensatedSize
-296> 2019-02-01 12:22:29.580474 7fe08c95fd80 4 rocksdb: Options.compaction_options_universal.size_ratio: 1
-295> 2019-02-01 12:22:29.580476 7fe08c95fd80 4 rocksdb: Options.compaction_options_universal.min_merge_width: 2
-294> 2019-02-01 12:22:29.580478 7fe08c95fd80 4 rocksdb: Options.compaction_options_universal.max_merge_width: 4294967295
-293> 2019-02-01 12:22:29.580480 7fe08c95fd80 4 rocksdb: Options.compaction_options_universal.max_size_amplification_percent: 200
-292> 2019-02-01 12:22:29.580482 7fe08c95fd80 4 rocksdb: Options.compaction_options_universal.compression_size_percent: -1
-291> 2019-02-01 12:22:29.580484 7fe08c95fd80 4 rocksdb: Options.compaction_options_fifo.max_table_files_size: 1073741824
-290> 2019-02-01 12:22:29.580486 7fe08c95fd80 4 rocksdb: Options.table_properties_collectors:
-289> 2019-02-01 12:22:29.580488 7fe08c95fd80 4 rocksdb: Options.inplace_update_support: 0
-288> 2019-02-01 12:22:29.580490 7fe08c95fd80 4 rocksdb: Options.inplace_update_num_locks: 10000
-287> 2019-02-01 12:22:29.580491 7fe08c95fd80 4 rocksdb: Options.memtable_prefix_bloom_size_ratio: 0.000000
-286> 2019-02-01 12:22:29.580495 7fe08c95fd80 4 rocksdb: Options.memtable_huge_page_size: 0
-285> 2019-02-01 12:22:29.580497 7fe08c95fd80 4 rocksdb: Options.bloom_locality: 0
-284> 2019-02-01 12:22:29.580498 7fe08c95fd80 4 rocksdb: Options.max_successive_merges: 0
-283> 2019-02-01 12:22:29.580501 7fe08c95fd80 4 rocksdb: Options.optimize_filters_for_hits: 0
-282> 2019-02-01 12:22:29.580502 7fe08c95fd80 4 rocksdb: Options.paranoid_file_checks: 0
-281> 2019-02-01 12:22:29.580504 7fe08c95fd80 4 rocksdb: Options.force_consistency_checks: 0
-280> 2019-02-01 12:22:29.580506 7fe08c95fd80 4 rocksdb: Options.report_bg_io_stats: 0
-279> 2019-02-01 12:22:29.588285 7fe08c95fd80 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/version_set.cc:2859] Recovered from manifest file:db/MANIFEST-024143 succeeded,manifest_file_number is 24143, next_file_number is 24149, last_sequence is 1272360340, log_number is 0,prev_log_number is 0,max_column_family is 0

-278> 2019-02-01 12:22:29.588321 7fe08c95fd80 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/version_set.cc:2867] Column family [default] (ID 0), log number is 24142

-277> 2019-02-01 12:22:29.588516 7fe08c95fd80 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020149588503, "job": 1, "event": "recovery_started", "log_files": [24144]}
-276> 2019-02-01 12:22:29.588538 7fe08c95fd80 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_open.cc:482] Recovering log #24144 mode 0
-275> 2019-02-01 12:22:29.588796 7fe08c95fd80 5 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_open.cc:815] [default] [WriteLevel0TableForRecovery] Level-0 table #24149: started
-274> 2019-02-01 12:22:29.595014 7fe08c95fd80 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020149594948, "cf_name": "default", "job": 1, "event": "table_file_creation", "file_number": 24149, "file_size": 2035, "table_properties": {"data_size": 990, "index_size": 28, "filter_size": 50, "raw_key_size": 639, "raw_average_key_size": 39, "raw_value_size": 431, "raw_average_value_size": 26, "num_data_blocks": 1, "num_entries": 16, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-273> 2019-02-01 12:22:29.595042 7fe08c95fd80 5 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_open.cc:847] [default] [WriteLevel0TableForRecovery] Level-0 table #24149: 2035 bytes OK
-272> 2019-02-01 12:22:29.595090 7fe08c95fd80 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/version_set.cc:2395] Creating manifest 24150

-271> 2019-02-01 12:22:29.602812 7fe08c95fd80 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020149602799, "job": 1, "event": "recovery_finished"}
-270> 2019-02-01 12:22:29.603160 7fe08c95fd80 5 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_files.cc:307] [JOB 2] Delete db//MANIFEST-024143 type=3 #24143 -- OK

-269> 2019-02-01 12:22:29.603197 7fe08c95fd80 5 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_files.cc:307] [JOB 2] Delete db/024150.sst type=2 #24150 -- OK

-268> 2019-02-01 12:22:29.603224 7fe08c95fd80 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020149603214, "job": 2, "event": "table_file_deletion", "file_number": 24150}
-267> 2019-02-01 12:22:29.603239 7fe08c95fd80 5 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_files.cc:307] [JOB 2] Delete db/024148.sst type=2 #24148 -- OK

-266> 2019-02-01 12:22:29.603251 7fe08c95fd80 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020149603246, "job": 2, "event": "table_file_deletion", "file_number": 24148}
-265> 2019-02-01 12:22:29.603261 7fe08c95fd80 5 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_files.cc:307] [JOB 2] Delete db//024144.log type=0 #24144 -- OK

-264> 2019-02-01 12:22:29.611124 7fe08c95fd80 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_open.cc:1063] DB pointer 0x562aff4ca000
-263> 2019-02-01 12:22:29.611216 7fe08c95fd80 1 bluestore(/var/lib/ceph/osd/ceph-25) _open_db opened rocksdb path db options compression=kNoCompression,max_write_buffer_number=4,min_write_buffer_number_to_merge=1,recycle_log_file_num=4,write_buffer_size=268435456,writable_file_max_buffer_size=0,compaction_readahead_size=2097152
-262> 2019-02-01 12:22:29.612303 7fe078550700 3 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl.cc:447] ------- DUMPING STATS -------
-261> 2019-02-01 12:22:29.612395 7fe078550700 3 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl.cc:448]
** DB Stats **
Uptime(secs): 0.0 total, 0.0 interval
Cumulative writes: 0 writes, 0 keys, 0 commit groups, 0.0 writes per commit group, ingest: 0.00 GB, 0.00 MB/s
Cumulative WAL: 0 writes, 0 syncs, 0.00 writes per sync, written: 0.00 GB, 0.00 MB/s
Cumulative stall: 00:00:0.000 H:M:S, 0.0 percent
Interval writes: 0 writes, 0 keys, 0 commit groups, 0.0 writes per commit group, ingest: 0.00 MB, 0.00 MB/s
Interval WAL: 0 writes, 0 syncs, 0.00 writes per sync, written: 0.00 MB, 0.00 MB/s
Interval stall: 00:00:0.000 H:M:S, 0.0 percent

** Compaction Stats [default] **
Level Files Size Score Read(GB) Rn(GB) Rnp1(GB) Write(GB) Wnew(GB) Moved(GB) W-Amp Rd(MB/s) Wr(MB/s) Comp(sec) Comp(cnt) Avg(sec) KeyIn KeyDrop
----------------------------------------------------------------------------------------------------------------------------------------------------------
L0 1/0 1.99 KB 0.2 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 0.3 0 1 0.006 0 0
L1 1/0 29.56 MB 2.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0
L2 18/0 1.11 GB 0.4 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0
Sum 20/0 1.14 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 0.3 0 1 0.006 0 0
Int 0/0 0.00 KB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 0.3 0 1 0.006 0 0
Uptime(secs): 0.0 total, 0.0 interval
Flush(GB): cumulative 0.000, interval 0.000
AddFile(GB): cumulative 0.000, interval 0.000
AddFile(Total Files): cumulative 0, interval 0
AddFile(L0 Files): cumulative 0, interval 0
AddFile(Keys): cumulative 0, interval 0
Cumulative compaction: 0.00 GB write, 0.06 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds
Interval compaction: 0.00 GB write, 0.06 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds
Stalls(count): 0 level0_slowdown, 0 level0_slowdown_with_compaction, 0 level0_numfiles, 0 level0_numfiles_with_compaction, 0 stop for pending_compaction_bytes, 0 slowdown for pending_compaction_bytes, 0 memtable_compaction, 0 memtable_slowdown, interval 0 total count

** File Read Latency Histogram By Level [default] **

** Compaction Stats [default] **
Level Files Size Score Read(GB) Rn(GB) Rnp1(GB) Write(GB) Wnew(GB) Moved(GB) W-Amp Rd(MB/s) Wr(MB/s) Comp(sec) Comp(cnt) Avg(sec) KeyIn KeyDrop
----------------------------------------------------------------------------------------------------------------------------------------------------------
L0 1/0 1.99 KB 0.2 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 0.3 0 1 0.006 0 0
L1 1/0 29.56 MB 2.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0
L2 18/0 1.11 GB 0.4 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0
Sum 20/0 1.14 GB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 1.0 0.0 0.3 0 1 0.006 0 0
Int 0/0 0.00 KB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0
Uptime(secs): 0.0 total, 0.0 interval
Flush(GB): cumulative 0.000, interval 0.000
AddFile(GB): cumulative 0.000, interval 0.000
AddFile(Total Files): cumulative 0, interval 0
AddFile(L0 Files): cumulative 0, interval 0
AddFile(Keys): cumulative 0, interval 0
Cumulative compaction: 0.00 GB write, 0.06 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds
Interval compaction: 0.00 GB write, 0.00 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds
Stalls(count): 0 level0_slowdown, 0 level0_slowdown_with_compaction, 0 level0_numfiles, 0 level0_numfiles_with_compaction, 0 stop for pending_compaction_bytes, 0 slowdown for pending_compaction_bytes, 0 memtable_compaction, 0 memtable_slowdown, interval 0 total count

** File Read Latency Histogram By Level [default] **

-260> 2019-02-01 12:22:29.612797 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1403] [default] [JOB 3] Compacting 1@1 + 18@2 files to L2, score 1.98
-259> 2019-02-01 12:22:29.612860 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1407] [default] Compaction start summary: Base version 2 Base level 1, inputs: [24147(29MB)], [23991(66MB) 23992(65MB) 23993(65MB) 23994(65MB) 23995(65MB) 23996(65MB) 23997(65MB) 23998(65MB) 23999(65MB) 24000(65MB) 24001(65MB) 24002(65MB) 24003(65MB) 24004(65MB) 24005(65MB) 24006(65MB) 24007(65MB) 24008(20MB)]

-258> 2019-02-01 12:22:29.612905 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020149612874, "job": 3, "event": "compaction_started", "files_L1": [24147], "files_L2": [23991, 23992, 23993, 23994, 23995, 23996, 23997, 23998, 23999, 24000, 24001, 24002, 24003, 24004, 24005, 24006, 24007, 24008], "score": 1.97506, "input_data_size": 1222536490}
-257> 2019-02-01 12:22:29.656532 7fe08c95fd80 1 freelist init
-256> 2019-02-01 12:22:29.679212 7fe08c95fd80 1 bluestore(/var/lib/ceph/osd/ceph-25) _open_alloc opening allocation metadata
-255> 2019-02-01 12:22:30.467224 7fe08c95fd80 1 bluestore(/var/lib/ceph/osd/ceph-25) _open_alloc loaded 293GiB in 155982 extents
-254> 2019-02-01 12:22:30.472181 7fe08c95fd80 2 osd.25 0 journal looks like ssd
-253> 2019-02-01 12:22:30.472193 7fe08c95fd80 2 osd.25 0 boot
-252> 2019-02-01 12:22:30.472352 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 0 Usage: 4219812 Request: 67108864
-251> 2019-02-01 12:22:30.472362 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 0 Usage: 4219812 Request: 13421773
-250> 2019-02-01 12:22:30.472364 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 1 Usage: 0 Request: 33554432
-249> 2019-02-01 12:22:30.472366 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 1 Usage: 0 Request: 6710887
-248> 2019-02-01 12:22:30.472367 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 2 Usage: 0 Request: 33554432
-247> 2019-02-01 12:22:30.472368 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 2 Usage: 0 Request: 20132660
-246> 2019-02-01 12:22:30.472370 7fe07f55e700 10 rocksdb: commit_cache_size old: 377487360 new: 134217728
-245> 2019-02-01 12:22:30.472372 7fe07f55e700 10 rocksdb: commit_cache_size High Pri Pool Ratio set to 0.5
-244> 2019-02-01 12:22:30.472426 7fe07f55e700 5 bluestore.MempoolThread(0x562afefc91d0) _tune_cache_size target: 1879048192 heap: 57794560 unmapped: 81920 mapped: 57712640 old cache_size: 134217728 new cache size: 771685171
-243> 2019-02-01 12:22:30.472435 7fe07f55e700 5 bluestore.MempoolThread(0x562afefc91d0) _trim_shards cache_size: 771685171 kv_alloc: 134217728 kv_used: 11284734 meta_alloc: 0 meta_used: 28237 data_alloc: 0 data_used: 0
-242> 2019-02-01 12:22:30.480080 7fe08c95fd80 0 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/cephfs/cls_cephfs.cc:197: loading cephfs
-241> 2019-02-01 12:22:30.480291 7fe08c95fd80 0 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/hello/cls_hello.cc:296: loading cls_hello
-240> 2019-02-01 12:22:30.480311 7fe08c95fd80 0 _get_class not permitted to load sdk
-239> 2019-02-01 12:22:30.480609 7fe08c95fd80 0 _get_class not permitted to load kvs
-238> 2019-02-01 12:22:30.480964 7fe08c95fd80 1 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/log/cls_log.cc:299: Loaded log class!
-237> 2019-02-01 12:22:30.480987 7fe08c95fd80 0 _get_class not permitted to load lua
-236> 2019-02-01 12:22:30.484858 7fe08c95fd80 1 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/refcount/cls_refcount.cc:222: Loaded refcount class!
-235> 2019-02-01 12:22:30.485092 7fe08c95fd80 1 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/replica_log/cls_replica_log.cc:135: Loaded replica log class!
-234> 2019-02-01 12:22:30.488406 7fe08c95fd80 1 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/rgw/cls_rgw.cc:3837: Loaded rgw class!
-233> 2019-02-01 12:22:30.488706 7fe08c95fd80 1 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/statelog/cls_statelog.cc:279: Loaded log class!
-232> 2019-02-01 12:22:30.488912 7fe08c95fd80 1 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/timeindex/cls_timeindex.cc:242: Loaded timeindex class!
-231> 2019-02-01 12:22:30.489095 7fe08c95fd80 1 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/user/cls_user.cc:410: Loaded user class!
-230> 2019-02-01 12:22:30.489242 7fe08c95fd80 1 <cls> /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/cls/version/cls_version.cc:214: Loaded version class!
-229> 2019-02-01 12:22:30.489877 7fe08c95fd80 0 osd.25 49867 crush map has features 2200130813952, adjusting msgr requires for clients
-228> 2019-02-01 12:22:30.489891 7fe08c95fd80 0 osd.25 49867 crush map has features 2200130813952 was 8705, adjusting msgr requires for mons
-227> 2019-02-01 12:22:30.489897 7fe08c95fd80 0 osd.25 49867 crush map has features 720578140510109696, adjusting msgr requires for osds
-226> 2019-02-01 12:22:31.891727 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #24154: 280873 keys, 69257034 bytes
-225> 2019-02-01 12:22:31.891819 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020151891784, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 24154, "file_size": 69257034, "table_properties": {"data_size": 67113166, "index_size": 1287021, "filter_size": 855860, "raw_key_size": 18293941, "raw_average_key_size": 65, "raw_value_size": 59543682, "raw_average_value_size": 211, "num_data_blocks": 17004, "num_entries": 280873, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-224> 2019-02-01 12:22:33.414369 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #24155: 119803 keys, 69085251 bytes
-223> 2019-02-01 12:22:33.414401 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020153414387, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 24155, "file_size": 69085251, "table_properties": {"data_size": 67111735, "index_size": 1517081, "filter_size": 455448, "raw_key_size": 10107275, "raw_average_key_size": 84, "raw_value_size": 63151406, "raw_average_value_size": 527, "num_data_blocks": 17166, "num_entries": 119803, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-222> 2019-02-01 12:22:33.510131 7fe08c95fd80 0 osd.25 49867 load_pgs
-221> 2019-02-01 12:22:33.511380 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.14(unlocked)] enter Initial
-220> 2019-02-01 12:22:33.513622 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.14( empty local-lis/les=49858/49859 n=0 ec=696/696 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49516) [4,25] r=1 lpr=0 crt=0'0 unknown NOTIFY mbc={}] exit Initial 0.002259 0 0.000000
-219> 2019-02-01 12:22:33.513661 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.14( empty local-lis/les=49858/49859 n=0 ec=696/696 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49516) [4,25] r=1 lpr=0 crt=0'0 unknown NOTIFY mbc={}] enter Reset
-218> 2019-02-01 12:22:33.513677 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-217> 2019-02-01 12:22:33.523025 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.21(unlocked)] enter Initial
-216> 2019-02-01 12:22:33.524038 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.21( v 49676'34 (0'0,49676'34] local-lis/les=49858/49859 n=6 ec=695/695 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,15] r=0 lpr=0 crt=49676'34 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.001013 0 0.000000
-215> 2019-02-01 12:22:33.524060 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.21( v 49676'34 (0'0,49676'34] local-lis/les=49858/49859 n=6 ec=695/695 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,15] r=0 lpr=0 crt=49676'34 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-214> 2019-02-01 12:22:33.524069 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-213> 2019-02-01 12:22:33.536816 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4e(unlocked)] enter Initial
-212> 2019-02-01 12:22:33.719389 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4e( v 49867'30257534 (49863'30256018,49867'30257534] local-lis/les=49858/49859 n=138 ec=2835/2835 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,18] r=0 lpr=0 crt=49867'30257534 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.182574 0 0.000000
-211> 2019-02-01 12:22:33.719523 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4e( v 49867'30257534 (49863'30256018,49867'30257534] local-lis/les=49858/49859 n=138 ec=2835/2835 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,18] r=0 lpr=0 crt=49867'30257534 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-210> 2019-02-01 12:22:33.719582 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-209> 2019-02-01 12:22:33.730319 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.37(unlocked)] enter Initial
-208> 2019-02-01 12:22:33.920539 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.37( v 49867'55424073 (49833'55422495,49867'55424073] local-lis/les=49858/49859 n=132 ec=225/225 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49867'55424073 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.190228 0 0.000000
-207> 2019-02-01 12:22:33.920605 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.37( v 49867'55424073 (49833'55422495,49867'55424073] local-lis/les=49858/49859 n=132 ec=225/225 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49867'55424073 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-206> 2019-02-01 12:22:33.920634 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-205> 2019-02-01 12:22:33.926467 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.30(unlocked)] enter Initial
-204> 2019-02-01 12:22:34.014767 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.30( v 49867'23919865 (49829'23918323,49867'23919865] local-lis/les=49858/49859 n=145 ec=225/225 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49508) [16,25] r=1 lpr=0 crt=49867'23919865 lcod 0'0 unknown NOTIFY mbc={}] exit Initial 0.088299 0 0.000000
-203> 2019-02-01 12:22:34.014860 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.30( v 49867'23919865 (49829'23918323,49867'23919865] local-lis/les=49858/49859 n=145 ec=225/225 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49508) [16,25] r=1 lpr=0 crt=49867'23919865 lcod 0'0 unknown NOTIFY mbc={}] enter Reset
-202> 2019-02-01 12:22:34.014910 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-201> 2019-02-01 12:22:34.021948 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.2c(unlocked)] enter Initial
-200> 2019-02-01 12:22:34.022611 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.2c( empty local-lis/les=49858/49859 n=0 ec=696/696 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49514) [3,25] r=1 lpr=0 crt=0'0 unknown NOTIFY mbc={}] exit Initial 0.000669 0 0.000000
-199> 2019-02-01 12:22:34.022679 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.2c( empty local-lis/les=49858/49859 n=0 ec=696/696 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49514) [3,25] r=1 lpr=0 crt=0'0 unknown NOTIFY mbc={}] enter Reset
-198> 2019-02-01 12:22:34.022724 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-197> 2019-02-01 12:22:34.025752 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.2c(unlocked)] enter Initial
-196> 2019-02-01 12:22:35.037996 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #24156: 119930 keys, 69082649 bytes
-195> 2019-02-01 12:22:35.040324 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020155040259, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 24156, "file_size": 69082649, "table_properties": {"data_size": 67111940, "index_size": 1513995, "filter_size": 455727, "raw_key_size": 10114646, "raw_average_key_size": 84, "raw_value_size": 63153490, "raw_average_value_size": 526, "num_data_blocks": 17171, "num_entries": 119930, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-194> 2019-02-01 12:22:35.088316 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.2c( v 49867'19572583 (49859'19571035,49867'19572583] local-lis/les=49858/49859 n=116 ec=225/225 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,15] r=0 lpr=0 crt=49867'19572583 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 1.062566 0 0.000000
-193> 2019-02-01 12:22:35.088393 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.2c( v 49867'19572583 (49859'19571035,49867'19572583] local-lis/les=49858/49859 n=116 ec=225/225 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,15] r=0 lpr=0 crt=49867'19572583 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-192> 2019-02-01 12:22:35.088523 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-191> 2019-02-01 12:22:35.098793 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[20.7(unlocked)] enter Initial
-190> 2019-02-01 12:22:35.099050 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[20.7( empty local-lis/les=49858/49859 n=0 ec=28742/28742 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49536) [17,25] r=1 lpr=0 crt=0'0 unknown NOTIFY mbc={}] exit Initial 0.000259 0 0.000000
-189> 2019-02-01 12:22:35.099104 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[20.7( empty local-lis/les=49858/49859 n=0 ec=28742/28742 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49536) [17,25] r=1 lpr=0 crt=0'0 unknown NOTIFY mbc={}] enter Reset
-188> 2019-02-01 12:22:35.099138 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-187> 2019-02-01 12:22:35.104824 7fe08c95fd80 5 osd.25 pg_epoch: 49859 pg[20.30(unlocked)] enter Initial
-186> 2019-02-01 12:22:35.111628 7fe08c95fd80 5 osd.25 pg_epoch: 49859 pg[20.30( empty local-lis/les=49858/49859 n=0 ec=28742/28742 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,1] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.006805 0 0.000000
-185> 2019-02-01 12:22:35.111753 7fe08c95fd80 5 osd.25 pg_epoch: 49859 pg[20.30( empty local-lis/les=49858/49859 n=0 ec=28742/28742 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,1] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset
-184> 2019-02-01 12:22:35.111794 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-183> 2019-02-01 12:22:35.117722 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[20.1a(unlocked)] enter Initial
-182> 2019-02-01 12:22:35.118308 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[20.1a( empty local-lis/les=49858/49859 n=0 ec=28742/28742 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.000588 0 0.000000
-181> 2019-02-01 12:22:35.118364 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[20.1a( empty local-lis/les=49858/49859 n=0 ec=28742/28742 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset
-180> 2019-02-01 12:22:35.118950 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-179> 2019-02-01 12:22:35.123487 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.cc(unlocked)] enter Initial
-178> 2019-02-01 12:22:35.346151 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.cc( v 49867'3973269 (49863'3971733,49867'3973269] local-lis/les=49858/49859 n=5079 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,6] r=0 lpr=0 crt=49867'3973269 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.222665 0 0.000000
-177> 2019-02-01 12:22:35.346217 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.cc( v 49867'3973269 (49863'3971733,49867'3973269] local-lis/les=49858/49859 n=5079 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,6] r=0 lpr=0 crt=49867'3973269 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-176> 2019-02-01 12:22:35.346240 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-175> 2019-02-01 12:22:35.352505 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.a(unlocked)] enter Initial
-174> 2019-02-01 12:22:35.500000 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 0 Usage: 31400258 Request: 67108864
-173> 2019-02-01 12:22:35.500026 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 1 Usage: 0 Request: 33554432
-172> 2019-02-01 12:22:35.500029 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 2 Usage: 0 Request: 33554432
-171> 2019-02-01 12:22:35.500050 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 3 Usage: 29994673 Request: 67108864
-170> 2019-02-01 12:22:35.500056 7fe07f55e700 10 rocksdb: commit_cache_size old: 134217728 new: 397284354
-169> 2019-02-01 12:22:35.500061 7fe07f55e700 10 rocksdb: commit_cache_size High Pri Pool Ratio set to 0.168919
-168> 2019-02-01 12:22:35.505079 7fe07f55e700 5 bluestore.MempoolThread(0x562afefc91d0) _tune_cache_size target: 1879048192 heap: 155762688 unmapped: 25772032 mapped: 129990656 old cache_size: 791884293 new cache size: 791884574
-167> 2019-02-01 12:22:35.505137 7fe07f55e700 5 bluestore.MempoolThread(0x562afefc91d0) _trim_shards cache_size: 791884574 kv_alloc: 397284354 kv_used: 61403123 meta_alloc: 263066626 meta_used: 28861 data_alloc: 131533312 data_used: 0
-166> 2019-02-01 12:22:35.514333 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.a( v 49867'6671753 (49863'6670205,49867'6671753] local-lis/les=49858/49859 n=5123 ec=223/223 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49854) [6,25] r=1 lpr=0 crt=49867'6671753 lcod 0'0 unknown NOTIFY mbc={}] exit Initial 0.161830 0 0.000000
-165> 2019-02-01 12:22:35.514428 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.a( v 49867'6671753 (49863'6670205,49867'6671753] local-lis/les=49858/49859 n=5123 ec=223/223 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49854) [6,25] r=1 lpr=0 crt=49867'6671753 lcod 0'0 unknown NOTIFY mbc={}] enter Reset
-164> 2019-02-01 12:22:35.514479 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-163> 2019-02-01 12:22:35.530283 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.69(unlocked)] enter Initial
-162> 2019-02-01 12:22:35.732711 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.69( v 49867'3323873 (49863'3322291,49867'3323873] local-lis/les=49858/49859 n=5150 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49519) [14,25] r=1 lpr=0 crt=49867'3323873 lcod 0'0 unknown NOTIFY mbc={}] exit Initial 0.202427 0 0.000000
-161> 2019-02-01 12:22:35.732803 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.69( v 49867'3323873 (49863'3322291,49867'3323873] local-lis/les=49858/49859 n=5150 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49519) [14,25] r=1 lpr=0 crt=49867'3323873 lcod 0'0 unknown NOTIFY mbc={}] enter Reset
-160> 2019-02-01 12:22:35.732852 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-159> 2019-02-01 12:22:35.747691 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1f8(unlocked)] enter Initial
-158> 2019-02-01 12:22:36.768812 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #24157: 120012 keys, 69084720 bytes
-157> 2019-02-01 12:22:36.768909 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020156768875, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 24157, "file_size": 69084720, "table_properties": {"data_size": 67111614, "index_size": 1516105, "filter_size": 456014, "raw_key_size": 10125359, "raw_average_key_size": 84, "raw_value_size": 63149739, "raw_average_value_size": 526, "num_data_blocks": 17173, "num_entries": 120012, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-156> 2019-02-01 12:22:36.809596 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1f8( v 49867'2649817 (49863'2648261,49867'2649817] local-lis/les=49858/49859 n=5345 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,17] r=0 lpr=0 crt=49867'2649817 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 1.061909 0 0.000000
-155> 2019-02-01 12:22:36.809754 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1f8( v 49867'2649817 (49863'2648261,49867'2649817] local-lis/les=49858/49859 n=5345 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,17] r=0 lpr=0 crt=49867'2649817 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-154> 2019-02-01 12:22:36.809815 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-153> 2019-02-01 12:22:36.822656 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.64(unlocked)] enter Initial
-152> 2019-02-01 12:22:37.031507 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.64( v 49867'4576814 (49863'4575277,49867'4576814] local-lis/les=49858/49859 n=5068 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,6] r=0 lpr=0 crt=49867'4576814 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.208853 0 0.000000
-151> 2019-02-01 12:22:37.031596 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.64( v 49867'4576814 (49863'4575277,49867'4576814] local-lis/les=49858/49859 n=5068 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,6] r=0 lpr=0 crt=49867'4576814 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-150> 2019-02-01 12:22:37.031645 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-149> 2019-02-01 12:22:37.045917 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1ff(unlocked)] enter Initial
-148> 2019-02-01 12:22:37.216736 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1ff( v 49867'5401687 (49863'5400102,49867'5401687] local-lis/les=49858/49859 n=5172 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,18] r=0 lpr=0 crt=49867'5401687 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.170822 0 0.000000
-147> 2019-02-01 12:22:37.216802 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1ff( v 49867'5401687 (49863'5400102,49867'5401687] local-lis/les=49858/49859 n=5172 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,18] r=0 lpr=0 crt=49867'5401687 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-146> 2019-02-01 12:22:37.216824 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-145> 2019-02-01 12:22:37.226954 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1ea(unlocked)] enter Initial
-144> 2019-02-01 12:22:37.363387 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1ea( v 49867'7592139 (49863'7590624,49867'7592139] local-lis/les=49858/49859 n=5218 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,22] r=0 lpr=0 crt=49867'7592139 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.136434 0 0.000000
-143> 2019-02-01 12:22:37.363450 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.1ea( v 49867'7592139 (49863'7590624,49867'7592139] local-lis/les=49858/49859 n=5218 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,22] r=0 lpr=0 crt=49867'7592139 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-142> 2019-02-01 12:22:37.363478 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-141> 2019-02-01 12:22:37.376058 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.17(unlocked)] enter Initial
-140> 2019-02-01 12:22:37.404865 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.17( empty local-lis/les=49858/49859 n=0 ec=696/696 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,14] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.028809 0 0.000000
-139> 2019-02-01 12:22:37.404921 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[9.17( empty local-lis/les=49858/49859 n=0 ec=696/696 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,14] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset
-138> 2019-02-01 12:22:37.404947 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-137> 2019-02-01 12:22:37.407987 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.197(unlocked)] enter Initial
-136> 2019-02-01 12:22:37.524812 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.197( v 49867'3117706 (49863'3116204,49867'3117706] local-lis/les=49858/49859 n=5058 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,0] r=0 lpr=0 crt=49867'3117706 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.116826 0 0.000000
-135> 2019-02-01 12:22:37.524875 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.197( v 49867'3117706 (49863'3116204,49867'3117706] local-lis/les=49858/49859 n=5058 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,0] r=0 lpr=0 crt=49867'3117706 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-134> 2019-02-01 12:22:37.524898 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-133> 2019-02-01 12:22:38.378841 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.179(unlocked)] enter Initial
-132> 2019-02-01 12:22:38.400254 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #24158: 121906 keys, 69094584 bytes
-131> 2019-02-01 12:22:38.400361 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020158400326, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 24158, "file_size": 69094584, "table_properties": {"data_size": 67111356, "index_size": 1521191, "filter_size": 461050, "raw_key_size": 10281884, "raw_average_key_size": 84, "raw_value_size": 63109693, "raw_average_value_size": 517, "num_data_blocks": 17222, "num_entries": 121906, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-130> 2019-02-01 12:22:38.570085 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.179( v 49867'2199197 (49863'2197669,49867'2199197] local-lis/les=49858/49859 n=5080 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,1] r=0 lpr=0 crt=49867'2199197 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.191246 0 0.000000
-129> 2019-02-01 12:22:38.570146 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.179( v 49867'2199197 (49863'2197669,49867'2199197] local-lis/les=49858/49859 n=5080 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,1] r=0 lpr=0 crt=49867'2199197 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-128> 2019-02-01 12:22:38.570176 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-127> 2019-02-01 12:22:38.579129 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.67(unlocked)] enter Initial
-126> 2019-02-01 12:22:38.712515 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.67( v 49867'3176344 (49863'3174836,49867'3176344] local-lis/les=49858/49859 n=5223 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,1] r=0 lpr=0 crt=49867'3176344 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.133388 0 0.000000
-125> 2019-02-01 12:22:38.712612 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.67( v 49867'3176344 (49863'3174836,49867'3176344] local-lis/les=49858/49859 n=5223 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,1] r=0 lpr=0 crt=49867'3176344 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-124> 2019-02-01 12:22:38.712662 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-123> 2019-02-01 12:22:38.717074 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.16e(unlocked)] enter Initial
-122> 2019-02-01 12:22:38.820432 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.16e( v 49867'3104266 (49863'3102689,49867'3104266] local-lis/les=49858/49859 n=5089 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,13] r=0 lpr=0 crt=49867'3104266 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.103359 0 0.000000
-121> 2019-02-01 12:22:38.820520 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.16e( v 49867'3104266 (49863'3102689,49867'3104266] local-lis/les=49858/49859 n=5089 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,13] r=0 lpr=0 crt=49867'3104266 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-120> 2019-02-01 12:22:38.820570 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-119> 2019-02-01 12:22:38.833132 7fe08c95fd80 5 osd.25 pg_epoch: 49859 pg[8.b(unlocked)] enter Initial
-118> 2019-02-01 12:22:38.837610 7fe08c95fd80 5 osd.25 pg_epoch: 49859 pg[8.b( v 49645'44 (0'0,49645'44] local-lis/les=49858/49859 n=4 ec=695/695 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,9] r=0 lpr=0 crt=49645'44 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.004496 0 0.000000
-117> 2019-02-01 12:22:38.837692 7fe08c95fd80 5 osd.25 pg_epoch: 49859 pg[8.b( v 49645'44 (0'0,49645'44] local-lis/les=49858/49859 n=4 ec=695/695 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,9] r=0 lpr=0 crt=49645'44 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-116> 2019-02-01 12:22:38.837741 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-115> 2019-02-01 12:22:38.845918 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.b9(unlocked)] enter Initial
-114> 2019-02-01 12:22:39.093756 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.b9( v 49867'9386146 (49867'9384580,49867'9386146] local-lis/les=49858/49859 n=5079 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=49867'9386146 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.247839 0 0.000000
-113> 2019-02-01 12:22:39.093829 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.b9( v 49867'9386146 (49867'9384580,49867'9386146] local-lis/les=49858/49859 n=5079 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=49867'9386146 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-112> 2019-02-01 12:22:39.093864 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-111> 2019-02-01 12:22:39.104988 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.157(unlocked)] enter Initial
-110> 2019-02-01 12:22:40.207777 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #24159: 120296 keys, 69086652 bytes
-109> 2019-02-01 12:22:40.208063 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020160208027, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 24159, "file_size": 69086652, "table_properties": {"data_size": 67110690, "index_size": 1518275, "filter_size": 456700, "raw_key_size": 10153392, "raw_average_key_size": 84, "raw_value_size": 63142787, "raw_average_value_size": 524, "num_data_blocks": 17167, "num_entries": 120296, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-108> 2019-02-01 12:22:40.280890 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.157( v 49867'4176469 (49863'4174968,49867'4176469] local-lis/les=49858/49859 n=5260 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49508) [16,25] r=1 lpr=0 crt=49867'4176469 lcod 0'0 unknown NOTIFY mbc={}] exit Initial 1.175926 0 0.000000
-107> 2019-02-01 12:22:40.280958 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.157( v 49867'4176469 (49863'4174968,49867'4176469] local-lis/les=49858/49859 n=5260 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49508) [16,25] r=1 lpr=0 crt=49867'4176469 lcod 0'0 unknown NOTIFY mbc={}] enter Reset
-106> 2019-02-01 12:22:40.281018 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-105> 2019-02-01 12:22:40.285306 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.26(unlocked)] enter Initial
-104> 2019-02-01 12:22:40.286561 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.26( v 49680'41 (0'0,49680'41] local-lis/les=49858/49859 n=8 ec=695/695 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,14] r=0 lpr=0 crt=49680'41 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.001257 0 0.000000
-103> 2019-02-01 12:22:40.286614 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.26( v 49680'41 (0'0,49680'41] local-lis/les=49858/49859 n=8 ec=695/695 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,14] r=0 lpr=0 crt=49680'41 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-102> 2019-02-01 12:22:40.286644 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-101> 2019-02-01 12:22:40.299357 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.14d(unlocked)] enter Initial
-100> 2019-02-01 12:22:40.483219 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.14d( v 49867'3364434 (49863'3362889,49867'3364434] local-lis/les=49858/49859 n=5143 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,17] r=0 lpr=0 crt=49867'3364434 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.183863 0 0.000000
-99> 2019-02-01 12:22:40.483284 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.14d( v 49867'3364434 (49863'3362889,49867'3364434] local-lis/les=49858/49859 n=5143 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,17] r=0 lpr=0 crt=49867'3364434 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-98> 2019-02-01 12:22:40.483313 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-97> 2019-02-01 12:22:40.486314 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.2f(unlocked)] enter Initial
-96> 2019-02-01 12:22:40.536391 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 0 Usage: 37425208 Request: 100663296
-95> 2019-02-01 12:22:40.536418 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 1 Usage: 0 Request: 33554432
-94> 2019-02-01 12:22:40.536422 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 2 Usage: 0 Request: 33554432
-93> 2019-02-01 12:22:40.536429 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 3 Usage: 47265969 Request: 100663296
-92> 2019-02-01 12:22:40.536435 7fe07f55e700 10 rocksdb: commit_cache_size old: 397284354 new: 437549792
-91> 2019-02-01 12:22:40.536444 7fe07f55e700 10 rocksdb: commit_cache_size High Pri Pool Ratio set to 0.230061
-90> 2019-02-01 12:22:40.549030 7fe07f55e700 5 bluestore.MempoolThread(0x562afefc91d0) _tune_cache_size target: 1879048192 heap: 228048896 unmapped: 39763968 mapped: 188284928 old cache_size: 791884594 new cache size: 791884594
-89> 2019-02-01 12:22:40.549100 7fe07f55e700 5 bluestore.MempoolThread(0x562afefc91d0) _trim_shards cache_size: 791884594 kv_alloc: 437549792 kv_used: 84695273 meta_alloc: 236223200 meta_used: 40461 data_alloc: 118111600 data_used: 0
-88> 2019-02-01 12:22:40.711393 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.2f( v 49867'77367396 (49867'77365811,49867'77367396] local-lis/les=49858/49859 n=142 ec=225/225 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=49867'77367396 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.225083 0 0.000000
-87> 2019-02-01 12:22:40.711492 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.2f( v 49867'77367396 (49867'77365811,49867'77367396] local-lis/les=49858/49859 n=142 ec=225/225 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=49867'77367396 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-86> 2019-02-01 12:22:40.711542 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-85> 2019-02-01 12:22:40.717441 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.50(unlocked)] enter Initial
-84> 2019-02-01 12:22:40.910509 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.50( v 49867'4396191 (49863'4394616,49867'4396191] local-lis/les=49858/49859 n=5108 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,22] r=0 lpr=0 crt=49867'4396191 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.193069 0 0.000000
-83> 2019-02-01 12:22:40.910601 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.50( v 49867'4396191 (49863'4394616,49867'4396191] local-lis/les=49858/49859 n=5108 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,22] r=0 lpr=0 crt=49867'4396191 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-82> 2019-02-01 12:22:40.910650 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-81> 2019-02-01 12:22:40.914982 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.130(unlocked)] enter Initial
-80> 2019-02-01 12:22:41.026444 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.130( v 49867'3759654 (49863'3758144,49867'3759654] local-lis/les=49858/49859 n=5028 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=49867'3759654 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.111481 0 0.000000
-79> 2019-02-01 12:22:41.026501 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.130( v 49867'3759654 (49863'3758144,49867'3759654] local-lis/les=49858/49859 n=5028 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=49867'3759654 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-78> 2019-02-01 12:22:41.026523 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-77> 2019-02-01 12:22:41.038722 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.19e(unlocked)] enter Initial
-76> 2019-02-01 12:22:41.995054 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #24160: 120241 keys, 69086486 bytes
-75> 2019-02-01 12:22:41.995128 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020161995095, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 24160, "file_size": 69086486, "table_properties": {"data_size": 67112398, "index_size": 1516499, "filter_size": 456602, "raw_key_size": 10142762, "raw_average_key_size": 84, "raw_value_size": 63146357, "raw_average_value_size": 525, "num_data_blocks": 17182, "num_entries": 120241, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-74> 2019-02-01 12:22:42.005941 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.19e( v 49859'63446 (28838'61937,49859'63446] local-lis/les=49858/49859 n=8207 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,13] r=0 lpr=0 crt=49859'63446 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.967222 0 0.000000
-73> 2019-02-01 12:22:42.006054 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.19e( v 49859'63446 (28838'61937,49859'63446] local-lis/les=49858/49859 n=8207 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,13] r=0 lpr=0 crt=49859'63446 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-72> 2019-02-01 12:22:42.006110 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-71> 2019-02-01 12:22:42.012037 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[17.11(unlocked)] enter Initial
-70> 2019-02-01 12:22:42.031090 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[17.11( v 2026'295 (0'0,2026'295] local-lis/les=49858/49859 n=1 ec=2018/2018 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,15] r=0 lpr=0 crt=2026'295 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.019055 0 0.000000
-69> 2019-02-01 12:22:42.031183 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[17.11( v 2026'295 (0'0,2026'295] local-lis/les=49858/49859 n=1 ec=2018/2018 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,15] r=0 lpr=0 crt=2026'295 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-68> 2019-02-01 12:22:42.031240 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-67> 2019-02-01 12:22:42.035834 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.189(unlocked)] enter Initial
-66> 2019-02-01 12:22:42.136839 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.189( v 49863'63248 (28842'61688,49863'63248] local-lis/les=49858/49859 n=8327 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49863'63248 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.101007 0 0.000000
-65> 2019-02-01 12:22:42.136903 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.189( v 49863'63248 (28842'61688,49863'63248] local-lis/les=49858/49859 n=8327 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49863'63248 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-64> 2019-02-01 12:22:42.136925 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-63> 2019-02-01 12:22:42.146595 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.10a(unlocked)] enter Initial
-62> 2019-02-01 12:22:42.387789 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.10a( v 49867'4627489 (49863'4625897,49867'4627489] local-lis/les=49858/49859 n=4951 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49805) [19,25] r=1 lpr=0 crt=49867'4627489 lcod 0'0 unknown NOTIFY mbc={}] exit Initial 0.241196 0 0.000000
-61> 2019-02-01 12:22:42.387849 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.10a( v 49867'4627489 (49863'4625897,49867'4627489] local-lis/les=49858/49859 n=4951 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49805) [19,25] r=1 lpr=0 crt=49867'4627489 lcod 0'0 unknown NOTIFY mbc={}] enter Reset
-60> 2019-02-01 12:22:42.387879 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-59> 2019-02-01 12:22:42.397000 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[15.17a(unlocked)] enter Initial
-58> 2019-02-01 12:22:42.536874 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[15.17a( v 49867'62762 (28910'61253,49867'62762] local-lis/les=49858/49859 n=8063 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49867'62762 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.139876 0 0.000000
-57> 2019-02-01 12:22:42.536938 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[15.17a( v 49867'62762 (28910'61253,49867'62762] local-lis/les=49858/49859 n=8063 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49867'62762 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-56> 2019-02-01 12:22:42.536959 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-55> 2019-02-01 12:22:42.545152 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.181(unlocked)] enter Initial
-54> 2019-02-01 12:22:42.662982 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.181( v 49863'63623 (28904'62029,49863'63623] local-lis/les=49858/49859 n=8396 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49854) [15,25] r=1 lpr=0 crt=49863'63623 lcod 0'0 unknown NOTIFY mbc={}] exit Initial 0.117831 0 0.000000
-53> 2019-02-01 12:22:42.663041 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.181( v 49863'63623 (28904'62029,49863'63623] local-lis/les=49858/49859 n=8396 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49854) [15,25] r=1 lpr=0 crt=49863'63623 lcod 0'0 unknown NOTIFY mbc={}] enter Reset
-52> 2019-02-01 12:22:42.663069 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-51> 2019-02-01 12:22:42.672763 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.142(unlocked)] enter Initial
-50> 2019-02-01 12:22:44.387480 7fe078550700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:1116] [default] [JOB 3] Generated table #24161: 120943 keys, 69091509 bytes
-49> 2019-02-01 12:22:44.387734 7fe078550700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1549020164387694, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 24161, "file_size": 69091509, "table_properties": {"data_size": 67112977, "index_size": 1519098, "filter_size": 458447, "raw_key_size": 10204827, "raw_average_key_size": 84, "raw_value_size": 63133068, "raw_average_value_size": 522, "num_data_blocks": 17199, "num_entries": 120943, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "0", "kMergeOperands": "0"}}
-48> 2019-02-01 12:22:44.405997 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.142( v 49863'63474 (28842'61921,49863'63474] local-lis/les=49858/49859 n=8251 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49863'63474 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 1.733236 0 0.000000
-47> 2019-02-01 12:22:44.406061 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.142( v 49863'63474 (28842'61921,49863'63474] local-lis/les=49858/49859 n=8251 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49863'63474 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-46> 2019-02-01 12:22:44.406087 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-45> 2019-02-01 12:22:44.416684 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.f5(unlocked)] enter Initial
-44> 2019-02-01 12:22:44.646601 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.f5( v 49867'6527528 (49863'6526007,49867'6527528] local-lis/les=49858/49859 n=4949 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=49867'6527528 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.229920 0 0.000000
-43> 2019-02-01 12:22:44.646702 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.f5( v 49867'6527528 (49863'6526007,49867'6527528] local-lis/les=49858/49859 n=4949 ec=2823/2823 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=49867'6527528 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-42> 2019-02-01 12:22:44.646799 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-41> 2019-02-01 12:22:44.653202 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.137(unlocked)] enter Initial
-40> 2019-02-01 12:22:44.761010 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.137( v 49863'63112 (28899'61533,49863'63112] local-lis/les=49858/49859 n=8168 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,1] r=0 lpr=0 crt=49863'63112 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.107828 0 0.000000
-39> 2019-02-01 12:22:44.761070 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[15.137( v 49863'63112 (28899'61533,49863'63112] local-lis/les=49858/49859 n=8168 ec=4720/4720 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,1] r=0 lpr=0 crt=49863'63112 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-38> 2019-02-01 12:22:44.761100 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-37> 2019-02-01 12:22:44.773003 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[13.23(unlocked)] enter Initial
-36> 2019-02-01 12:22:44.773409 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[13.23( empty local-lis/les=49858/49859 n=0 ec=704/704 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,22] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.000409 0 0.000000
-35> 2019-02-01 12:22:44.773494 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[13.23( empty local-lis/les=49858/49859 n=0 ec=704/704 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,22] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset
-34> 2019-02-01 12:22:44.773513 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-33> 2019-02-01 12:22:44.778161 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4c(unlocked)] enter Initial
-32> 2019-02-01 12:22:44.880839 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4c( v 49867'32956785 (49676'32955213,49867'32956785] local-lis/les=49858/49859 n=131 ec=2835/2835 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,14] r=0 lpr=0 crt=49867'32956785 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.102679 0 0.000000
-31> 2019-02-01 12:22:44.880927 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4c( v 49867'32956785 (49676'32955213,49867'32956785] local-lis/les=49858/49859 n=131 ec=2835/2835 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,14] r=0 lpr=0 crt=49867'32956785 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-30> 2019-02-01 12:22:44.880992 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-29> 2019-02-01 12:22:44.887352 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4a(unlocked)] enter Initial
-28> 2019-02-01 12:22:45.061582 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4a( v 49867'71479713 (49863'71478192,49867'71479713] local-lis/les=49858/49859 n=130 ec=2835/2835 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49867'71479713 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.174232 0 0.000000
-27> 2019-02-01 12:22:45.061643 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[3.4a( v 49867'71479713 (49863'71478192,49867'71479713] local-lis/les=49858/49859 n=130 ec=2835/2835 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,10] r=0 lpr=0 crt=49867'71479713 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-26> 2019-02-01 12:22:45.061671 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-25> 2019-02-01 12:22:45.066870 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[17.60(unlocked)] enter Initial
-24> 2019-02-01 12:22:45.076792 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[17.60( v 2026'314 (0'0,2026'314] local-lis/les=49858/49859 n=3 ec=2018/2018 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=2026'314 lcod 0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.009923 0 0.000000
-23> 2019-02-01 12:22:45.076844 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[17.60( v 2026'314 (0'0,2026'314] local-lis/les=49858/49859 n=3 ec=2018/2018 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49858) [25,7] r=0 lpr=0 crt=2026'314 lcod 0'0 mlcod 0'0 unknown mbc={}] enter Reset
-22> 2019-02-01 12:22:45.076871 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-21> 2019-02-01 12:22:45.079332 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.27(unlocked)] enter Initial
-20> 2019-02-01 12:22:45.085811 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.27( v 49859'61 (0'0,49859'61] local-lis/les=49858/49859 n=11 ec=695/695 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49590) [0,25] r=1 lpr=0 crt=49859'61 lcod 0'0 unknown NOTIFY mbc={}] exit Initial 0.006481 0 0.000000
-19> 2019-02-01 12:22:45.085843 7fe08c95fd80 5 osd.25 pg_epoch: 49863 pg[8.27( v 49859'61 (0'0,49859'61] local-lis/les=49858/49859 n=11 ec=695/695 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49590) [0,25] r=1 lpr=0 crt=49859'61 lcod 0'0 unknown NOTIFY mbc={}] enter Reset
-18> 2019-02-01 12:22:45.085859 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-17> 2019-02-01 12:22:45.099258 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.68(unlocked)] enter Initial
-16> 2019-02-01 12:22:45.586311 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 0 Usage: 42749064 Request: 100663296
-15> 2019-02-01 12:22:45.586347 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 1 Usage: 0 Request: 33554432
-14> 2019-02-01 12:22:45.586351 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 2 Usage: 0 Request: 33554432
-13> 2019-02-01 12:22:45.586359 7fe07f55e700 10 rocksdb: request_cache_bytes Priority: 3 Usage: 59149489 Request: 100663296
-12> 2019-02-01 12:22:45.586375 7fe07f55e700 10 rocksdb: commit_cache_size old: 437549792 new: 437549792
-11> 2019-02-01 12:22:45.586411 7fe07f55e700 10 rocksdb: commit_cache_size High Pri Pool Ratio set to 0.230061
-10> 2019-02-01 12:22:45.587631 7fe07f55e700 5 bluestore.MempoolThread(0x562afefc91d0) _tune_cache_size target: 1879048192 heap: 268886016 unmapped: 5128192 mapped: 263757824 old cache_size: 791884594 new cache size: 791884594
-9> 2019-02-01 12:22:45.587687 7fe07f55e700 5 bluestore.MempoolThread(0x562afefc91d0) _trim_shards cache_size: 791884594 kv_alloc: 437549792 kv_used: 101898553 meta_alloc: 236223200 meta_used: 52786 data_alloc: 118111600 data_used: 0
-8> 2019-02-01 12:22:46.059514 7fe078550700 3 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_compaction_flush.cc:1591] Compaction error: Corruption: block checksum mismatch
-7> 2019-02-01 12:22:46.059535 7fe078550700 4 rocksdb: (Original Log Time 2019/02/01-12:22:46.059344) [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/compaction_job.cc:621] [default] compacted to: base level 1 max bytes base 268435456 files[1 1 18 0 0 0 0] max score 0.25, MB/sec: 74.3 rd, 37.7 wr, level 2, files in(1, 18) out(9) MB in(29.6, 1136.3) out(591.3), read-write-amplify(59.4) write-amplify(20.0) Corruption: block checksum mismatch, records
-6> 2019-02-01 12:22:46.059543 7fe078550700 4 rocksdb: (Original Log Time 2019/02/01-12:22:46.059483) EVENT_LOG_v1 {"time_micros": 1549020166059376, "job": 3, "event": "compaction_finished", "compaction_time_micros": 16446375, "output_level": 2, "num_output_files": 9, "total_output_size": 619981052, "num_input_records": 1998356, "num_output_records": 1243902, "num_subcompactions": 1, "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [1, 1, 18, 0, 0, 0, 0]}
-5> 2019-02-01 12:22:46.059550 7fe078550700 2 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/rocksdb/db/db_impl_compaction_flush.cc:1275] Waiting after background compaction error: Corruption: block checksum mismatch, Accumulated background error counts: 1
-4> 2019-02-01 12:22:46.111584 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.68( v 49867'7934015 (49867'7932446,49867'7934015] local-lis/les=49858/49859 n=5101 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49514) [3,25] r=1 lpr=0 crt=49867'7934015 lcod 0'0 unknown NOTIFY mbc={}] exit Initial 1.012327 0 0.000000
-3> 2019-02-01 12:22:46.111650 7fe08c95fd80 5 osd.25 pg_epoch: 49867 pg[2.68( v 49867'7934015 (49867'7932446,49867'7934015] local-lis/les=49858/49859 n=5101 ec=748/748 lis/c 49858/49858 les/c/f 49859/49859/0 49858/49858/49514) [3,25] r=1 lpr=0 crt=49867'7934015 lcod 0'0 unknown NOTIFY mbc={}] enter Reset
-2> 2019-02-01 12:22:46.111675 7fe08c95fd80 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , trimmed_dups: , clear_divergent_priors: 0
-1> 2019-02-01 12:22:46.111821 7fe079d53700 -1 rocksdb: submit_transaction error: Corruption: block checksum mismatch code = 2 Rocksdb transaction:
Put( Prefix = O key = 0x7f80000000000000021600000021213dfffffffffffffffeffffffffffffffff'o' Value size = 30)
0> 2019-02-01 12:22:46.117761 7fe079d53700 -1 /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/os/bluestore/BlueStore.cc: In function 'void BlueStore::_kv_sync_thread()' thread 7fe079d53700 time 2019-02-01 12:22:46.111884
/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.9/rpm/el7/BUILD/ceph-12.2.9/src/os/bluestore/BlueStore.cc: 8717: FAILED assert(r == 0)

ceph version 12.2.9 (9e300932ef8a8916fb3fda78c58691a6ab0f4217) luminous (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x110) [0x562af51e5e90]
2: (BlueStore::_kv_sync_thread()+0x3482) [0x562af5090162]
3: (BlueStore::KVSyncThread::entry()+0xd) [0x562af50d701d]
4: (()+0x7e25) [0x7fe089e12e25]
5: (clone()+0x6d) [0x7fe088f03bad]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
1/ 5 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 rbd_mirror
0/ 5 rbd_replay
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
1/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 ms
1/ 5 mon
0/10 monc
1/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 1 reserver
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/10 civetweb
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
0/ 0 refs
1/ 5 xio
1/ 5 compressor
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
20/20 rocksdb
4/ 5 leveldb
4/ 5 memdb
1/ 5 kinetic
1/ 5 fuse
1/ 5 mgr
1/ 5 mgrc
1/ 5 dpdk
1/ 5 eventtrace
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-osd.25.log
--- end dump of recent events ---
2019-02-01 12:22:46.129568 7fe079d53700 -1 *** Caught signal (Aborted) **
in thread 7fe079d53700 thread_name:bstore_kv_sync

ceph version 12.2.9 (9e300932ef8a8916fb3fda78c58691a6ab0f4217) luminous (stable)
1: (()+0xa5c3d1) [0x562af51a73d1]
2: (()+0xf6d0) [0x7fe089e1a6d0]
3: (gsignal()+0x37) [0x7fe088e3b277]
4: (abort()+0x148) [0x7fe088e3c968]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x284) [0x562af51e6004]
6: (BlueStore::_kv_sync_thread()+0x3482) [0x562af5090162]
7: (BlueStore::KVSyncThread::entry()+0xd) [0x562af50d701d]
8: (()+0x7e25) [0x7fe089e12e25]
9: (clone()+0x6d) [0x7fe088f03bad]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
0> 2019-02-01 12:22:46.129568 7fe079d53700 -1 *** Caught signal (Aborted) **
in thread 7fe079d53700 thread_name:bstore_kv_sync

ceph version 12.2.9 (9e300932ef8a8916fb3fda78c58691a6ab0f4217) luminous (stable)
1: (()+0xa5c3d1) [0x562af51a73d1]
2: (()+0xf6d0) [0x7fe089e1a6d0]
3: (gsignal()+0x37) [0x7fe088e3b277]
4: (abort()+0x148) [0x7fe088e3c968]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x284) [0x562af51e6004]
6: (BlueStore::_kv_sync_thread()+0x3482) [0x562af5090162]
7: (BlueStore::KVSyncThread::entry()+0xd) [0x562af50d701d]
8: (()+0x7e25) [0x7fe089e12e25]
9: (clone()+0x6d) [0x7fe088f03bad]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
1/ 5 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 rbd_mirror
0/ 5 rbd_replay
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
1/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 ms
1/ 5 mon
0/10 monc
1/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 1 reserver
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/10 civetweb
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
0/ 0 refs
1/ 5 xio
1/ 5 compressor
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
20/20 rocksdb
4/ 5 leveldb
4/ 5 memdb
1/ 5 kinetic
1/ 5 fuse
1/ 5 mgr
1/ 5 mgrc
1/ 5 dpdk
1/ 5 eventtrace
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-osd.25.log
--- end dump of recent events ---
(1-1/3)