Project

General

Profile

Actions

Bug #17078

closed

bluestore: ceph-disk-test.py fails with fsck leaked some space

Added by Kefu Chai over 7 years ago. Updated over 7 years ago.

Status:
Resolved
Priority:
Urgent
Assignee:
Category:
ceph cli
Target version:
-
% Done:

0%

Source:
Development
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
ceph-disk
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

see /a/kchai-2016-08-19_04:12:33-ceph-disk-wip-cmake---basic-mira/373775

test run: http://pulpito.ceph.com/kchai-2016-08-19_04:12:33-ceph-disk-wip-cmake---basic-mira/
wip-cmake is almost the same with master, it contains some cmake changes not related to ceph-disk.


Files

ceph-disk.log (33.4 KB) ceph-disk.log ceph-disk-test command to create the osd Loïc Dachary, 08/23/2016 03:04 PM

Related issues 1 (0 open1 closed)

Related to Ceph - Bug #17100: tests: scsi_debug fails /dev/disk/by-partuuidResolvedLoïc Dachary08/23/2016

Actions
Actions #1

Updated by Loïc Dachary over 7 years ago

  • Related to Bug #17100: tests: scsi_debug fails /dev/disk/by-partuuid added
Actions #2

Updated by Loïc Dachary over 7 years ago

  • Status changed from New to In Progress
Actions #3

Updated by Loïc Dachary over 7 years ago

It looks like fsck leaked some space;4096 bytes leaked fails the bluestore test. Should fsck be disabled ? It is currently explicitly enabled

ceph-disk --verbose activate /dev/vdb1
main_activate: path = /dev/vdb1
get_dm_uuid: get_dm_uuid /dev/vdb1 uuid path is /sys/dev/block/253:17/dm/uuid
command: Running command: /sbin/blkid -o udev -p /dev/vdb1
command: Running command: /sbin/blkid -p -s TYPE -o value -- /dev/vdb1
command: Running command: /usr/bin/ceph-conf --cluster=ceph --name=osd. --lookup osd_mount_options_xfs
command: Running command: /usr/bin/ceph-conf --cluster=ceph --name=osd. --lookup osd_fs_mount_options_xfs
mount: Mounting /dev/vdb1 on /var/lib/ceph/tmp/mnt.Mq5lWR with options noatime,inode64
command_check_call: Running command: /usr/bin/mount -t xfs -o noatime,inode64 -- /dev/vdb1 /var/lib/ceph/tmp/mnt.Mq5lWR
command: Running command: /sbin/restorecon /var/lib/ceph/tmp/mnt.Mq5lWR
activate: Cluster uuid is 32099794-62e4-4869-9cb7-1ee71a2ff1fd
command: Running command: /usr/bin/ceph-osd --cluster=ceph --show-config-value=fsid
activate: Cluster name is ceph
activate: OSD uuid is 7f16f24e-6928-11e6-b380-525400ba922d
activate: OSD id is 2
activate: Initializing OSD...
command_check_call: Running command: /usr/bin/ceph --cluster ceph --name client.bootstrap-osd --keyring /var/lib/ceph/bootstrap-osd/ceph.keyring mon getmap -o /var/lib/ceph/tmp/mnt.Mq5lWR/activate.monmap
2016-08-23 12:21:54.781870 7faeef35e700 -1 WARNING: the following dangerous and experimental features are enabled: *
2016-08-23 12:21:54.817147 7faeef35e700 -1 WARNING: the following dangerous and experimental features are enabled: *
got monmap epoch 1
command: Running command: /usr/bin/timeout 300 ceph-osd --cluster ceph --mkfs --mkkey -i 2 --monmap /var/lib/ceph/tmp/mnt.Mq5lWR/activate.monmap --osd-data /var/lib/ceph/tmp/mnt.Mq5lWR --osd-uuid 7f16f24e-6928-1\
1e6-b380-525400ba922d --keyring /var/lib/ceph/tmp/mnt.Mq5lWR/keyring --setuser ceph --setgroup ceph
mount_activate: Failed to activate
unmount: Unmounting /var/lib/ceph/tmp/mnt.Mq5lWR
command_check_call: Running command: /bin/umount -- /var/lib/ceph/tmp/mnt.Mq5lWR
Traceback (most recent call last):
  File "/sbin/ceph-disk", line 9, in <module>
    load_entry_point('ceph-disk==1.0.0', 'console_scripts', 'ceph-disk')()
  File "/usr/lib/python2.7/site-packages/ceph_disk/main.py", line 5018, in run
    main(sys.argv[1:])
  File "/usr/lib/python2.7/site-packages/ceph_disk/main.py", line 4969, in main
    args.func(args)
  File "/usr/lib/python2.7/site-packages/ceph_disk/main.py", line 3323, in main_activate
    reactivate=args.reactivate,
  File "/usr/lib/python2.7/site-packages/ceph_disk/main.py", line 3079, in mount_activate
    (osd_id, cluster) = activate(path, activate_key_template, init)
  File "/usr/lib/python2.7/site-packages/ceph_disk/main.py", line 3255, in activate
    keyring=keyring,
  File "/usr/lib/python2.7/site-packages/ceph_disk/main.py", line 2710, in mkfs
    '--setgroup', get_ceph_user(),
  File "/usr/lib/python2.7/site-packages/ceph_disk/main.py", line 2674, in ceph_osd_mkfs
    raise Error('%s failed : %s' % (str(arguments), error))
ceph_disk.main.Error: Error: ['ceph-osd', '--cluster', 'ceph', '--mkfs', '--mkkey', '-i', '2', '--monmap', '/var/lib/ceph/tmp/mnt.Mq5lWR/activate.monmap', '--osd-data', '/var/lib/ceph/tmp/mnt.Mq5lWR', '--osd-uui\
d', '7f16f24e-6928-11e6-b380-525400ba922d', '--keyring', '/var/lib/ceph/tmp/mnt.Mq5lWR/keyring', '--setuser', 'ceph', '--setgroup', 'ceph'] failed : 2016-08-23 12:21:55.020773 7f541d869800 -1 WARNING: the follow\
ing dangerous and experimental features are enabled: *
2016-08-23 12:21:55.020936 7f541d869800 -1 WARNING: the following dangerous and experimental features are enabled: *
2016-08-23 12:21:55.021022 7f541d869800 -1 WARNING: experimental feature 'bluestore' is enabled
Please be aware that this feature is experimental, untested,
unsupported, and may result in data corruption, data loss,
and/or irreparable damage to your cluster.  Do not use
feature with important data.

2016-08-23 12:21:55.051277 7f541d869800 -1 WARNING: the following dangerous and experimental features are enabled: *
2016-08-23 12:21:55.058012 7f541d869800 -1 WARNING: experimental feature 'rocksdb' is enabled
Please be aware that this feature is experimental, untested,
unsupported, and may result in data corruption, data loss,
and/or irreparable damage to your cluster.  Do not use
feature with important data.

2016-08-23 12:21:56.237241 7f541d869800 -1 bluestore(/var/lib/ceph/tmp/mnt.Mq5lWR) fsck leaked some space;4096 bytes leaked
2016-08-23 12:21:56.567251 7f541d869800 -1 bluestore(/var/lib/ceph/tmp/mnt.Mq5lWR) mount fsck found 1 errors
2016-08-23 12:21:56.567261 7f541d869800 -1 OSD::mkfs: couldn't mount ObjectStore: error -5
2016-08-23 12:21:56.567295 7f541d869800 -1  ** ERROR: error creating empty object store in /var/lib/ceph/tmp/mnt.Mq5lWR: (5) Input/output error

Actions #4

Updated by Loïc Dachary over 7 years ago

  • Subject changed from ceph-disk-test.py fails in ceph-disk test suite to bluestore: ceph-disk-test.py fails with fsck leaked some space
  • Description updated (diff)
Actions #5

Updated by Loïc Dachary over 7 years ago

  • Status changed from In Progress to Fix Under Review
Actions #6

Updated by Loïc Dachary over 7 years ago

2016-08-23 14:10:49.223746 7f5042644800 -1 WARNING: the following dangerous and experimental features are enabled: *
2016-08-23 14:10:49.223838 7f5042644800 -1 WARNING: the following dangerous and experimental features are enabled: *
2016-08-23 14:10:49.223842 7f5042644800  0 set uid:gid to 167:167 (ceph:ceph)
2016-08-23 14:10:49.223892 7f5042644800  0 ceph version v11.0.0-1720-gb403cad (b403cad100725b42b1d7afc366fd2b9596a51ea4), process ceph-osd, pid 16590
2016-08-23 14:10:49.223948 7f5042644800  5 object store type is bluestore
2016-08-23 14:10:49.223967 7f5042644800 -1 WARNING: experimental feature 'bluestore' is enabled
Please be aware that this feature is experimental, untested,
unsupported, and may result in data corruption, data loss,
and/or irreparable damage to your cluster.  Do not use
feature with important data.

2016-08-23 14:10:49.224030 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) set_cache_shards 1
2016-08-23 14:10:49.254215 7f5042644800 -1 WARNING: the following dangerous and experimental features are enabled: *
2016-08-23 14:10:49.254228 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _set_csum csum_type crc32c
2016-08-23 14:10:49.254232 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _set_compression mode none alg (none)
2016-08-23 14:10:49.254650 7f5042644800  1 -- :/0 messenger.start
2016-08-23 14:10:49.254704 7f5042644800  1 -- :/1074415300 mark_down_all
2016-08-23 14:10:49.254953 7f5042644800  1 -- :/1074415300 shutdown complete.
2016-08-23 14:10:49.254993 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) mkfs path /var/lib/ceph/tmp/mnt.yHSJud
2016-08-23 14:10:49.256420 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) mkfs already created
2016-08-23 14:10:49.256427 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) set_cache_shards 5
2016-08-23 14:10:49.256431 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) mount path /var/lib/ceph/tmp/mnt.yHSJud
2016-08-23 14:10:49.256461 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) fsck
2016-08-23 14:10:49.256566 7f5042644800  1 bdev create path /var/lib/ceph/tmp/mnt.yHSJud/block type kernel
2016-08-23 14:10:49.257054 7f5042644800  1 bdev(/var/lib/ceph/tmp/mnt.yHSJud/block) open path /var/lib/ceph/tmp/mnt.yHSJud/block
2016-08-23 14:10:49.257366 7f5042644800  1 bdev(/var/lib/ceph/tmp/mnt.yHSJud/block) open size 214642441728 (0x31f9afbe00, 199 GB) block_size 4096 (4096 B) non-rotational
2016-08-23 14:10:49.257379 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud/block) _read_bdev_label
2016-08-23 14:10:49.257653 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud/block) _read_bdev_label got bdev(osd_uuid 5bd05434-6931-11e6-b448-525400ba922d size 0x31f9afbe00 btime 2016-08-23 12:59:10.143975 desc main)
2016-08-23 14:10:49.257680 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _set_alloc_sizes min_alloc_size 0x1000 order 12 max_alloc_size 0x0
2016-08-23 14:10:49.258062 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_db kv_backend = rocksdb
2016-08-23 14:10:49.258555 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_db bluefs = 0
2016-08-23 14:10:49.258568 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_db initializing bluefs
2016-08-23 14:10:49.258616 7f5042644800  1 bdev create path /var/lib/ceph/tmp/mnt.yHSJud/block type kernel
2016-08-23 14:10:49.259039 7f5042644800  1 bdev(/var/lib/ceph/tmp/mnt.yHSJud/block) open path /var/lib/ceph/tmp/mnt.yHSJud/block
2016-08-23 14:10:49.259155 7f5042644800  1 bdev(/var/lib/ceph/tmp/mnt.yHSJud/block) open size 214642441728 (0x31f9afbe00, 199 GB) block_size 4096 (4096 B) non-rotational
2016-08-23 14:10:49.259161 7f5042644800  1 bluefs add_block_device bdev 1 path /var/lib/ceph/tmp/mnt.yHSJud/block size 199 GB
2016-08-23 14:10:49.259191 7f5042644800  1 bluefs mount
2016-08-23 14:10:49.259698 7f5042644800 10 bitmapalloc:BitMapAllocator instance 139982851982976 size 0x31f9afbe00
2016-08-23 14:10:49.260697 7f5042644800 10 bitmapalloc:init_add_free instance 139982851982976 offset 0x2000 length 0x1ffcfe000
2016-08-23 14:10:49.260719 7f5042644800 20 bitmapalloc:insert_free instance 139982851982976 off 0x100000 len 0x1ffc00000
2016-08-23 14:10:49.260989 7f5042644800 10 bitmapalloc:init_rm_free instance 139982851982976 offset 0x600000 length 0x100000
2016-08-23 14:10:49.260995 7f5042644800 10 bitmapalloc:init_rm_free instance 139982851982976 offset 0x800000 length 0x100000
2016-08-23 14:10:49.260997 7f5042644800 10 bitmapalloc:init_rm_free instance 139982851982976 offset 0xc00000 length 0x100000
2016-08-23 14:10:49.260998 7f5042644800 10 bitmapalloc:init_rm_free instance 139982851982976 offset 0x100000 length 0x400000
2016-08-23 14:10:49.261000 7f5042644800 10 bitmapalloc:init_rm_free instance 139982851982976 offset 0xb00000 length 0x100000
2016-08-23 14:10:49.261001 7f5042644800 10 bitmapalloc:init_rm_free instance 139982851982976 offset 0x700000 length 0x100000
2016-08-23 14:10:49.261002 7f5042644800 10 bitmapalloc:init_rm_free instance 139982851982976 offset 0xa00000 length 0x100000
2016-08-23 14:10:49.261037 7f5042644800 -1 WARNING: experimental feature 'rocksdb' is enabled
Please be aware that this feature is experimental, untested,
unsupported, and may result in data corruption, data loss,
and/or irreparable damage to your cluster.  Do not use
feature with important data.

2016-08-23 14:10:49.261122 7f5042644800  0  set rocksdb option compression = kNoCompression
2016-08-23 14:10:49.261130 7f5042644800  0  set rocksdb option max_write_buffer_number = 16
2016-08-23 14:10:49.261134 7f5042644800  0  set rocksdb option min_write_buffer_number_to_merge = 3
2016-08-23 14:10:49.261141 7f5042644800  0  set rocksdb option recycle_log_file_num = 16
2016-08-23 14:10:49.261187 7f5042644800  0  set rocksdb option compression = kNoCompression
2016-08-23 14:10:49.261193 7f5042644800  0  set rocksdb option max_write_buffer_number = 16
2016-08-23 14:10:49.261203 7f5042644800  0  set rocksdb option min_write_buffer_number_to_merge = 3
2016-08-23 14:10:49.261207 7f5042644800  0  set rocksdb option recycle_log_file_num = 16
2016-08-23 14:10:49.261326 7f5042644800  4 rocksdb: RocksDB version: 4.9.0

2016-08-23 14:10:49.261334 7f5042644800  4 rocksdb: Git sha rocksdb_build_git_sha:b403cad100725b42b1d7afc366fd2b9596a51ea4
2016-08-23 14:10:49.261336 7f5042644800  4 rocksdb: Compile date Aug 23 2016
2016-08-23 14:10:49.261339 7f5042644800  4 rocksdb: DB SUMMARY

2016-08-23 14:10:49.261370 7f5042644800  4 rocksdb: CURRENT file:  CURRENT

2016-08-23 14:10:49.261373 7f5042644800  4 rocksdb: IDENTITY file:  IDENTITY

2016-08-23 14:10:49.261375 7f5042644800  4 rocksdb: MANIFEST file:  MANIFEST-000035 size: 100 Bytes

2016-08-23 14:10:49.261377 7f5042644800  4 rocksdb: SST files in db dir, Total Num: 1, files: 000004.sst 

2016-08-23 14:10:49.261379 7f5042644800  4 rocksdb: Write Ahead Log file in db: 000006.log size: 0 ; 000009.log size: 0 ; 000012.log size: 0 ; 000015.log size: 0 ; 000018.log size: 0 ; 000021.log size: 0 ; 000024.log size: 0 ; 000027.log size: 0 ; 000030.log size: 0 ; 000033.log size: 0 ; 000036.log size: 0 ; 

2016-08-23 14:10:49.261383 7f5042644800  4 rocksdb:          Options.error_if_exists: 0
2016-08-23 14:10:49.261385 7f5042644800  4 rocksdb:        Options.create_if_missing: 0
2016-08-23 14:10:49.261386 7f5042644800  4 rocksdb:          Options.paranoid_checks: 1
2016-08-23 14:10:49.261387 7f5042644800  4 rocksdb:                      Options.env: 0x7f504c3a8240
2016-08-23 14:10:49.261388 7f5042644800  4 rocksdb:                 Options.info_log: 0x7f504c3a86a0
2016-08-23 14:10:49.261389 7f5042644800  4 rocksdb:           Options.max_open_files: -1
2016-08-23 14:10:49.261390 7f5042644800  4 rocksdb: Options.max_file_opening_threads: 16
2016-08-23 14:10:49.261391 7f5042644800  4 rocksdb:       Options.max_total_wal_size: 0
2016-08-23 14:10:49.261392 7f5042644800  4 rocksdb:        Options.disableDataSync: 0
2016-08-23 14:10:49.261393 7f5042644800  4 rocksdb:              Options.use_fsync: 0
2016-08-23 14:10:49.261395 7f5042644800  4 rocksdb:      Options.max_log_file_size: 0
2016-08-23 14:10:49.261396 7f5042644800  4 rocksdb: Options.max_manifest_file_size: 18446744073709551615
2016-08-23 14:10:49.261398 7f5042644800  4 rocksdb:      Options.log_file_time_to_roll: 0
2016-08-23 14:10:49.261398 7f5042644800  4 rocksdb:      Options.keep_log_file_num: 1000
2016-08-23 14:10:49.261399 7f5042644800  4 rocksdb:   Options.recycle_log_file_num: 16
2016-08-23 14:10:49.261401 7f5042644800  4 rocksdb:        Options.allow_os_buffer: 1
2016-08-23 14:10:49.261402 7f5042644800  4 rocksdb:       Options.allow_mmap_reads: 0
2016-08-23 14:10:49.261403 7f5042644800  4 rocksdb:       Options.allow_fallocate: 1
2016-08-23 14:10:49.261404 7f5042644800  4 rocksdb:      Options.allow_mmap_writes: 0
2016-08-23 14:10:49.261405 7f5042644800  4 rocksdb:          Options.create_missing_column_families: 0
2016-08-23 14:10:49.261406 7f5042644800  4 rocksdb:                              Options.db_log_dir: 
2016-08-23 14:10:49.261407 7f5042644800  4 rocksdb:                                 Options.wal_dir: db
2016-08-23 14:10:49.261408 7f5042644800  4 rocksdb:                Options.table_cache_numshardbits: 6
2016-08-23 14:10:49.261408 7f5042644800  4 rocksdb:     Options.delete_obsolete_files_period_micros: 21600000000
2016-08-23 14:10:49.261410 7f5042644800  4 rocksdb:              Options.base_background_compactions: 1
2016-08-23 14:10:49.261410 7f5042644800  4 rocksdb:              Options.max_background_compactions: 1
2016-08-23 14:10:49.261411 7f5042644800  4 rocksdb:                      Options.max_subcompactions: 1
2016-08-23 14:10:49.261412 7f5042644800  4 rocksdb:                  Options.max_background_flushes: 1
2016-08-23 14:10:49.261413 7f5042644800  4 rocksdb:                         Options.WAL_ttl_seconds: 0
2016-08-23 14:10:49.261414 7f5042644800  4 rocksdb:                       Options.WAL_size_limit_MB: 0
2016-08-23 14:10:49.261415 7f5042644800  4 rocksdb:             Options.manifest_preallocation_size: 4194304
2016-08-23 14:10:49.261416 7f5042644800  4 rocksdb:                          Options.allow_os_buffer: 1
2016-08-23 14:10:49.261417 7f5042644800  4 rocksdb:                         Options.allow_mmap_reads: 0
2016-08-23 14:10:49.261418 7f5042644800  4 rocksdb:                        Options.allow_mmap_writes: 0
2016-08-23 14:10:49.261419 7f5042644800  4 rocksdb:                      Options.is_fd_close_on_exec: 1
2016-08-23 14:10:49.261420 7f5042644800  4 rocksdb:                    Options.stats_dump_period_sec: 600
2016-08-23 14:10:49.261421 7f5042644800  4 rocksdb:                    Options.advise_random_on_open: 1
2016-08-23 14:10:49.261422 7f5042644800  4 rocksdb:                     Options.db_write_buffer_size: 0d
2016-08-23 14:10:49.261423 7f5042644800  4 rocksdb:          Options.access_hint_on_compaction_start: NORMAL
2016-08-23 14:10:49.261424 7f5042644800  4 rocksdb:   Options.new_table_reader_for_compaction_inputs: 0
2016-08-23 14:10:49.261425 7f5042644800  4 rocksdb:                Options.compaction_readahead_size: 0d
2016-08-23 14:10:49.261426 7f5042644800  4 rocksdb:                Options.random_access_max_buffer_size: 1048576d
2016-08-23 14:10:49.261427 7f5042644800  4 rocksdb:               Options.writable_file_max_buffer_size: 1048576d
2016-08-23 14:10:49.261428 7f5042644800  4 rocksdb:                       Options.use_adaptive_mutex: 0
2016-08-23 14:10:49.261428 7f5042644800  4 rocksdb:                             Options.rate_limiter: (nil)
2016-08-23 14:10:49.261430 7f5042644800  4 rocksdb:      Options.sst_file_manager.rate_bytes_per_sec: 0
2016-08-23 14:10:49.261431 7f5042644800  4 rocksdb:                           Options.bytes_per_sync: 0
2016-08-23 14:10:49.261432 7f5042644800  4 rocksdb:                       Options.wal_bytes_per_sync: 0
2016-08-23 14:10:49.261433 7f5042644800  4 rocksdb:                        Options.wal_recovery_mode: 0
2016-08-23 14:10:49.261434 7f5042644800  4 rocksdb:                   Options.enable_thread_tracking: 0
2016-08-23 14:10:49.261434 7f5042644800  4 rocksdb:          Options.allow_concurrent_memtable_write: 0
2016-08-23 14:10:49.261435 7f5042644800  4 rocksdb:       Options.enable_write_thread_adaptive_yield: 0
2016-08-23 14:10:49.261436 7f5042644800  4 rocksdb:              Options.write_thread_max_yield_usec: 100
2016-08-23 14:10:49.261437 7f5042644800  4 rocksdb:             Options.write_thread_slow_yield_usec: 3
2016-08-23 14:10:49.261438 7f5042644800  4 rocksdb:                                Options.row_cache: None
2016-08-23 14:10:49.261439 7f5042644800  4 rocksdb:        Options.wal_filter: None
2016-08-23 14:10:49.261440 7f5042644800  4 rocksdb:                     Options.avoid_flush_during_recovery: 0
2016-08-23 14:10:49.261441 7f5042644800  4 rocksdb: Compression algorithms supported:
2016-08-23 14:10:49.261442 7f5042644800  4 rocksdb:     Snappy supported: 1
2016-08-23 14:10:49.261443 7f5042644800  4 rocksdb:     Zlib supported: 1
2016-08-23 14:10:49.261444 7f5042644800  4 rocksdb:     Bzip supported: 1
2016-08-23 14:10:49.261451 7f5042644800  4 rocksdb:     LZ4 supported: 0
2016-08-23 14:10:49.261453 7f5042644800  4 rocksdb: Fast CRC32 supported: 0
2016-08-23 14:10:49.261857 7f5042644800  4 rocksdb: Recovering from manifest file: MANIFEST-000035

2016-08-23 14:10:49.261907 7f5042644800  4 rocksdb: --------------- Options for column family [default]:

2016-08-23 14:10:49.261913 7f5042644800  4 rocksdb:               Options.comparator: rocksdb.InternalKeyComparator:leveldb.BytewiseComparator
2016-08-23 14:10:49.261920 7f5042644800  4 rocksdb:           Options.merge_operator: .T:int64_array.b:bitwise_xor
2016-08-23 14:10:49.261922 7f5042644800  4 rocksdb:        Options.compaction_filter: None
2016-08-23 14:10:49.261923 7f5042644800  4 rocksdb:        Options.compaction_filter_factory: None
2016-08-23 14:10:49.261924 7f5042644800  4 rocksdb:         Options.memtable_factory: SkipListFactory
2016-08-23 14:10:49.261925 7f5042644800  4 rocksdb:            Options.table_factory: BlockBasedTable
2016-08-23 14:10:49.261938 7f5042644800  4 rocksdb:            table_factory options:   flush_block_policy_factory: FlushBlockBySizePolicyFactory (0x7f504c28c728)
  cache_index_and_filter_blocks: 0
  pin_l0_filter_and_index_blocks_in_cache: 0
  index_type: 0
  hash_index_allow_collision: 1
  checksum: 1
  no_block_cache: 0
  block_cache: 0x7f504c2c0518
  block_cache_size: 134217728
  block_cache_compressed: (nil)
  block_size: 4096
  block_size_deviation: 10
  block_restart_interval: 16
  index_block_restart_interval: 1
  filter_policy: nullptr
  whole_key_filtering: 1
  skip_table_builder_flush: 0
  format_version: 2

2016-08-23 14:10:49.261942 7f5042644800  4 rocksdb:        Options.write_buffer_size: 67108864
2016-08-23 14:10:49.261943 7f5042644800  4 rocksdb:  Options.max_write_buffer_number: 16
2016-08-23 14:10:49.261944 7f5042644800  4 rocksdb:          Options.compression: NoCompression
2016-08-23 14:10:49.261945 7f5042644800  4 rocksdb:                  Options.bottommost_compression: Disabled
2016-08-23 14:10:49.261948 7f5042644800  4 rocksdb:       Options.prefix_extractor: nullptr
2016-08-23 14:10:49.261949 7f5042644800  4 rocksdb:             Options.num_levels: 7
2016-08-23 14:10:49.261950 7f5042644800  4 rocksdb:        Options.min_write_buffer_number_to_merge: 3
2016-08-23 14:10:49.261952 7f5042644800  4 rocksdb:     Options.max_write_buffer_number_to_maintain: 0
2016-08-23 14:10:49.261953 7f5042644800  4 rocksdb:            Options.compression_opts.window_bits: -14
2016-08-23 14:10:49.261954 7f5042644800  4 rocksdb:                  Options.compression_opts.level: -1
2016-08-23 14:10:49.261955 7f5042644800  4 rocksdb:               Options.compression_opts.strategy: 0
2016-08-23 14:10:49.261956 7f5042644800  4 rocksdb:         Options.compression_opts.max_dict_bytes: 0
2016-08-23 14:10:49.261957 7f5042644800  4 rocksdb:      Options.level0_file_num_compaction_trigger: 4
2016-08-23 14:10:49.261957 7f5042644800  4 rocksdb:          Options.level0_slowdown_writes_trigger: 20
2016-08-23 14:10:49.261958 7f5042644800  4 rocksdb:              Options.level0_stop_writes_trigger: 24
2016-08-23 14:10:49.261959 7f5042644800  4 rocksdb:                   Options.target_file_size_base: 67108864
2016-08-23 14:10:49.261960 7f5042644800  4 rocksdb:             Options.target_file_size_multiplier: 1
2016-08-23 14:10:49.261961 7f5042644800  4 rocksdb:                Options.max_bytes_for_level_base: 268435456
2016-08-23 14:10:49.261962 7f5042644800  4 rocksdb: Options.level_compaction_dynamic_level_bytes: 0
2016-08-23 14:10:49.261963 7f5042644800  4 rocksdb:          Options.max_bytes_for_level_multiplier: 10
2016-08-23 14:10:49.261964 7f5042644800  4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[0]: 1
2016-08-23 14:10:49.261965 7f5042644800  4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[1]: 1
2016-08-23 14:10:49.261966 7f5042644800  4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[2]: 1
2016-08-23 14:10:49.261967 7f5042644800  4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[3]: 1
2016-08-23 14:10:49.261968 7f5042644800  4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[4]: 1
2016-08-23 14:10:49.261969 7f5042644800  4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[5]: 1
2016-08-23 14:10:49.261970 7f5042644800  4 rocksdb: Options.max_bytes_for_level_multiplier_addtl[6]: 1
2016-08-23 14:10:49.261971 7f5042644800  4 rocksdb:       Options.max_sequential_skip_in_iterations: 8
2016-08-23 14:10:49.261972 7f5042644800  4 rocksdb:              Options.expanded_compaction_factor: 25
2016-08-23 14:10:49.261973 7f5042644800  4 rocksdb:                Options.source_compaction_factor: 1
2016-08-23 14:10:49.261974 7f5042644800  4 rocksdb:          Options.max_grandparent_overlap_factor: 10
2016-08-23 14:10:49.261975 7f5042644800  4 rocksdb:                        Options.arena_block_size: 8388608
2016-08-23 14:10:49.261976 7f5042644800  4 rocksdb:   Options.soft_pending_compaction_bytes_limit: 68719476736
2016-08-23 14:10:49.261977 7f5042644800  4 rocksdb:   Options.hard_pending_compaction_bytes_limit: 274877906944
2016-08-23 14:10:49.261978 7f5042644800  4 rocksdb:       Options.rate_limit_delay_max_milliseconds: 1000
2016-08-23 14:10:49.261979 7f5042644800  4 rocksdb:                Options.disable_auto_compactions: 0
2016-08-23 14:10:49.261980 7f5042644800  4 rocksdb:           Options.verify_checksums_in_compaction: 1
2016-08-23 14:10:49.261981 7f5042644800  4 rocksdb:                         Options.compaction_style: 0
2016-08-23 14:10:49.261982 7f5042644800  4 rocksdb:                           Options.compaction_pri: 0
2016-08-23 14:10:49.261983 7f5042644800  4 rocksdb:  Options.compaction_options_universal.size_ratio: 1
2016-08-23 14:10:49.261983 7f5042644800  4 rocksdb: Options.compaction_options_universal.min_merge_width: 2
2016-08-23 14:10:49.261984 7f5042644800  4 rocksdb: Options.compaction_options_universal.max_merge_width: 4294967295
2016-08-23 14:10:49.261985 7f5042644800  4 rocksdb: Options.compaction_options_universal.max_size_amplification_percent: 200
2016-08-23 14:10:49.261987 7f5042644800  4 rocksdb: Options.compaction_options_universal.compression_size_percent: -1
2016-08-23 14:10:49.261988 7f5042644800  4 rocksdb: Options.compaction_options_fifo.max_table_files_size: 1073741824
2016-08-23 14:10:49.261989 7f5042644800  4 rocksdb:                   Options.table_properties_collectors: 
2016-08-23 14:10:49.261990 7f5042644800  4 rocksdb:                   Options.inplace_update_support: 0
2016-08-23 14:10:49.261991 7f5042644800  4 rocksdb:                 Options.inplace_update_num_locks: 10000
2016-08-23 14:10:49.261992 7f5042644800  4 rocksdb:               Options.min_partial_merge_operands: 2
2016-08-23 14:10:49.261993 7f5042644800  4 rocksdb:               Options.memtable_prefix_bloom_size_ratio: 0.000000
2016-08-23 14:10:49.262002 7f5042644800  4 rocksdb:   Options.memtable_prefix_bloom_huge_page_tlb_size: 0
2016-08-23 14:10:49.262003 7f5042644800  4 rocksdb:                           Options.bloom_locality: 0
2016-08-23 14:10:49.262004 7f5042644800  4 rocksdb:                    Options.max_successive_merges: 0
2016-08-23 14:10:49.262005 7f5042644800  4 rocksdb:                Options.optimize_filters_for_hits: 0
2016-08-23 14:10:49.262006 7f5042644800  4 rocksdb:                Options.paranoid_file_checks: 0
2016-08-23 14:10:49.262006 7f5042644800  4 rocksdb:                Options.report_bg_io_stats: 0
2016-08-23 14:10:49.264217 7f5042644800  4 rocksdb: Recovered from manifest file:db/MANIFEST-000035 succeeded,manifest_file_number is 35, next_file_number is 37, last_sequence is 8, log_number is 0,prev_log_number is 0,max_column_family is 0

2016-08-23 14:10:49.264229 7f5042644800  4 rocksdb: Column family [default] (ID 0), log number is 4

2016-08-23 14:10:49.264274 7f5042644800  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1471961449264269, "job": 1, "event": "recovery_started", "log_files": [6, 9, 12, 15, 18, 21, 24, 27, 30, 33, 36]}
2016-08-23 14:10:49.264279 7f5042644800  4 rocksdb: Recovering log #6 mode 0
2016-08-23 14:10:49.264288 7f5042644800  4 rocksdb: Recovering log #9 mode 0
2016-08-23 14:10:49.264291 7f5042644800  4 rocksdb: Recovering log #12 mode 0
2016-08-23 14:10:49.264295 7f5042644800  4 rocksdb: Recovering log #15 mode 0
2016-08-23 14:10:49.264315 7f5042644800  4 rocksdb: Recovering log #18 mode 0
2016-08-23 14:10:49.264320 7f5042644800  4 rocksdb: Recovering log #21 mode 0
2016-08-23 14:10:49.264322 7f5042644800  4 rocksdb: Recovering log #24 mode 0
2016-08-23 14:10:49.264325 7f5042644800  4 rocksdb: Recovering log #27 mode 0
2016-08-23 14:10:49.264328 7f5042644800  4 rocksdb: Recovering log #30 mode 0
2016-08-23 14:10:49.264330 7f5042644800  4 rocksdb: Recovering log #33 mode 0
2016-08-23 14:10:49.264333 7f5042644800  4 rocksdb: Recovering log #36 mode 0
2016-08-23 14:10:49.264343 7f5042644800  4 rocksdb: Creating manifest 38

2016-08-23 14:10:49.264394 7f5042644800 10 bitmapalloc:reserve instance 139982851982976 num_used 196520 total 204698
2016-08-23 14:10:49.264398 7f5042644800 10 bitmapalloc:alloc_extents instance 139982851982976 want_size 1048576 alloc_unit 1048576 hint 0
2016-08-23 14:10:49.268037 7f5042644800 10 bitmapalloc:reserve instance 139982851982976 num_used 196521 total 204698
2016-08-23 14:10:49.268053 7f5042644800 10 bitmapalloc:alloc_extents instance 139982851982976 want_size 1048576 alloc_unit 1048576 hint 0
2016-08-23 14:10:49.269441 7f5042644800 10 bitmapalloc:release 0xc00000~100000
2016-08-23 14:10:49.269525 7f5042644800  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1471961449269519, "job": 1, "event": "recovery_finished"}
2016-08-23 14:10:49.269601 7f5042644800 10 bitmapalloc:release 0x800000~100000
2016-08-23 14:10:49.269627 7f5042644800 10 bitmapalloc:commit_start instance 139982851982976 releasing 2097152 in extents 2
2016-08-23 14:10:49.270441 7f5042644800 10 bitmapalloc:commit_finish instance 139982851982976 released 2097152 in extents 2
2016-08-23 14:10:49.270462 7f5042644800 20 bitmapalloc:insert_free instance 139982851982976 off 0x800000 len 0x100000
2016-08-23 14:10:49.270468 7f5042644800 20 bitmapalloc:insert_free instance 139982851982976 off 0xc00000 len 0x100000
2016-08-23 14:10:49.270672 7f5042644800 10 bitmapalloc:reserve instance 139982851982976 num_used 196520 total 204698
2016-08-23 14:10:49.270677 7f5042644800 10 bitmapalloc:alloc_extents instance 139982851982976 want_size 1048576 alloc_unit 1048576 hint 0
2016-08-23 14:10:49.273167 7f5042644800 10 bitmapalloc:release 0xb00000~100000
2016-08-23 14:10:49.273183 7f5042644800  4 rocksdb: DB pointer 0x7f504c39b200
2016-08-23 14:10:49.273197 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_db opened rocksdb path db options compression=kNoCompression,max_write_buffer_number=16,min_write_buffer_number_to_merge=3,recycle_log_file_num=16
2016-08-23 14:10:49.273700 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_super_meta old nid_max 0
2016-08-23 14:10:49.273724 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_super_meta freelist_type bitmap
2016-08-23 14:10:49.273732 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_super_meta bluefs_extents 0x[2000~1ffcfe000]
2016-08-23 14:10:49.273744 7f5042644800  1 freelist init
2016-08-23 14:10:49.273779 7f5042644800 10 freelist init blocks 0x31f9b00
2016-08-23 14:10:49.273789 7f5042644800 10 freelist init blocks_per_key 0x80
2016-08-23 14:10:49.273793 7f5042644800 10 freelist init bytes_per_block 0x1000
2016-08-23 14:10:49.273796 7f5042644800 10 freelist init size 0x31f9afb000
2016-08-23 14:10:49.273799 7f5042644800 10 freelist init size 0x31f9afb000 bytes_per_block 0x1000 blocks 0x31f9b00 blocks_per_key 0x80
2016-08-23 14:10:49.273804 7f5042644800 10 freelist _init_misc bytes_per_key 0x80000, key_mask 0xfffffffffff80000
2016-08-23 14:10:49.292674 7f5042644800 10 bitmapalloc:BitMapAllocator instance 139982855689472 size 0x31f9afbe00
2016-08-23 14:10:49.292705 7f5042644800 10 freelist enumerate_next start
2016-08-23 14:10:49.292767 7f5042644800 30 freelist enumerate_next found clear bit, key 0x0 bit 0x2 offset 0x2000
2016-08-23 14:10:49.292770 7f5042644800 30 freelist  no more set bits in 0x0
2016-08-23 14:10:49.292777 7f5042644800 30 freelist enumerate_next found set bit, key 0x31f9a80000 bit 0x7b offset 0x31f9afb000
2016-08-23 14:10:49.292780 7f5042644800 10 freelist enumerate_next 0x2000~31f9af9000
2016-08-23 14:10:49.292782 7f5042644800 10 bitmapalloc:init_add_free instance 139982855689472 offset 0x2000 length 0x31f9af9000
2016-08-23 14:10:49.292783 7f5042644800 20 bitmapalloc:insert_free instance 139982855689472 off 0x2000 len 0x31f9af9000
2016-08-23 14:10:49.377763 7f5042644800 30 freelist  no more clear bits in 0x31f9a80000
2016-08-23 14:10:49.377803 7f5042644800 10 freelist enumerate_next end
2016-08-23 14:10:49.377804 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_alloc loaded 199 G in 1 extents
2016-08-23 14:10:49.377821 7f5042644800 10 bitmapalloc:init_rm_free instance 139982855689472 offset 0x2000 length 0x1ffcfe000
2016-08-23 14:10:49.381245 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _open_alloc marked bluefs_extents 0x[2000~1ffcfe000] as allocated
2016-08-23 14:10:49.420774 7f5042644800  1 bluefs fsck
2016-08-23 14:10:49.420821 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) statfs store_statfs missed, using empty
2016-08-23 14:10:49.420824 7f5042644800 20 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) statfs store_statfs(0x31f8efb000/0x31f9afbe00, stored 0x0/0x0, compress 0x0/0x0/0x0)
2016-08-23 14:10:49.420833 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) fsck checking for stray bnodes and onodes
2016-08-23 14:10:49.420850 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) fsck checking for stray omap data
2016-08-23 14:10:49.420859 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) fsck checking wal events
2016-08-23 14:10:49.420865 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) fsck checking freelist vs allocated
2016-08-23 14:10:49.445577 7f5042644800 10 freelist enumerate_next start
2016-08-23 14:10:49.445610 7f5042644800 30 freelist enumerate_next found clear bit, key 0x0 bit 0x2 offset 0x2000
2016-08-23 14:10:49.445613 7f5042644800 30 freelist  no more set bits in 0x0
2016-08-23 14:10:49.445621 7f5042644800 30 freelist enumerate_next found set bit, key 0x31f9a80000 bit 0x7b offset 0x31f9afb000
2016-08-23 14:10:49.445622 7f5042644800 10 freelist enumerate_next 0x2000~31f9af9000
2016-08-23 14:10:50.436997 7f5042644800 30 freelist  no more clear bits in 0x31f9a80000
2016-08-23 14:10:50.437032 7f5042644800 10 freelist enumerate_next end
2016-08-23 14:10:50.442144 7f5042644800 -1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) fsck leaked some space;4096 bytes leaked
2016-08-23 14:10:50.442173 7f5042644800 10 bitmapalloc:shutdown instance 139982855689472
2016-08-23 14:10:50.450615 7f5042644800 10 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) _close_fm
2016-08-23 14:10:50.450631 7f5042644800  1 freelist shutdown
2016-08-23 14:10:50.450800 7f5042644800  1 bluefs umount
2016-08-23 14:10:50.450805 7f5042644800 10 bitmapalloc:commit_start instance 139982851982976 releasing 1048576 in extents 1
2016-08-23 14:10:50.451845 7f5042644800 10 bitmapalloc:commit_finish instance 139982851982976 released 1048576 in extents 1
2016-08-23 14:10:50.451867 7f5042644800 20 bitmapalloc:insert_free instance 139982851982976 off 0xb00000 len 0x100000
2016-08-23 14:10:50.451879 7f5042644800 10 bitmapalloc:shutdown instance 139982851982976
2016-08-23 14:10:50.452012 7f5042644800  1 bdev(/var/lib/ceph/tmp/mnt.yHSJud/block) close
2016-08-23 14:10:50.707943 7f5042644800  1 bdev(/var/lib/ceph/tmp/mnt.yHSJud/block) close
2016-08-23 14:10:50.780989 7f5042644800  1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) fsck finish with 1 errors
2016-08-23 14:10:50.781294 7f5042644800 -1 bluestore(/var/lib/ceph/tmp/mnt.yHSJud) mount fsck found 1 errors
2016-08-23 14:10:50.781301 7f5042644800 -1 OSD::mkfs: couldn't mount ObjectStore: error -5
2016-08-23 14:10:50.781339 7f5042644800 -1 [0;31m ** ERROR: error creating empty object store in /var/lib/ceph/tmp/mnt.yHSJud: (5) Input/output error[0m
Actions #8

Updated by Loïc Dachary over 7 years ago

  • Status changed from Fix Under Review to In Progress
  • Assignee changed from Loïc Dachary to Sage Weil
Actions #9

Updated by Loïc Dachary over 7 years ago

  • Status changed from In Progress to Fix Under Review
Actions #10

Updated by Sage Weil over 7 years ago

  • Priority changed from Normal to Urgent
Actions #11

Updated by Loïc Dachary over 7 years ago

  • Status changed from Fix Under Review to Resolved
Actions

Also available in: Atom PDF