Bug #43904: bluefs _replay invalid extent 1: 0x9d4a2a000~100000: already given (on upgrade) - bluestore - Ceph

Custom queries

Bug queue
Bug triage
Crash queue
Crash triage
Feedback
My issues
Need Review
Pending backports
Product Backlog Scrub

Actions

Copy link

Bug #43904

closed

bluefs _replay invalid extent 1: 0x9d4a2a000~100000: already given (on upgrade)

Added by Sage Weil over 4 years ago. Updated about 4 years ago.

Status:

Resolved

Priority:

Urgent

Assignee:

Target version:

% Done:

Source:

Tags:

Backport:

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Pull request ID:

33027

Crash signature (v1):

Crash signature (v2):

Description

...
2020-01-30T08:54:14.065-0600 7f791b1a0d80 10 fbmap_alloc 0x561c241ce700 init_add_free 0x9d3d0a000~100000
2020-01-30T08:54:14.065-0600 7f791b1a0d80 10 fbmap_alloc 0x561c241ce700 init_add_free done
2020-01-30T08:54:14.065-0600 7f791b1a0d80 10 fbmap_alloc 0x561c241ce700 init_add_free 0x9d4929000~100000
2020-01-30T08:54:14.065-0600 7f791b1a0d80 10 fbmap_alloc 0x561c241ce700 init_add_free done
2020-01-30T08:54:14.065-0600 7f791b1a0d80 10 fbmap_alloc 0x561c241ce700 init_add_free 0x9d4a2a000~100000
2020-01-30T08:54:14.065-0600 7f791b1a0d80 10 fbmap_alloc 0x561c241ce700 init_add_free done
2020-01-30T08:54:14.065-0600 7f791b1a0d80 -1 bluefs _replay invalid extent 1: 0x9d4a2a000~100000: already given
2020-01-30T08:54:14.065-0600 7f791b1a0d80 -1 bluefs mount failed to replay log: (14) Bad address
2020-01-30T08:54:14.065-0600 7f791b1a0d80  1 fbmap_alloc 0x561c241ce700 shutdown
2020-01-30T08:54:14.069-0600 7f791b1a0d80 -1 bluestore(/var/lib/ceph/osd/ceph-9) _open_bluefs failed bluefs mount: (14) Bad address
2020-01-30T08:54:14.069-0600 7f791b1a0d80  1 bdev(0x561c24ea8000 /var/lib/ceph/osd/ceph-9/block) close
2020-01-30T08:54:14.377-0600 7f791b1a0d80 -1 osd.9 0 OSD:init: unable to mount object store
2020-01-30T08:54:14.377-0600 7f791b1a0d80 -1 ESC[0;31m ** ERROR: osd init failed: (14) Bad addressESC[0m

this cluster started with kraken and has been upgraded all the way (now) to octopus. the oldest bluestores crash this way; newer ones are fine.

History
Notes
Property changes

Actions

Copy link

Updated by Sage Weil over 4 years ago

2020-01-30T08:54:36.237-0600 7f15413abd80  0 ceph version 15.0.0-10068-g06c3344 (06c3344aefdb0609884137d53815d75eeb19882f) octopus (rc), process ceph-osd, pid 2479197
2020-01-30T08:54:36.237-0600 7f15413abd80  0 pidfile_write: ignore empty --pid-file
2020-01-30T08:54:36.237-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9) set_cache_shards 1
2020-01-30T08:54:36.237-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bdev create path /var/lib/ceph/osd/ceph-9/block type kernel
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) open path /var/lib/ceph/osd/ceph-9/block
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) open size 1024103616512 (0xee71551000, 954 GiB) block_size 4096 (4 KiB) non-rotational discard supported
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.241-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bluestore(/var/lib/ceph/osd/ceph-9) _set_cache_sizes cache_size 3221225472 meta 0.4 kv 0.4 data 0.2
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bdev create path /var/lib/ceph/osd/ceph-9/block type kernel
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bdev(0x559ad0c5e380 /var/lib/ceph/osd/ceph-9/block) open path /var/lib/ceph/osd/ceph-9/block
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bdev(0x559ad0c5e380 /var/lib/ceph/osd/ceph-9/block) open size 1024103616512 (0xee71551000, 954 GiB) block_size 4096 (4 KiB) non-rotational discard supported
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-9/block size 954 GiB
2020-01-30T08:54:36.241-0600 7f15413abd80  1 bdev(0x559ad0c5e380 /var/lib/ceph/osd/ceph-9/block) close
2020-01-30T08:54:36.593-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) close
2020-01-30T08:54:36.801-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9) get_numa_node bdev sdd can't detect numa_node
2020-01-30T08:54:36.801-0600 7f15413abd80  0 starting osd.9 osd_data /var/lib/ceph/osd/ceph-9 /var/lib/ceph/osd/ceph-9/journal
2020-01-30T08:54:36.801-0600 7f15413abd80 -1 Falling back to public interface
2020-01-30T08:54:36.813-0600 7f15413abd80  0 load: jerasure load: lrc load: isa 
2020-01-30T08:54:36.813-0600 7f15413abd80  1 bdev create path /var/lib/ceph/osd/ceph-9/block type kernel
2020-01-30T08:54:36.813-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) open path /var/lib/ceph/osd/ceph-9/block
2020-01-30T08:54:36.813-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) open size 1024103616512 (0xee71551000, 954 GiB) block_size 4096 (4 KiB) non-rotational discard supported
2020-01-30T08:54:36.813-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.813-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.813-0600 7f15413abd80  1 bluestore(/var/lib/ceph/osd/ceph-9) _set_cache_sizes cache_size 3221225472 meta 0.4 kv 0.4 data 0.2
2020-01-30T08:54:36.813-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) close
2020-01-30T08:54:36.937-0600 7f15413abd80  0 osd.9:0.OSDShard using op scheduler ClassedOpQueueScheduler(queue=WeightedPriorityQueue, cutoff=196)
2020-01-30T08:54:36.937-0600 7f15413abd80  0 osd.9:1.OSDShard using op scheduler ClassedOpQueueScheduler(queue=WeightedPriorityQueue, cutoff=196)
2020-01-30T08:54:36.937-0600 7f15413abd80  0 osd.9:2.OSDShard using op scheduler ClassedOpQueueScheduler(queue=WeightedPriorityQueue, cutoff=196)
2020-01-30T08:54:36.937-0600 7f15413abd80  0 osd.9:3.OSDShard using op scheduler ClassedOpQueueScheduler(queue=WeightedPriorityQueue, cutoff=196)
2020-01-30T08:54:36.937-0600 7f15413abd80  0 osd.9:4.OSDShard using op scheduler ClassedOpQueueScheduler(queue=WeightedPriorityQueue, cutoff=196)
2020-01-30T08:54:36.937-0600 7f15413abd80  0 osd.9:5.OSDShard using op scheduler ClassedOpQueueScheduler(queue=WeightedPriorityQueue, cutoff=196)
2020-01-30T08:54:36.937-0600 7f15413abd80  0 osd.9:6.OSDShard using op scheduler ClassedOpQueueScheduler(queue=WeightedPriorityQueue, cutoff=196)
2020-01-30T08:54:36.937-0600 7f15413abd80  0 osd.9:7.OSDShard using op scheduler ClassedOpQueueScheduler(queue=WeightedPriorityQueue, cutoff=196)
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9) set_cache_shards 32
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bluestore(/var/lib/ceph/osd/ceph-9) _mount path /var/lib/ceph/osd/ceph-9
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bdev create path /var/lib/ceph/osd/ceph-9/block type kernel
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) open path /var/lib/ceph/osd/ceph-9/block
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) open size 1024103616512 (0xee71551000, 954 GiB) block_size 4096 (4 KiB) non-rotational discard supported
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bluestore(/var/lib/ceph/osd/ceph-9) _set_cache_sizes cache_size 3221225472 meta 0.4 kv 0.4 data 0.2
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9) _open_db kv_backend = rocksdb
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9/block) _read_bdev_label got bdev(osd_uuid 09f5acc9-3013-4706-a60c-9b8b23edc58c, size 0xee71551000, btime 2016-12-30T13:29:49.379488-0600, desc main, 1 meta)
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9) _open_db do_bluefs = 1
2020-01-30T08:54:36.937-0600 7f15413abd80 10 bluestore(/var/lib/ceph/osd/ceph-9) _open_db initializing bluefs
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bdev create path /var/lib/ceph/osd/ceph-9/block type kernel
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bdev(0x559ad0c5e380 /var/lib/ceph/osd/ceph-9/block) open path /var/lib/ceph/osd/ceph-9/block
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bdev(0x559ad0c5e380 /var/lib/ceph/osd/ceph-9/block) open size 1024103616512 (0xee71551000, 954 GiB) block_size 4096 (4 KiB) non-rotational discard supported
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-9/block size 954 GiB
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bluefs mount
2020-01-30T08:54:36.937-0600 7f15413abd80  1 bluefs _init_alloc id 1 alloc_size 0x10000 size 0xee71551000
2020-01-30T08:54:36.937-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 BitmapAllocator 0xee71551000/10000
2020-01-30T08:54:36.945-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x2000~989bfe000
2020-01-30T08:54:36.945-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x989d05000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x98a216000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x98c2c9000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x98d50e000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x98ed90000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9935c9000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x99427f000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x995274000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x99625a000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x999cff000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x99bcff000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x99d90e000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x99dec4000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x99f94e000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a2502000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a3182000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a3dff000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a4000000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a4d43000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a5001000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a5801000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a8902000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a8c00000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a8e40000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a91df000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9a963b000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9addc7000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9aec62000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9af5be000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9af8a2000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9afe44000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b0000000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b05cb000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b06d8000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b0800000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b0a38000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b0c00000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b2401000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b3556000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b4841000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9b8963000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9baed1000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9bb109000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9be17d000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9beeac000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9bf000000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9bf10a000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9bfef3000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c0ac8000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c1933000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c2eae000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c453a000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c68a0000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c6d18000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c712c000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c8247000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c8400000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c893d000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9c8eb1000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9cb84f000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9cbc00000~200000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9ce805000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9cec00000~300000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9d3d0a000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9d4929000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free 0x9d4a2a000~100000
2020-01-30T08:54:36.953-0600 7f15413abd80 10 fbmap_alloc 0x559acff58700 init_add_free done
2020-01-30T08:54:36.953-0600 7f15413abd80 -1 bluefs _replay invalid extent 1: 0x9d4a2a000~100000: already given
2020-01-30T08:54:36.957-0600 7f15413abd80 -1 bluefs mount failed to replay log: (14) Bad address
2020-01-30T08:54:36.957-0600 7f15413abd80  1 fbmap_alloc 0x559acff58700 shutdown
2020-01-30T08:54:36.957-0600 7f15413abd80 -1 bluestore(/var/lib/ceph/osd/ceph-9) _open_bluefs failed bluefs mount: (14) Bad address
2020-01-30T08:54:36.957-0600 7f15413abd80  1 bdev(0x559ad0c5e000 /var/lib/ceph/osd/ceph-9/block) close
2020-01-30T08:54:37.265-0600 7f15413abd80 -1 osd.9 0 OSD:init: unable to mount object store
2020-01-30T08:54:37.265-0600 7f15413abd80 -1  ** ERROR: osd init failed: (14) Bad address

Actions

Copy link

Updated by Igor Fedotov over 4 years ago

What I don't like for this log is a mismatch between reported allocation size (0x10000) and allocated extent alignments (which seems to be 0x1000):

fbmap_alloc 0x559acff58700 BitmapAllocator 0xee71551000/10000

...
fbmap_alloc 0x559acff58700 init_add_free 0x9d4a2a000~100000

Actions

Copy link

Updated by Igor Fedotov over 4 years ago

bluefs allocations validation has been introduced recently by https://github.com/ceph/ceph/pull/31513

So looks like a mismatch between some old allocation scheme and current estimations...

Actions

Copy link

Updated by Igor Fedotov over 4 years ago

like at some past point we didn't care about 64K/1M alignment while gifting to bluefs..

Actions

Copy link

Updated by Igor Fedotov over 4 years ago

The only workaround I can think of is to disable bluefs_log_replay_check_allocations and(!) switch bluefs allocator back to stupid or avl one. Need to check how they handle such a mismatch though....

Actions

Copy link

Updated by Sage Weil over 4 years ago

I think the root problem is that the alloc unit was 64k (bluefs_shared_alloc_size=64k) but there was a more granular allocation in there. I was able to work around this by setting bluefs_shared_alloc=4k.

That check aside, is it permissible to have existing granular allocations and to set the shared_alloc_size larger? (Does that only impact allocations going forward?) If so, it's just the verification that needs a fix.

Otherwise.. I think maybe it needs to scan the log for the op_alloc_add events and pick the min of the granularity it finds and the configured alloc_size?

Actions

Copy link

Updated by Igor Fedotov over 4 years ago

Sage Weil wrote:

I think the root problem is that the alloc unit was 64k (bluefs_shared_alloc_size=64k) but there was a more granular allocation in there.

Not exactly - it's gifted extent offsets which has 4K granularity in this log. Which means it's main bluestore allocator who did that. And underlying flash drive means 4K min alloc size for main allocator and I assume old days (btw not sure about current behavior) stupid one could 'gift' space with no respect to bluefs 1MB boundaries. I recall I did relevant fixes a while ago for bitmap allocator...

I was able to work around this by setting bluefs_shared_alloc=4k.

Yeah this would work with some perf penalties. AFAIR we had some when did benchmarking after downgrading bluefs alloc size.

That check aside, is it permissible to have existing granular allocations and to set the shared_alloc_size larger? (Does that only impact allocations going forward?) If so, it's just the verification that needs a fix.

No, not for bitmap allocator at least. If I understand correctly that's what you've got initially. Bitmap might improperly clean corresponding bit while doing 'partial' release and hence eventually cause existing data overwrite.
Hence the new validation on startup.

Otherwise.. I think maybe it needs to scan the log for the op_alloc_add events and pick the min of the granularity it finds and the configured alloc_size?

yeah, that's probably doable. But then we'll need a performance warning or something and finally recommend users to redeploy.

Actions

Copy link

Updated by Igor Fedotov over 4 years ago

BTW just realized that this issue coupled by the lack of bluefs allocations validation on startup (i.e. Luminous to Nautilus releases ) is a real candidate to cause DB corruptions (read checksum failures)....

Actions

Copy link