Actions
Bug #19943
closedosd: enoent on snaptrimmer
% Done:
0%
Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
OSD
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
-15> 2017-05-16 03:54:15.567351 7f2462a12700 20 osd.1 op_wq(3) _process 2.3 item PGQueueable(PGSnapTrim prio 5 cost 1048576 e814) pg 0x56090e3b4000 -14> 2017-05-16 03:54:15.567357 7f2462a12700 10 osd.1 pg_epoch: 814 pg[2.3( v 812'4221 (714'3846,812'4221] local-lis/les=810/812 n=47 ec=10 lis/c 810/810 les/c/f 812/812/0 808/810/810) [1,5] r=0 lpr=810 crt=812'4221 lcod 812'4219 mlcod 812'4219 active+clean+snaptrim snaptrimq=[263~1,27b~4,2a7~1,2ab~d,2ba~4,2bf~1]] snap_trimmer posting -13> 2017-05-16 03:54:15.567384 7f2462a12700 10 osd.1 pg_epoch: 814 pg[2.3( v 812'4221 (714'3846,812'4221] local-lis/les=810/812 n=47 ec=10 lis/c 810/810 les/c/f 812/812/0 808/810/810) [1,5] r=0 lpr=810 crt=812'4221 lcod 812'4219 mlcod 812'4219 active+clean+snaptrim snaptrimq=[263~1,27b~4,2a7~1,2ab~d,2ba~4,2bf~1]] SnapTrimmer state<Trimming/AwaitAsyncWork>: AwaitAsyncWork: trimming snap 263 -12> 2017-05-16 03:54:15.567407 7f2462a12700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/#-1:c0371625:::snapmapper:0# -11> 2017-05-16 03:54:15.567621 7f2462a12700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/#-1:c0371625:::snapmapper:0# -10> 2017-05-16 03:54:15.567690 7f2462a12700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/#-1:c0371625:::snapmapper:0# -9> 2017-05-16 03:54:15.567743 7f2462a12700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/#-1:c0371625:::snapmapper:0# -8> 2017-05-16 03:54:15.567794 7f2462a12700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/#-1:c0371625:::snapmapper:0# -7> 2017-05-16 03:54:15.567847 7f2462a12700 10 osd.1 pg_epoch: 814 pg[2.3( v 812'4221 (714'3846,812'4221] local-lis/les=810/812 n=47 ec=10 lis/c 810/810 les/c/f 812/812/0 808/810/810) [1,5] r=0 lpr=810 crt=812'4221 lcod 812'4219 mlcod 812'4219 active+clean+snaptrim snaptrimq=[263~1,27b~4,2a7~1,2ab~d,2ba~4,2bf~1]] SnapTrimmer state<Trimming/AwaitAsyncWork>: AwaitAsyncWork react trimming 2:fa704231:::smithi05621570-490:269 -6> 2017-05-16 03:54:15.567870 7f2462a12700 10 osd.1 pg_epoch: 814 pg[2.3( v 812'4221 (714'3846,812'4221] local-lis/les=810/812 n=47 ec=10 lis/c 810/810 les/c/f 812/812/0 808/810/810) [1,5] r=0 lpr=810 crt=812'4221 lcod 812'4219 mlcod 812'4219 active+clean+snaptrim snaptrimq=[263~1,27b~4,2a7~1,2ab~d,2ba~4,2bf~1]] get_object_context: obc NOT found in cache: 2:fa704231:::smithi05621570-490:269 -5> 2017-05-16 03:54:15.567880 7f2462a12700 15 filestore(/var/lib/ceph/osd/ceph-1) getattr 2.3_head/#2:fa704231:::smithi05621570-490:269# '_' -4> 2017-05-16 03:54:15.567933 7f2462a12700 10 filestore(/var/lib/ceph/osd/ceph-1) error opening file /var/lib/ceph/osd/ceph-1/current/2.3_head/DIR_F/smithi05621570-490__269_8C420E5F__2 with flags=2: (2) No such file or directory -3> 2017-05-16 03:54:15.567946 7f2462a12700 10 filestore(/var/lib/ceph/osd/ceph-1) getattr 2.3_head/#2:fa704231:::smithi05621570-490:269# '_' = -2 -2> 2017-05-16 03:54:15.567950 7f2462a12700 10 osd.1 pg_epoch: 814 pg[2.3( v 812'4221 (714'3846,812'4221] local-lis/les=810/812 n=47 ec=10 lis/c 810/810 les/c/f 812/812/0 808/810/810) [1,5] r=0 lpr=810 crt=812'4221 lcod 812'4219 mlcod 812'4219 active+clean+snaptrim snaptrimq=[263~1,27b~4,2a7~1,2ab~d,2ba~4,2bf~1]] get_object_context: no obc for soid 2:fa704231:::smithi05621570-490:269 and !can_create -1> 2017-05-16 03:54:15.567959 7f2462a12700 -1 osd.1 pg_epoch: 814 pg[2.3( v 812'4221 (714'3846,812'4221] local-lis/les=810/812 n=47 ec=10 lis/c 810/810 les/c/f 812/812/0 808/810/810) [1,5] r=0 lpr=810 crt=812'4221 lcod 812'4219 mlcod 812'4219 active+clean+snaptrim snaptrimq=[263~1,27b~4,2a7~1,2ab~d,2ba~4,2bf~1]] trim_object could not find coid 2:fa704231:::smithi05621570-490:269 0> 2017-05-16 03:54:15.571025 7f2462a12700 -1 *** Caught signal (Aborted) ** in thread 7f2462a12700 thread_name:tp_osd_tp ceph version 12.0.1-2422-g0d194cc (0d194cc84cf22302e6f62c1cba71d85c99637937) 1: (()+0x98c027) [0x5609043fd027] 2: (()+0x10330) [0x7f2480cd0330] 3: (gsignal()+0x37) [0x7f247fcf4c37] 4: (abort()+0x148) [0x7f247fcf8028] 5: (PrimaryLogPG::trim_object(bool, hobject_t const&)+0x1250) [0x56090408a370] 6: (PrimaryLogPG::AwaitAsyncWork::react(PrimaryLogPG::DoSnapWork const&)+0x8a6) [0x56090408bcc6] 7: (boost::statechart::simple_state<PrimaryLogPG::AwaitAsyncWork, PrimaryLogPG::Trimming, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::react_impl(boost::statechart::event_base const&, void const*)+0x90) [0x5609040eab40] 8: (PrimaryLogPG::snap_trimmer(unsigned int)+0x1b6) [0x560904046ea6] 9: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0xfd2) [0x560903f3bcc2] 10: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x955) [0x56090443e3c5] 11: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x560904440520] 12: (()+0x8184) [0x7f2480cc8184]
snapmapper shouldn't have htat object:
teuthology:1182436 03:58 PM $ grep 2:fa704231:::smithi05621570-490 remote/*/log/*osd.1* | grep snap_mapper 2017-05-16 03:37:48.951783 7fa1e5d9c700 20 snap_mapper.add_oid 2:fa704231:::smithi05621570-490:4 3,4 2017-05-16 03:37:48.951955 7fa1e5d9c700 20 snap_mapper.set_snaps 2:fa704231:::smithi05621570-490:4 3,4 2017-05-16 03:37:51.765773 7fa1e5d9c700 20 snap_mapper.update_snaps 2:fa704231:::smithi05621570-490:4 4 was 2017-05-16 03:37:51.765946 7fa1e5d9c700 20 snap_mapper.get_snaps 2:fa704231:::smithi05621570-490:4 3,4 2017-05-16 03:37:51.765963 7fa1e5d9c700 20 snap_mapper.set_snaps 2:fa704231:::smithi05621570-490:4 4 2017-05-16 03:37:53.772318 7fa1e5d9c700 20 snap_mapper.remove_oid 2:fa704231:::smithi05621570-490:4 2017-05-16 03:37:53.772325 7fa1e5d9c700 20 snap_mapper._remove_oid 2:fa704231:::smithi05621570-490:4 2017-05-16 03:37:53.772476 7fa1e5d9c700 20 snap_mapper.get_snaps 2:fa704231:::smithi05621570-490:4 4 2017-05-16 03:37:53.772483 7fa1e5d9c700 20 snap_mapper.clear_snaps 2:fa704231:::smithi05621570-490:4 2017-05-16 03:39:50.166759 7fa1e2d96700 20 snap_mapper.add_oid 2:fa704231:::smithi05621570-490:5b 3d,53,56,58,59,5a,5b 2017-05-16 03:39:50.166875 7fa1e2d96700 20 snap_mapper.set_snaps 2:fa704231:::smithi05621570-490:5b 3d,53,56,58,59,5a,5b 2017-05-16 03:39:58.302018 7fa1e0d92700 20 snap_mapper.remove_oid 2:fa704231:::smithi05621570-490:5b 2017-05-16 03:39:58.302021 7fa1e0d92700 20 snap_mapper._remove_oid 2:fa704231:::smithi05621570-490:5b 2017-05-16 03:39:58.302093 7fa1e0d92700 20 snap_mapper.get_snaps 2:fa704231:::smithi05621570-490:5b 3d,53,56,58,59,5a,5b 2017-05-16 03:39:58.302097 7fa1e0d92700 20 snap_mapper.clear_snaps 2:fa704231:::smithi05621570-490:5b 2017-05-16 03:45:06.148733 7f9301842700 20 snap_mapper.add_oid 2:fa704231:::smithi05621570-490:131 12c 2017-05-16 03:45:06.148904 7f9301842700 20 snap_mapper.set_snaps 2:fa704231:::smithi05621570-490:131 12c 2017-05-16 03:45:12.490071 7f9301842700 20 snap_mapper.remove_oid 2:fa704231:::smithi05621570-490:131 2017-05-16 03:45:12.490077 7f9301842700 20 snap_mapper._remove_oid 2:fa704231:::smithi05621570-490:131 2017-05-16 03:45:12.490253 7f9301842700 20 snap_mapper.get_snaps 2:fa704231:::smithi05621570-490:131 12c 2017-05-16 03:45:12.490260 7f9301842700 20 snap_mapper.clear_snaps 2:fa704231:::smithi05621570-490:131 2017-05-16 03:48:12.572931 7f92fe03b700 20 snap_mapper.remove_oid 2:fa704231:::smithi05621570-490:head 2017-05-16 03:48:12.572933 7f92fe03b700 20 snap_mapper._remove_oid 2:fa704231:::smithi05621570-490:head 2017-05-16 03:52:15.264425 7f92ff03d700 20 snap_mapper.add_oid 2:fa704231:::smithi05621570-490:269 200,210,215,22c,240,245,249,24a,24b,24e,24f,251,259,260,261,262,263 2017-05-16 03:52:15.264573 7f92ff03d700 20 snap_mapper.set_snaps 2:fa704231:::smithi05621570-490:269 200,210,215,22c,240,245,249,24a,24b,24e,24f,251,259,260,261,262,263 2017-05-16 03:52:41.833040 7f9301842700 20 snap_mapper.add_oid 2:fa704231:::smithi05621570-490:279 26e,275,277 2017-05-16 03:52:41.833244 7f9301842700 20 snap_mapper.set_snaps 2:fa704231:::smithi05621570-490:279 26e,275,277 2017-05-16 03:52:52.392636 7f92fa033700 20 snap_mapper.remove_oid 2:fa704231:::smithi05621570-490:269 2017-05-16 03:52:52.392639 7f92fa033700 20 snap_mapper._remove_oid 2:fa704231:::smithi05621570-490:269 2017-05-16 03:52:52.392783 7f92fa033700 20 snap_mapper.get_snaps 2:fa704231:::smithi05621570-490:269 200,210,215,22c,240,245,249,24a,24b,24e,24f,251,259,260,261,262,263 2017-05-16 03:52:52.392790 7f92fa033700 20 snap_mapper.clear_snaps 2:fa704231:::smithi05621570-490:269 2017-05-16 03:53:11.338655 7f9301842700 20 snap_mapper.get_snaps 2:fa704231:::smithi05621570-490:279 26e,275,277 2017-05-16 03:53:13.940511 7f9301842700 20 snap_mapper.remove_oid 2:fa704231:::smithi05621570-490:279 2017-05-16 03:53:13.940514 7f9301842700 20 snap_mapper._remove_oid 2:fa704231:::smithi05621570-490:279 2017-05-16 03:53:13.940631 7f9301842700 20 snap_mapper.get_snaps 2:fa704231:::smithi05621570-490:279 26e,275,277 2017-05-16 03:53:13.940636 7f9301842700 20 snap_mapper.clear_snaps 2:fa704231:::smithi05621570-490:279 2017-05-16 03:53:40.165676 7f9301842700 20 snap_mapper.add_oid 2:fa704231:::smithi05621570-490:2a5 27b,27c,27d,27e,284,28c,292,2a0,2a3,2a4 2017-05-16 03:53:40.165785 7f9301842700 20 snap_mapper.set_snaps 2:fa704231:::smithi05621570-490:2a5 27b,27c,27d,27e,284,28c,292,2a0,2a3,2a4 2017-05-16 03:53:44.700164 7f9301842700 20 snap_mapper.update_snaps 2:fa704231:::smithi05621570-490:2a5 27b,27c,27d,27e,284,28c,2a0,2a3,2a4 was 2017-05-16 03:53:44.700268 7f9301842700 20 snap_mapper.get_snaps 2:fa704231:::smithi05621570-490:2a5 27b,27c,27d,27e,284,28c,292,2a0,2a3,2a4 2017-05-16 03:53:44.700277 7f9301842700 20 snap_mapper.set_snaps 2:fa704231:::smithi05621570-490:2a5 27b,27c,27d,27e,284,28c,2a0,2a3,2a4
note that 269 was deleted at 03:52:52.392790
filestore, rocksdb (recent).
/a/sage-2017-05-16_02:42:05-rados-wip-sage-testing2---basic-smithi/1182436
Actions