Project

General

Profile

Bug #40520

snap_mapper record resurrected: trim_object: Can not trim 3:205afc9d:::smithi13915600-489:124 repair needed (no obc)

Added by Sage Weil almost 5 years ago. Updated over 3 years ago.

Status:
Can't reproduce
Priority:
Normal
Assignee:
-
Target version:
-
% 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

2019-06-22T02:14:23.262+0000 7f7dfd3d9700 20 bluestore(/var/lib/ceph/osd/ceph-7) _record_onode onode #3:205afc9d:::smithi13915600-489:124# is 386 (384 bytes onode + 2 bytes spanning blobs + 0 bytes inline extents)
2019-06-22T02:14:29.293+0000 7f7e013e1700 15 bluestore(/var/lib/ceph/osd/ceph-7) _setattrs 3.0_head #3:205afc9d:::smithi13915600-489:124# 1 keys
2019-06-22T02:14:29.293+0000 7f7e013e1700 10 bluestore(/var/lib/ceph/osd/ceph-7) _setattrs 3.0_head #3:205afc9d:::smithi13915600-489:124# 1 keys = 0
2019-06-22T02:14:29.293+0000 7f7e013e1700 20 bluestore.extentmap(0x104a5dd0) update #3:205afc9d:::smithi13915600-489:124#
2019-06-22T02:14:29.293+0000 7f7e013e1700 20 bluestore(/var/lib/ceph/osd/ceph-7) _record_onode onode #3:205afc9d:::smithi13915600-489:124# is 386 (384 bytes onode + 2 bytes spanning blobs + 0 bytes inline extents)

then the ceph-objectstore-tool removes it,
remote/smithi097/log/objectstore_tool.22875.log.gz:2019-06-22T02:16:29.837+0000 7f5c3a86e9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) _fsck  #3:205afc9d:::smithi13915600-489:124#
remote/smithi097/log/objectstore_tool.22875.log.gz:2019-06-22T02:16:29.837+0000 7f5c3a86e9c0 20 bluestore(/var/lib/ceph/osd/ceph-7).collection(3.0_head 0x532b000) get_onode oid #3:205afc9d:::smithi13915600-489:124# key 0x7f8000000000000003205afc9d21736d'ithi13915600-489!='0x0000000000000124ffffffffffffffff'o'
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:32.653+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) _fsck  #3:205afc9d:::smithi13915600-489:124#
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:32.653+0000 7f25db8eb9c0 20 bluestore(/var/lib/ceph/osd/ceph-7).collection(3.0_head 0x535f000) get_onode oid #3:205afc9d:::smithi13915600-489:124# key 0x7f8000000000000003205afc9d21736d'ithi13915600-489!='0x0000000000000124ffffffffffffffff'o'
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.617+0000 7f25db8eb9c0 20 bluestore(/var/lib/ceph/osd/ceph-7) _collection_list oid #3:205afc9d:::smithi13915600-489:124# end GHMAX
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.705+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) stat 3.0_head #3:205afc9d:::smithi13915600-489:124#
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.705+0000 7f25db8eb9c0 20 bluestore(/var/lib/ceph/osd/ceph-7).collection(3.0_head 0x535de00) get_onode oid #3:205afc9d:::smithi13915600-489:124# key 0x7f8000000000000003205afc9d21736d'ithi13915600-489!='0x0000000000000124ffffffffffffffff'o'
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.705+0000 7f25db8eb9c0 15 bluestore(/var/lib/ceph/osd/ceph-7) getattr 3.0_head #3:205afc9d:::smithi13915600-489:124# _
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.705+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) getattr 3.0_head #3:205afc9d:::smithi13915600-489:124# _ = 0
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.705+0000 7f25db8eb9c0 15 bluestore(/var/lib/ceph/osd/ceph-7) read 3.0_head #3:205afc9d:::smithi13915600-489:124# 0x0~100000
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) read 3.0_head #3:205afc9d:::smithi13915600-489:124# 0x0~100000 = 1048576
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 15 bluestore(/var/lib/ceph/osd/ceph-7) read 3.0_head #3:205afc9d:::smithi13915600-489:124# 0x100000~100000
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) read 3.0_head #3:205afc9d:::smithi13915600-489:124# 0x100000~100000 = 1048576
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 15 bluestore(/var/lib/ceph/osd/ceph-7) read 3.0_head #3:205afc9d:::smithi13915600-489:124# 0x200000~198d8
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) read 3.0_head #3:205afc9d:::smithi13915600-489:124# 0x200000~198d8 = 104664
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 15 bluestore(/var/lib/ceph/osd/ceph-7) getattrs 3.0_head #3:205afc9d:::smithi13915600-489:124#
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) getattrs 3.0_head #3:205afc9d:::smithi13915600-489:124# = 0
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 15 bluestore(/var/lib/ceph/osd/ceph-7) omap_get_header 3.0_head oid #3:205afc9d:::smithi13915600-489:124#
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) omap_get_header 3.0_head oid #3:205afc9d:::smithi13915600-489:124# = 0
remote/smithi097/log/objectstore_tool.23010.log.gz:2019-06-22T02:16:33.709+0000 7f25db8eb9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) get_omap_iterator 3.0_head #3:205afc9d:::smithi13915600-489:124#
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:35.661+0000 7fd01e47e9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) _fsck  #3:205afc9d:::smithi13915600-489:124#
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:35.661+0000 7fd01e47e9c0 20 bluestore(/var/lib/ceph/osd/ceph-7).collection(3.0_head 0x4cdb000) get_onode oid #3:205afc9d:::smithi13915600-489:124# key 0x7f8000000000000003205afc9d21736d'ithi13915600-489!='0x0000000000000124ffffffffffffffff'o'
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.561+0000 7fd01e47e9c0 20 bluestore(/var/lib/ceph/osd/ceph-7) _collection_list oid #3:205afc9d:::smithi13915600-489:124# end GHMAX
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.561+0000 7fd01e47e9c0 20 snap_mapper.remove_oid 3:205afc9d:::smithi13915600-489:124
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.561+0000 7fd01e47e9c0 20 snap_mapper._remove_oid 3:205afc9d:::smithi13915600-489:124
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.561+0000 7fd01e47e9c0 20 snap_mapper.get_snaps 3:205afc9d:::smithi13915600-489:124 a6,dd,ef,fe,102,112,121
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.561+0000 7fd01e47e9c0 20 snap_mapper.clear_snaps 3:205afc9d:::smithi13915600-489:124
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.597+0000 7fd01e47e9c0 20 bluestore(/var/lib/ceph/osd/ceph-7).collection(3.0_head 0x4cd9e00) get_onode oid #3:205afc9d:::smithi13915600-489:124# key 0x7f8000000000000003205afc9d21736d'ithi13915600-489!='0x0000000000000124ffffffffffffffff'o'
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.597+0000 7fd01e47e9c0 15 bluestore(/var/lib/ceph/osd/ceph-7) _remove 3.0_head #3:205afc9d:::smithi13915600-489:124# onode 0x5fb7180 txc 0x3d5b300
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.597+0000 7fd01e47e9c0 15 bluestore(/var/lib/ceph/osd/ceph-7) _do_truncate 3.0_head #3:205afc9d:::smithi13915600-489:124# 0x0
remote/smithi097/log/objectstore_tool.23140.log.gz:2019-06-22T02:16:36.601+0000 7fd01e47e9c0 10 bluestore(/var/lib/ceph/osd/ceph-7) _remove 3.0_head #3:205afc9d:::smithi13915600-489:124# = 0

after the osd starts back up,
2019-06-22T02:17:44.296+0000 7fcec3d06700 10 osd.7 pg_epoch: 619 pg[3.0( v 619'2999 (0'0,619'2999] local-lis/les=618/619 n=50 ec=19/19 lis/c 618/618 les/c/f 619/619/0 614/618/618) [7,5,2] r=0 lpr=618 luod=613'2997 crt=619'2999 lcod 613'2997 mlcod 0'0 active+clean+snaptrim trimq=26 ps=34] SnapTrimmer state<Trimming/AwaitAsyncWork>: AwaitAsyncWork react trimming 3:205afc9d:::smithi13915600-489:124
2019-06-22T02:17:44.296+0000 7fcec3d06700 10 osd.7 pg_epoch: 619 pg[3.0( v 619'2999 (0'0,619'2999] local-lis/les=618/619 n=50 ec=19/19 lis/c 618/618 les/c/f 619/619/0 614/618/618) [7,5,2] r=0 lpr=618 luod=613'2997 crt=619'2999 lcod 613'2997 mlcod 0'0 active+clean+snaptrim trimq=26 ps=34] get_object_context: obc NOT found in cache: 3:205afc9d:::smithi13915600-489:124
2019-06-22T02:17:44.296+0000 7fcec3d06700 15 bluestore(/var/lib/ceph/osd/ceph-7) getattr 3.0_head #3:205afc9d:::smithi13915600-489:124# _
2019-06-22T02:17:44.296+0000 7fcec3d06700 20 bluestore(/var/lib/ceph/osd/ceph-7).collection(3.0_head 0x10430000) get_onode oid #3:205afc9d:::smithi13915600-489:124# key 0x7f8000000000000003205afc9d21736d'ithi13915600-489!='0x0000000000000124ffffffffffffffff'o'
2019-06-22T02:17:44.296+0000 7fcec3d06700 20 bluestore(/var/lib/ceph/osd/ceph-7).collection(3.0_head 0x10430000)  r -2 v.len 0
2019-06-22T02:17:44.296+0000 7fcec3d06700 10 bluestore(/var/lib/ceph/osd/ceph-7) getattr 3.0_head #3:205afc9d:::smithi13915600-489:124# _ = -2
2019-06-22T02:17:44.296+0000 7fcec3d06700 10 osd.7 pg_epoch: 619 pg[3.0( v 619'2999 (0'0,619'2999] local-lis/les=618/619 n=50 ec=19/19 lis/c 618/618 les/c/f 619/619/0 614/618/618) [7,5,2] r=0 lpr=618 luod=613'2997 crt=619'2999 lcod 613'2997 mlcod 0'0 active+clean+snaptrim trimq=26 ps=34] get_object_context: no obc for soid 3:205afc9d:::smithi13915600-489:124 and !can_create
2019-06-22T02:17:44.296+0000 7fcec3d06700 -1 log_channel(cluster) log [ERR] : trim_object: Can not trim 3:205afc9d:::smithi13915600-489:124 repair needed (no obc)

/a/sage-2019-06-21_16:36:51-rados:thrash-wip-sage2-testing-2019-06-20-2154-distro-basic-smithi/4057604

also,
/a/sage-2019-06-21_16:36:51-rados:thrash-wip-sage2-testing-2019-06-20-2154-distro-basic-smithi/4057754


Related issues

Related to RADOS - Bug #40454: snap_mapper error, scrub gets r -2..repaired Can't reproduce

History

#1 Updated by Sage Weil almost 5 years ago

  • Related to Bug #40454: snap_mapper error, scrub gets r -2..repaired added

#2 Updated by Sage Weil over 4 years ago

  • Status changed from New to Need More Info

I think this was from something like

teuthology-suite rados/thrash --subset 1/99 --filter snaps

#3 Updated by Josh Durgin over 4 years ago

  • Priority changed from High to Urgent

#4 Updated by Sage Weil about 4 years ago

  • Priority changed from Urgent to High

#5 Updated by Neha Ojha over 3 years ago

  • Status changed from Need More Info to Can't reproduce
  • Priority changed from High to Normal

Also available in: Atom PDF