Actions
Bug #52259
closedunittest-staged-fltree fails
% Done:
0%
Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
... DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - BtreeLBAManager::get_root: reading root at paddr_t<0, 8192> depth 1 DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - get_lba_btree_extent: reading leaf at offset paddr_t<0, 8192>, depth 1 DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - get_lba_btree_extent: read leaf at offset paddr_t<0, 8192> CachedExtent(addr=0x601000a9c780, type=LADDR_LEAF, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<0, 8192>, state=DIRTY, last_committed_crc=326493981, refcount=4, size=1, meta=btree_node_meta_t(begin=0, end=18446744073709551615, depth=1)), parent CachedExtent(addr=0x601000176e00, type=ROOT, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<NULL_SEG, NULL_OFF>, state=DIRTY, last_committed_crc=0, refcount=7) DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - LBALeafNode::lookup_pin 0 DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - BtreeLBAManager::get_mapping: got mapping LBAPin(0~16384->paddr_t<1, 8192> DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - TransactionManager::pin_to_extent(0x601000858140): getting extent LBAPin(0~16384->paddr_t<1, 8192> DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - TransactionManager::pin_to_extent(0x601000858140): got extent CachedExtent(addr=0x601000b56d00, type=ONODE_BLOCK_STAGED, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=850290427, refcount=3, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - OTree::LeafNode::insert_value(0x601000858140): insert NodeL0@0x0+4000Lv0$ with insert_key=key_hobj(4,4,4; "ns7_..__/128B","oid7..__/13B"; 3,3), insert_value=ValueConf(TEST_EXTENDED, 989B), insert_pos(END, END, END), history=history(EQ, GT, --), mstat(-2) ... DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - OTree::Seastore(0x601000858140): mutate CachedExtent(addr=0x601000b56d00, type=ONODE_BLOCK_STAGED, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=850290427, refcount=3, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) ... DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - Cache::duplicate_for_write(0x601000858140): CachedExtent(addr=0x601000b56d00, type=ONODE_BLOCK_STAGED, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=850290427, refcount=6, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) -> CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=850290427, refcount=2, laddr=18446744073709551615, pin=empty, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - TransactionManager::get_mutable_extent(0x601000858140): duplicating CachedExtent(addr=0x601000b56d00, type=ONODE_BLOCK_STAGED, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=850290427, refcount=5, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) for write: CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=850290427, refcount=2, laddr=18446744073709551615, pin=empty, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - OTree::Layout::insert: begin at insert_pos(LAST, END, END), insert_stage=1, insert_size=1159B ... DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - OTree::Extent::Replay: decoding INSERT ... DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - OTree::Extent::Replay: apply key_hobj(4,4,4; "ns7_..__/128B","oid7..__/13B"; 3,3), ValueConf(TEST_EXTENDED, 989B), insert_pos(LAST, END, END), insert_stage=1, insert_size=1159B ... DEBUG 2021-08-14 02:38:09,351 [shard 0] seastore - OTree::Layout::insert: done at insert_pos(0, 1, 0), insert_stage=1, insert_size=1159B DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - TransactionManager::submit_transaction(0x601000858140): about to await throttle DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - SegmentCleaner::log_gc_state(await_hard_limits): total 1073741824, available 1065328640, unavailable 8413184, used 20480, reclaimable 0, reclaim_ratio 0.0, available_ratio 0.9921646118164062, should_block_on_gc false, gc_should_reclaim_space false, journal_head journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), journal_tail_target journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), dirty_tail journal_seq_t(segment_seq=0, offset=paddr_t<1, 24576>), dirty_tail_limit journal_seq_t(segment_seq=0, offset=paddr_t<1, 24576>), gc_should_trim_journal false, DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - TransactionManager::submit_transaction_direct(0x601000858140): about to prepare DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - Cache::prepare_record(0x601000858140): enter DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - Cache::prepare_record(0x601000858140): read_set validated DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - Cache::prepare_record(0x601000858140): mutating CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=850290427, refcount=1, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - Cache::replace_extent: prev CachedExtent(addr=0x601000b56d00, type=ONODE_BLOCK_STAGED, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=850290427, refcount=3, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)), next CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=850290427, refcount=2, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - Cache::invalidate: invalidate begin -- extent CachedExtent(addr=0x601000b56d00, type=ONODE_BLOCK_STAGED, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=850290427, refcount=2, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - Cache::invalidate: invalidate end DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - TransactionManager::submit_transaction_direct(0x601000858140): about to submit to journal DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - write_record, mdlength 4096, dlength 0, target 28672 DEBUG 2021-08-14 02:38:09,352 [shard 0] seastore - segment_write to segment 1 at offset 28672, physical offset 8417280, len 4096, crc 335995726 DEBUG 2021-08-14 02:38:09,376 [shard 0] seastore - write_record: commit target 28672 DEBUG 2021-08-14 02:38:09,376 [shard 0] seastore - TransactionManager::submit_transaction_direct(0x601000858140): journal commit to paddr_t<1, 32768> seq journal_seq_t(segment_seq=1, offset=paddr_t<1, 28672>) DEBUG 2021-08-14 02:38:09,376 [shard 0] seastore - Cache::complete_commit(0x601000858140): enter DEBUG 2021-08-14 02:38:09,376 [shard 0] seastore - Cache::complete_commit(0x601000858140): mutated CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=1625198013, refcount=2, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,376 [shard 0] seastore - update_journal_tail_target: journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - SegmentCleaner::log_gc_state(GCProcess::run_until_halt): total 1073741824, available 1065324544, unavailable 8417280, used 20480, reclaimable 0, reclaim_ratio 0.0, available_ratio 0.9921607971191406, should_block_on_gc false, gc_should_reclaim_space false, journal_head journal_seq_t(segment_seq=1, offset=paddr_t<1, 28672>), journal_tail_target journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), dirty_tail journal_seq_t(segment_seq=0, offset=paddr_t<1, 28672>), dirty_tail_limit journal_seq_t(segment_seq=0, offset=paddr_t<1, 28672>), gc_should_trim_journal false, DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - Cache::create_transaction(0x601000858140): created source=MUTATE DEBUG 2021-08-14 02:38:09,377 [shard 0] test - [2] insert key_hobj(7,7,7; "ns6_..__/255B","oid6..__/2048B"; 0,0) -> TestItem(#4, 992B) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - Cache::get_root(0x601000858140): waiting root CachedExtent(addr=0x601000176e00, type=ROOT, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<NULL_SEG, NULL_OFF>, state=DIRTY, last_committed_crc=0, refcount=3) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - Cache::get_root(0x601000858140): got root read CachedExtent(addr=0x601000176e00, type=ROOT, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<NULL_SEG, NULL_OFF>, state=DIRTY, last_committed_crc=0, refcount=4) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - BtreeLBAManager::get_mapping: 0 DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - Cache::get_root(0x601000858140): root already on transaction CachedExtent(addr=0x601000176e00, type=ROOT, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<NULL_SEG, NULL_OFF>, state=DIRTY, last_committed_crc=0, refcount=4) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - BtreeLBAManager::get_root: reading root at paddr_t<0, 8192> depth 1 DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - get_lba_btree_extent: reading leaf at offset paddr_t<0, 8192>, depth 1 DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - get_lba_btree_extent: read leaf at offset paddr_t<0, 8192> CachedExtent(addr=0x601000a9c780, type=LADDR_LEAF, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<0, 8192>, state=DIRTY, last_committed_crc=326493981, refcount=4, size=1, meta=btree_node_meta_t(begin=0, end=18446744073709551615, depth=1)), parent CachedExtent(addr=0x601000176e00, type=ROOT, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<NULL_SEG, NULL_OFF>, state=DIRTY, last_committed_crc=0, refcount=7) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - LBALeafNode::lookup_pin 0 DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - BtreeLBAManager::get_mapping: got mapping LBAPin(0~16384->paddr_t<1, 8192> DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - TransactionManager::pin_to_extent(0x601000858140): getting extent LBAPin(0~16384->paddr_t<1, 8192> DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - TransactionManager::pin_to_extent(0x601000858140): got extent CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=1625198013, refcount=3, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - OTree::LeafNode::insert_value(0x601000858140): insert NodeL0@0x0+4000Lv0$ with insert_key=key_hobj(7,7,7; "ns6_..__/255B","oid6..__/2048B"; 0,0), insert_value=ValueConf(TEST_EXTENDED, 989B), insert_pos(END, END, END), history=history(GT, --, --), mstat(-2) ... DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - OTree::Seastore(0x601000858140): mutate CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=1625198013, refcount=3, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) ... DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - Cache::duplicate_for_write(0x601000858140): CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=1625198013, refcount=6, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) -> CachedExtent(addr=0x601000b56c00, type=ONODE_BLOCK_STAGED, version=3, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=1625198013, refcount=2, laddr=18446744073709551615, pin=empty, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - TransactionManager::get_mutable_extent(0x601000858140): duplicating CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=1625198013, refcount=5, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) for write: CachedExtent(addr=0x601000b56c00, type=ONODE_BLOCK_STAGED, version=3, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=1625198013, refcount=2, laddr=18446744073709551615, pin=empty, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - OTree::Layout::insert: begin at insert_pos(END, END, END), insert_stage=2, insert_size=3336B ... DEBUG 2021-08-14 02:38:09,377 [shard 0] seastore - OTree::Extent::Replay: decoding INSERT ... DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - OTree::Extent::Replay: apply key_hobj(7,7,7; "ns6_..__/255B","oid6..__/2048B"; 0,0), ValueConf(TEST_EXTENDED, 989B), insert_pos(END, END, END), insert_stage=2, insert_size=3336B ... DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - OTree::Layout::insert: done at insert_pos(1, 0, 0), insert_stage=2, insert_size=3336B DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - TransactionManager::submit_transaction(0x601000858140): about to await throttle DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - SegmentCleaner::log_gc_state(await_hard_limits): total 1073741824, available 1065324544, unavailable 8417280, used 20480, reclaimable 0, reclaim_ratio 0.0, available_ratio 0.9921607971191406, should_block_on_gc false, gc_should_reclaim_space false, journal_head journal_seq_t(segment_seq=1, offset=paddr_t<1, 28672>), journal_tail_target journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), dirty_tail journal_seq_t(segment_seq=0, offset=paddr_t<1, 28672>), dirty_tail_limit journal_seq_t(segment_seq=0, offset=paddr_t<1, 28672>), gc_should_trim_journal false, DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - TransactionManager::submit_transaction_direct(0x601000858140): about to prepare DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - Cache::prepare_record(0x601000858140): enter DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - Cache::prepare_record(0x601000858140): read_set validated DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - Cache::prepare_record(0x601000858140): mutating CachedExtent(addr=0x601000b56c00, type=ONODE_BLOCK_STAGED, version=3, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=1625198013, refcount=1, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - Cache::replace_extent: prev CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=1625198013, refcount=3, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)), next CachedExtent(addr=0x601000b56c00, type=ONODE_BLOCK_STAGED, version=3, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=1625198013, refcount=2, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - Cache::invalidate: invalidate begin -- extent CachedExtent(addr=0x6010009cdd00, type=ONODE_BLOCK_STAGED, version=2, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=DIRTY, last_committed_crc=1625198013, refcount=2, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - Cache::invalidate: invalidate end DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - TransactionManager::submit_transaction_direct(0x601000858140): about to submit to journal DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - write_record, mdlength 4096, dlength 0, target 32768 DEBUG 2021-08-14 02:38:09,378 [shard 0] seastore - segment_write to segment 1 at offset 32768, physical offset 8421376, len 4096, crc 530964746 DEBUG 2021-08-14 02:38:09,379 [shard 0] seastore - write_record: commit target 32768 DEBUG 2021-08-14 02:38:09,379 [shard 0] seastore - TransactionManager::submit_transaction_direct(0x601000858140): journal commit to paddr_t<1, 36864> seq journal_seq_t(segment_seq=1, offset=paddr_t<1, 32768>) DEBUG 2021-08-14 02:38:09,379 [shard 0] seastore - Cache::complete_commit(0x601000858140): enter DEBUG 2021-08-14 02:38:09,379 [shard 0] seastore - Cache::complete_commit(0x601000858140): mutated CachedExtent(addr=0x601000b56c00, type=ONODE_BLOCK_STAGED, version=3, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 24576>), paddr=paddr_t<1, 8192>, state=MUTATION_PENDING, last_committed_crc=1313456216, refcount=2, laddr=0, pin=LBAPin(0~16384->paddr_t<1, 8192>, fltree_header=headerL0(is_level_tail=1, level=0)) DEBUG 2021-08-14 02:38:09,379 [shard 0] seastore - update_journal_tail_target: journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>) DEBUG 2021-08-14 02:38:09,379 [shard 0] seastore - SegmentCleaner::log_gc_state(GCProcess::run_until_halt): total 1073741824, available 1065320448, unavailable 8421376, used 20480, reclaimable 0, reclaim_ratio 0.0, available_ratio 0.992156982421875, should_block_on_gc false, gc_should_reclaim_space false, journal_head journal_seq_t(segment_seq=1, offset=paddr_t<1, 32768>), journal_tail_target journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), dirty_tail journal_seq_t(segment_seq=0, offset=paddr_t<1, 32768>), dirty_tail_limit journal_seq_t(segment_seq=0, offset=paddr_t<1, 32768>), gc_should_trim_journal false, DEBUG 2021-08-14 02:38:09,380 [shard 0] seastore - Cache::create_transaction(0x601000858140): created source=MUTATE DEBUG 2021-08-14 02:38:09,380 [shard 0] test - [3] insert key_hobj(1,1,1; "ns3_..__/255B","oid3____"; 2,2) -> TestItem(#3, 576B) DEBUG 2021-08-14 02:38:09,380 [shard 0] seastore - OTree::Seastore(0x601000858140): get root: trigger eagain unittest-staged-fltree: ../src/crimson/os/seastore/onode_manager/staged-fltree/node.cc:420: crimson::os::seastore::onode::Node::load_root(crimson::os::seastore::onode::context_t, crimson::os::seastore::onode::RootNodeTracker&)::<lambda(auto:115&&)> [with auto:115 = std::unique_ptr<crimson::os::seastore::onode::Super>]: Assertion `_super' failed. Aborting on shard 0. ...
Files
Updated by Kefu Chai over 2 years ago
- File consoleText.bz2 consoleText.bz2 added
Updated by Kefu Chai over 2 years ago
- Priority changed from Normal to Urgent
bin/unittest-staged-fltree --gtest_filter=d_seastore_tm_test_t.7_tree_insert_erase_eagain ... DEBUG 2021-08-14 13:26:57,299 [shard 0] seastore - Cache::create_transaction(0x601000028640): created source=MUTATE DEBUG 2021-08-14 13:26:57,299 [shard 0] test - [7] insert key_hobj(7,7,7; "ns3_..__/256B","oid3..__/13B"; 1,1) -> TestItem(#4, 992B) DEBUG 2021-08-14 13:26:57,299 [shard 0] seastore - Cache::get_root(0x601000028640): waiting root CachedExtent(addr=0x601000067300, type=ROOT, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<NULL_SEG, NULL_OFF>, state=DIRTY, last_committed_crc=0, refcount=3) DEBUG 2021-08-14 13:26:57,299 [shard 0] seastore - Cache::get_root(0x601000028640): got root read CachedExtent(addr=0x601000067300, type=ROOT, version=1, dirty_from_or_retired_at=journal_seq_t(segment_seq=1, offset=paddr_t<1, 4096>), paddr=paddr_t<NULL_SEG, NULL_OFF>, state=DIRTY, last_committed_crc=0, refcount=4) DEBUG 2021-08-14 13:26:57,299 [shard 0] seastore - OTree::Seastore(0x601000028640): reading at 0x0: trigger eagain unittest-staged-fltree: ../src/crimson/os/seastore/onode_manager/staged-fltree/node.cc:703: auto crimson::os::seastore::onode::Node::load(crimson::os::seastore::onode::context_t, crimson::os::seastore::laddr_t, bool)::(anonymous class)::operator()(auto) const [extent:auto = boost::intrusive_ptr<crimson::os::seastore::onode::NodeExtent>]: Assertion `extent' failed. Aborting on shard 0.
Updated by Kefu Chai over 2 years ago
$ bin/unittest-staged-fltree --gtest_filter=d_seastore_tm_test_t.7_tree_insert_erase_eagain --log-to-stdout 0 --memory 256M --smp 1 Note: Google Test filter = d_seastore_tm_test_t.7_tree_insert_erase_eagain [==========] Running 1 test from 1 test suite. [----------] Global test environment set-up. [----------] 1 test from d_seastore_tm_test_t [ RUN ] d_seastore_tm_test_t.7_tree_insert_erase_eagain unittest-staged-fltree: ../src/crimson/os/seastore/onode_manager/staged-fltree/node.cc:420: auto crimson::os::seastore::onode::Node::load_root(crimson::os::seastore::onode::context_t, crimson::os::seastore::onode::RootNodeTracker &)::(anonymous class)::operator()(auto &&) const [_super:auto = std::unique_ptr<crimson::os::seastore::onode::Super, std::default_delete<crimson::os::seastore::onode::Super> >]: Assertion `_super' failed. Aborting on shard 0. Backtrace: 0x2adc9b5 0x2b12fb0 0x7ff5b740f3bf /lib/x86_64-linux-gnu/libc.so.6+0x4618a /lib/x86_64-linux-gnu/libc.so.6+0x25858 /lib/x86_64-linux-gnu/libc.so.6+0x25728 /lib/x86_64-linux-gnu/libc.so.6+0x36f35
auto seastar::futurize_invoke<crimson::interruptible::interruptible_future_detail<crimson::os::seastore::TransactionConflictCondition, crimson::errorator<crimson::unthrowable_wrapper<std::error_code const&, crimson::ec<(std::errc)5> > >::_future<crimson::errorated_future_marker<std::pair<crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::Cursor, bool> > > > (*&)(crimson::os::seastore::onode::key_hobj_t&&, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::insert(crimson::os::seastore::Transaction&, ghobject_t const&, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::tree_value_config_t)::{lambda(auto:1&)#1}&&), crimson::os::seastore::onode::key_hobj_t, {lambda(auto:1&)#1}>(crimson::interruptible::interruptible_future_detail<crimson::os::seastore::TransactionConflictCondition, crimson::errorator<crimson::unthrowable_wrapper<std::error_code const&, crimson::ec<(std::errc)5> > >::_future<crimson::errorated_future_marker<std::pair<crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::Cursor, bool> > > > (*&)(crimson::os::seastore::onode::key_hobj_t&&, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::insert(crimson::os::seastore::Transaction&, ghobject_t const&, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::tree_value_config_t)::{lambda(auto:1&)#1}&&), crimson::os::seastore::onode::key_hobj_t&&, {lambda(auto:1&)#1}&&) at ??:?
auto seastar::do_with<crimson::os::seastore::onode::key_hobj_t, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::insert(crimson::os::seastore::Transaction&, ghobject_t const&, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::tree_value_config_t)::{lambda(auto:1&)#1}>(crimson::os::seastore::onode::key_hobj_t&&, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::insert(crimson::os::seastore::Transaction&, ghobject_t const&, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::tree_value_config_t)::{lambda(auto:1&)#1}&&) at ??:?
crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::insert(crimson::os::seastore::Transaction&, ghobject_t const&, crimson::os::seastore::onode::Btree<crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::tree_value_config_t) at ??:?
crimson::os::seastore::onode::TreeBuilder<false, crimson::os::seastore::onode::TestValue<(crimson::os::seastore::onode::value_magic_t)85, (unsigned short)256, (unsigned short)2048, (unsigned short)1200, 8192u, 16384u, true> >::insert_one(crimson::os::seastore::Transaction&, __gnu_cxx::__normal_iterator<crimson::os::seastore::onode::KVPool<crimson::os::seastore::onode::test_item_t>::kv_t**, std::vector<crimson::os::seastore::onode::KVPool<crimson::os::seastore::onode::test_item_t>::kv_t*, std::allocator<crimson::os::seastore::onode::KVPool<crimson::os::seastore::onode::test_item_t>::kv_t*> > > const&) at ??:?
Updated by chunmei liu over 2 years ago
Is is caused by alloc_extent hint PR? if so, then already fixed it in the PR. the unit test run success locally, please check it.
oh, seems not this one, I meet another bug caused by my PR, but my PR is not merged in, I didn't meet this bug locally, Let Yingxin take a look on it.
Updated by Kefu Chai over 2 years ago
neither can i reproduce this issue in following environments
- debian sid + clang 13
- centos 8.4 + gcc 10
but i can reproduce it with
- ubuntu 20.04 + clang 10
- ubuntu 20.04 + clang 13
- ubuntu 20.04 + gcc 9
in which, "ubuntu 20.04 + gcc 9" is used in our jenkins test nodes.
Updated by Yingxin Cheng over 2 years ago
This shows that there might be issues in interruptive-future implementation. https://github.com/ceph/ceph/pull/42781
Updated by Yingxin Cheng over 2 years ago
- Related to Bug #52275: Interruptive future is not working added
Actions