Project

General

Profile

Actions

Bug #4704

closed

clone range short read

Added by Samuel Just about 11 years ago. Updated about 11 years ago.

Status:
Rejected
Priority:
Urgent
Assignee:
Category:
OSD
Target version:
-
% Done:

0%

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

Description

3:25:12.181924 7fd0257fa700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/a468ec03/snapmapper/0//-1
2013-04-10 13:25:12.182007 7fd0257fa700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/a468ec03/snapmapper/0//-1
2013-04-10 13:25:12.182088 7fd0257fa700 10 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[840~2,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] SnapTrimmer state<Trimming/TrimmingObjects>: TrimmingObjects: got ENOENT
2013-04-10 13:25:12.182107 7fd0257fa700 20 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[840~2,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] exit Trimming/TrimmingObjects
2013-04-10 13:25:12.182121 7fd0257fa700 20 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[840~2,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] enter Trimming/WaitingOnReplicas
2013-04-10 13:25:12.182135 7fd0257fa700 10 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[840~2,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] SnapTrimmer state<Trimming/WaitingOnReplicas>: Waiting on Replicas react
2013-04-10 13:25:12.182144 7fd0327fc700 20 filestore(/var/lib/ceph/osd/ceph-1) _do_copy_range 852682~3382 to 852682
2013-04-10 13:25:12.182148 7fd0257fa700 10 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[840~2,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] SnapTrimmer state<Trimming/WaitingOnReplicas>: WaitingOnReplicas: adding snap 840 to purged_snaps
2013-04-10 13:25:12.182184 7fd0327fc700 20 filestore(/var/lib/ceph/osd/ceph-1) _do_copy_range 852682~3382 to 852682 = 3382
2013-04-10 13:25:12.182189 7fd0327fc700 20 filestore(/var/lib/ceph/osd/ceph-1) _do_copy_range 3211264~239 to 3211264
2013-04-10 13:25:12.182164 7fd0257fa700 10 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] SnapTrimmer state<Trimming/WaitingOnReplicas>: purged_snaps now [1~601,603~40,644~5e,6a3~1a,6be~2a,6e9~17,701~5,707~5,70d~13,721~a,72c~a,737~15,74d~5,753~25,779~5,77f~13,793~5,799~7,7a2~1,7a5~4,7aa~6,7b1~3,7b5~5,7bb~3,7bf~1,7c1~2,7c5~7,7cd~3,7d1~3,7d5~2,7d8~1,7da~4,7e1~2,7e5~2,7e8~1,7ea~2,7ed~1,7ef~e,7ff~8,808~6,80f~2,812~1,817~2,81a~1,81c~2,81f~3,824~2,827~2,82a~2,82e~4,833~1,836~1,838~7,840~1], snap_trimq now [841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]
2013-04-10 13:25:12.182216 7fd0327fc700 -1 filestore(/var/lib/ceph/osd/ceph-1) FileStore::_do_copy_range got short read result at 3211264 of fd 51 len 239
2013-04-10 13:25:12.182219 7fd0327fc700 20 filestore(/var/lib/ceph/osd/ceph-1) _do_copy_range 3211264~239 to 3211264 = -34
2013-04-10 13:25:12.182227 7fd0327fc700 10 filestore(/var/lib/ceph/osd/ceph-1) clone_range 3.117_head/8dd4a517/mira0375291-19/722//3 -> 3.117_head/8dd4a517/mira0375291-19/76d//3 852682~2358821 to 852682 = -2
2013-04-10 13:25:12.182232 7fd0327fc700 0 filestore(/var/lib/ceph/osd/ceph-1) error (2) No such file or directory not handled on operation 30 (1449644.0.12, or op 12, counting from 0)
2013-04-10 13:25:12.182242 7fd0327fc700 0 filestore(/var/lib/ceph/osd/ceph-1) ENOENT on clone suggests osd bug
2013-04-10 13:25:12.182230 7fd0257fa700 20 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] write_info bigbl 876
2013-04-10 13:25:12.182250 7fd0257fa700 5 filestore(/var/lib/ceph/osd/ceph-1) queue_transactions existing osr(3.ec 0x2a3f020)/0x2a3f020
2013-04-10 13:25:12.182255 7fd0257fa700 5 filestore(/var/lib/ceph/osd/ceph-1) queue_transactions (parallel) 1449660 0x7fd01810c290
2013-04-10 13:25:12.182263 7fd0257fa700 5 filestore(/var/lib/ceph/osd/ceph-1) queue_op 0x7fd0181150e0 seq 1449660 osr(3.ec 0x2a3f020) 1573 bytes (queue has 9 ops and 1275327 bytes)
2013-04-10 13:25:12.182268 7fd0257fa700 20 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] exit Trimming/WaitingOnReplicas
2013-04-10 13:25:12.182283 7fd0257fa700 20 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] enter NotTrimming
2013-04-10 13:25:12.182297 7fd0257fa700 10 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] SnapTrimmer state<NotTrimming>: NotTrimming react
2013-04-10 13:25:12.182312 7fd0257fa700 10 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] SnapTrimmer state<NotTrimming>: NotTrimming: trimming 841
2013-04-10 13:25:12.182328 7fd0257fa700 20 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] exit NotTrimming
2013-04-10 13:25:12.182343 7fd0257fa700 20 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] enter Trimming/TrimmingObjects
2013-04-10 13:25:12.182357 7fd0257fa700 10 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] SnapTrimmer state<Trimming/TrimmingObjects>: TrimmingObjects react
2013-04-10 13:25:12.182371 7fd0257fa700 10 osd.1 pg_epoch: 3525 pg[3.ec( empty local-les=3515 n=0 ec=6 les/c 3515/3525 3510/3510/3510) [1,0] r=0 lpr=3510 mlcod 0'0 active+clean snaptrimq=[841~1,843~3,847~4,84c~4,852~1,854~1,856~2,85a~1,85c~1,85e~1]] SnapTrimmer state<Trimming/TrimmingObjects>: TrimmingObjects: trimming snap 841
2013-04-10 13:25:12.182388 7fd0257fa700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/a468ec03/snapmapper/0//-1
2013-04-10 13:25:12.182483 7fd0257fa700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/a468ec03/snapmapper/0//-1
2013-04-10 13:25:12.182568 7fd0257fa700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/a468ec03/snapmapper/0//-1
2013-04-10 13:25:12.182653 7fd0257fa700 15 filestore(/var/lib/ceph/osd/ceph-1) get_omap_iterator meta/

Actions

Also available in: Atom PDF