Actions
Bug #24516
closed[rbd-mirror] object map is getting invalidated during rbd-mirror-fsx-workunit test
Added by Jason Dillaman almost 6 years ago. Updated over 5 years ago.
Status:
Resolved
Priority:
Normal
Assignee:
Jason Dillaman
Target version:
-
% Done:
0%
Source:
Tags:
Backport:
luminous,mimic
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
2018-06-13 17:16:37.723 7f03d17fa700 -1 librbd::object_map::Request: failed to update object map: (34) Numerical result out of range 2018-06-13 17:16:37.723 7f03d17fa700 -1 librbd::object_map::InvalidateRequest: 0x7f03a0173e60 invalidating object map in-memory 2018-06-13 17:16:37.723 7f03d17fa700 -1 librbd::object_map::InvalidateRequest: 0x7f03a0173e60 invalidating object map on-disk 2018-06-13 17:16:37.731 7f03d17fa700 -1 librbd::object_map::InvalidateRequest: 0x7f03a0173e60 should_complete: r=0 2018-06-13 17:16:37.739 7f03d17fa700 -1 librbd::object_map::Request: failed to update object map: (34) Numerical result out of range 2018-06-13 17:16:37.739 7f03d17fa700 -1 librbd::object_map::InvalidateRequest: 0x7f03940621a0 invalidating object map in-memory 2018-06-13 17:16:37.739 7f03d17fa700 -1 librbd::object_map::InvalidateRequest: 0x7f03940621a0 invalidating object map on-disk 2018-06-13 17:16:37.743 7f03d17fa700 -1 librbd::object_map::InvalidateRequest: 0x7f03940621a0 should_complete: r=0
Updated by Jason Dillaman over 5 years ago
2018-09-12T12:10:54.992 INFO:teuthology.orchestra.run.smithi036.stdout:mapped writes DISABLED 2018-09-12T12:10:54.992 INFO:teuthology.orchestra.run.smithi036.stdout:mapped reads DISABLED 2018-09-12T12:10:54.993 INFO:teuthology.orchestra.run.smithi036.stdout:Seed set to 4254 2018-09-12T12:10:54.994 INFO:teuthology.orchestra.run.smithi036.stdout:mapped writes DISABLED 2018-09-12T12:10:54.994 INFO:teuthology.orchestra.run.smithi036.stdout:mapped reads DISABLED 2018-09-12T12:10:54.994 INFO:teuthology.orchestra.run.smithi036.stdout:Seed set to 4254 2018-09-12T12:10:54.994 INFO:teuthology.orchestra.run.smithi036.stdout:mapped writes DISABLED 2018-09-12T12:10:54.995 INFO:teuthology.orchestra.run.smithi036.stdout:mapped reads DISABLED 2018-09-12T12:10:54.995 INFO:teuthology.orchestra.run.smithi036.stdout:Seed set to 4254 2018-09-12T12:10:54.995 INFO:teuthology.orchestra.run.smithi036.stdout:mapped writes DISABLED 2018-09-12T12:10:54.995 INFO:teuthology.orchestra.run.smithi036.stdout:mapped reads DISABLED 2018-09-12T12:10:54.996 INFO:teuthology.orchestra.run.smithi036.stdout:Seed set to 4254 2018-09-12T12:10:54.996 INFO:teuthology.orchestra.run.smithi036.stdout:mapped writes DISABLED 2018-09-12T12:10:54.996 INFO:teuthology.orchestra.run.smithi036.stdout:mapped reads DISABLED 2018-09-12T12:10:54.996 INFO:teuthology.orchestra.run.smithi036.stdout:Seed set to 4254 2018-09-12T12:10:54.999 INFO:teuthology.orchestra.run.smithi036.stdout:mapped writes DISABLED 2018-09-12T12:10:54.999 INFO:teuthology.orchestra.run.smithi036.stdout:mapped reads DISABLED 2018-09-12T12:10:54.999 INFO:teuthology.orchestra.run.smithi036.stdout:Seed set to 4255
Updated by Jason Dillaman over 5 years ago
- Status changed from New to In Progress
- Assignee set to Jason Dillaman
Updated by Jason Dillaman over 5 years ago
It's related to a race with an rbd-mirror daemon sync snapshot getting removed via a notification to fsx:
2018-09-14 01:18:44.474 7f72367fc700 10 librbd::ImageWatcher: 0x7f722831fc80 remote snap_create request: .rbd-mirror.b7f9cd01-e621-4e99-a16e-08565e1bfab3.b7bcae18-d464-4255-9607-a57f189f9f11 2018-09-14 01:18:44.474 7f72367fc700 5 librbd::Operations: 0x560b03eaff00 execute_snap_create: snap_name=.rbd-mirror.b7f9cd01-e621-4e99-a16e-08565e1bfab3.b7bcae18-d464-4255-9607-a57f189f9f11 2018-09-14 01:18:44.474 7f72367fc700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 send_suspend_requests 2018-09-14 01:18:44.474 7f72367fc700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 send_suspend_aio 2018-09-14 01:18:44.506 7f7235ffb700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 handle_suspend_aio: r=0 2018-09-14 01:18:44.506 7f7235ffb700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 send_append_op_event 2018-09-14 01:18:44.514 7f7235ffb700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 handle_append_op_event: r=0 2018-09-14 01:18:44.514 7f7235ffb700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 send_allocate_snap_id 2018-09-14 01:18:44.542 7f72367fc700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 handle_allocate_snap_id: r=0, snap_id=315 2018-09-14 01:18:44.542 7f72367fc700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 send_create_snap 2018-09-14 01:18:44.558 7f72367fc700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 handle_create_snap: r=0 2018-09-14 01:18:44.558 7f72367fc700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 update_snap_context 2018-09-14 01:18:44.558 7f72367fc700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 send_create_object_map 2018-09-14 01:18:44.558 7f72367fc700 5 librbd::object_map::SnapshotCreateRequest: 0x7f722801bc60 send_read_map: oid=rbd_object_map.106256c84198 2018-09-14 01:18:44.558 7f72367fc700 5 librbd::object_map::SnapshotCreateRequest: 0x7f722801bc60 should_complete: state=READ_MAP, r=0 2018-09-14 01:18:44.558 7f72367fc700 5 librbd::object_map::SnapshotCreateRequest: 0x7f722801bc60 send_write_map: snap_oid=rbd_object_map.106256c84198.000000000000013b 2018-09-14 01:18:44.566 7f72367fc700 5 librbd::object_map::SnapshotCreateRequest: 0x7f722801bc60 should_complete: state=WRITE_MAP, r=0 2018-09-14 01:18:44.566 7f72367fc700 5 librbd::object_map::SnapshotCreateRequest: 0x7f722801bc60 send_add_snapshot: oid=rbd_object_map.106256c84198 2018-09-14 01:18:44.574 7f72367fc700 5 librbd::object_map::SnapshotCreateRequest: 0x7f722801bc60 should_complete: state=ADD_SNAPSHOT, r=0 2018-09-14 01:18:44.574 7f72367fc700 5 librbd::SnapshotCreateRequest: 0x7f72283481b0 handle_create_object_map: r=0 ... 2018-09-14 01:18:45.802 7f72367fc700 10 librbd::ImageWatcher: 0x7f722831fc80 remote snap_remove request: .rbd-mirror.b7f9cd01-e621-4e99-a16e-08565e1bfab3.b7bcae18-d464-4255-9607-a57f189f9f11 2018-09-14 01:18:45.802 7f72367fc700 5 librbd::Operations: 0x560b03eaff00 execute_snap_remove: snap_name=.rbd-mirror.b7f9cd01-e621-4e99-a16e-08565e1bfab3.b7bcae18-d464-4255-9607-a57f189f9f11 2018-09-14 01:18:45.818 7f7235ffb700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 trash_snap: 2018-09-14 01:18:45.830 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 handle_trash_snap: r=0 2018-09-14 01:18:45.830 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 get_snap: 2018-09-14 01:18:45.838 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 handle_get_snap: r=0 2018-09-14 01:18:45.838 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 remove_object_map: 2018-09-14 01:18:45.858 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 handle_remove_object_map: r=0 2018-09-14 01:18:45.858 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 release_snap_id: snap_name=.rbd-mirror.b7f9cd01-e621-4e99-a16e-08565e1bfab3.b7bcae18-d464-4255-9607-a57f189f9f11, snap_id=315 ... 2018-09-14 01:18:46.046 7f7235ffb700 20 librbd::io::CopyupRequest: 0x7f71df29f100 append_request: 0x7f71df31fc00 2018-09-14 01:18:46.046 7f7235ffb700 20 librbd::io::CopyupRequest: 0x7f71df29f100 send: completion 0x560b03d442c0, oid rbd_data.106256c84198.000000000000000d, extents [27262976,8192,27369472,8192,27475968,8192,27582464,8192,27688960,8192,27795456,8192,27901952,8192,28008448,8192,28114944,8192,28221440,8192,28327936,8192,28434432,8192,28540928,8192,28647424,8192,28753920,8192,28860416,8192,28966912,8192,29073408,8192,29179904,8192,29286400,8192,29392896,8192,29499392,8192,29605888,8192,29712384,8192,29818880,8192,29925376,8192,30031872,8192,30138368,8192,30244864,8192,30351360,8192,30457856,8192,30564352,8192,30670848,8192,30777344,8192,30883840,8192,30990336,8192,31096832,8192,31203328,8192,31309824,8192,31416320,8192,31522816,8192,31629312,8192,31735808,8192,31842304,8192,31948800,8192,32055296,8192,32161792,8192,32268288,8192,32374784,8192,32481280,8192,32587776,8192,32694272,8192,32800768,8192,32907264,8192,33013760,8192,33120256,8192,33226752,8192,33333248,8192,33439744,8192,33546240,8192,33652736,8192,33759232,8192,33865728,8192,33972224,8192,34078720,8192,34185216,8192,34291712,8192,34398208,8192,34504704,8192,34611200,8192,34717696,8192,34824192,8192,34930688,8192,35037184,8192,35143680,8192,35250176,8192,35356672,8192,35463168,8192,35569664,8192,35676160,8192,35782656,8192,35889152,8192,35995648,8192,36102144,8192,36208640,8192,36315136,8192,36421632,8192,36528128,8192,36634624,8192,36741120,8192,36847616,8192,36954112,8192,37060608,8192,37167104,8192,37273600,8192,37380096,8192,37486592,8192,37593088,8192,37699584,8192,37806080,8192,37912576,8192,38019072,8192,38125568,8192,38232064,8192,38338560,8192,38445056,8192,38551552,8192,38658048,8192,38764544,8192,38871040,8192,38977536,8192,39084032,8192,39190528,8192,39297024,8192,39403520,8192,39510016,8192,39616512,8192,39723008,8192,39829504,8192,39936000,8192,40042496,8192,40148992,8192,40255488,8192,40361984,8192,40468480,8192,40574976,8192,40681472,8192,40787968,8192,40894464,8192,41000960,8192,41107456,8192,41213952,8192,41320448,8192,41426944,8192,41533440,8192,41639936,8192,41746432,8192,41852928,8192,41959424,8192,42065920,8192,42172416,8192,42278912,8192,42385408,8192,42491904,8192,42598400,8192,42704896,8192,42811392,8192,42917888,8192,43024384,8192,43130880,8192,43237376,8192,43343872,8192,43450368,8192,43556864,8192,43663360,8192,43769856,8192,43876352,8192,43982848,8192,44089344,8192,44195840,8192,44302336,8192,44408832,8192,44515328,8192,44621824,8192,44728320,8192,44834816,8192,44941312,8192,45047808,8192,45154304,8192,45260800,8192,45367296,8192,45473792,8192,45580288,8192,45686784,8192,45793280,8192,45899776,8192,46006272,8192,46112768,8192,46219264,8192,46325760,8192,46432256,8192,46538752,8192,46645248,8192,46751744,8192,46858240,8192,46964736,8192,47071232,8192,47177728,8192,47284224,8192,47390720,8192,47497216,8192,47603712,8192,47710208,8192,47816704,8192,47923200,8192,48029696,8192,48136192,8192,48242688,8192,48349184,8192,48455680,8192,48562176,8192,48668672,8192,48775168,8192,48881664,8192,48988160,8192,49094656,8192,49201152,8192,49307648,8192,49414144,8192,49520640,8192,49627136,8192,49733632,8192,49840128,8192,49946624,8192,50053120,8192,50159616,8192,50266112,8192,50372608,8192,50479104,8192,50585600,8192,50692096,8192,50798592,8192,50905088,8192,51011584,8192,51118080,8192,51224576,8192,51331072,8192,51437568,8192,51544064,8192,51650560,8192,51757056,8192,51863552,8192,51970048,8192,52076544,8192,52183040,8192,52289536,8192,52396032,8192,52502528,8192,52609024,8192,52715520,8192,52822016,8192,52928512,8192,53035008,8192,53141504,8192,53248000,8192,53354496,8192,53460992,8192,53567488,8192,53673984,8192,53780480,8192,53886976,8192,53993472,8192,54099968,8192,54206464,8192,54312960,8192,54419456,8192] 2018-09-14 01:18:46.198 7f7235ffb700 20 librbd::io::CopyupRequest: 0x7f71df29f100 should_complete: oid rbd_data.106256c84198.000000000000000d, r 2097152 2018-09-14 01:18:46.198 7f7235ffb700 20 librbd::io::CopyupRequest: 0x7f71df29f100 should_complete: READ_FROM_PARENT 2018-09-14 01:18:46.198 7f7235ffb700 20 librbd::io::CopyupRequest: 0x7f71df29f100 send_object_map_head: 2018-09-14 01:18:46.198 7f7235ffb700 20 librbd::io::CopyupRequest: 0x7f71df29f100 send_object_map_head: truncate object no 13 current state 0 new state 1 2018-09-14 01:18:46.310 7f72367fc700 20 librbd::io::CopyupRequest: 0x7f71df29f100 should_complete: oid rbd_data.106256c84198.000000000000000d, r 0 2018-09-14 01:18:46.310 7f72367fc700 20 librbd::io::CopyupRequest: 0x7f71df29f100 should_complete: OBJECT_MAP_HEAD 2018-09-14 01:18:46.310 7f72367fc700 20 librbd::io::CopyupRequest: 0x7f71df29f100 send_object_map: oid rbd_data.106256c84198.000000000000000d 2018-09-14 01:18:46.310 7f72367fc700 20 librbd::ObjectMap: 0x7f71ba900170 aio_update: start=13, end=14, ->1 2018-09-14 01:18:46.310 7f72367fc700 20 librbd::object_map::UpdateRequest: 0x7f7229472aa0 update_object_map: ictx=0x560b03e9f2a0, oid=rbd_object_map.106256c84198.000000000000013b, [13,14) = ->1 2018-09-14 01:18:46.318 7f72367fc700 20 librbd::object_map::UpdateRequest: 0x7f7229472aa0 handle_update_object_map: r=-2 2018-09-14 01:18:46.318 7f72367fc700 20 librbd::object_map::Request: 0x7f7229472aa0 should_complete: r=-2 2018-09-14 01:18:46.318 7f72367fc700 -1 librbd::object_map::Request: failed to update object map: (2) No such file or directory 2018-09-14 01:18:46.318 7f72367fc700 -1 librbd::object_map::InvalidateRequest: 0x7f7228044020 invalidating object map in-memory 2018-09-14 01:18:46.318 7f72367fc700 -1 librbd::object_map::InvalidateRequest: 0x7f7228044020 invalidating object map on-disk ... 2018-09-14 01:18:46.550 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 handle_release_snap_id: r=0 2018-09-14 01:18:46.550 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 remove_snap: 2018-09-14 01:18:46.574 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 handle_remove_snap: r=0 2018-09-14 01:18:46.574 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 remove_snap_context: 2018-09-14 01:18:46.574 7f72367fc700 5 librbd::SnapshotRemoveRequest: 0x7f7228019410 should_complete: r=0
Updated by Jason Dillaman over 5 years ago
- Status changed from In Progress to Fix Under Review
- Backport set to luminous,mimic
Updated by Mykola Golub over 5 years ago
- Status changed from Fix Under Review to Pending Backport
Updated by Jason Dillaman over 5 years ago
- Status changed from Pending Backport to In Progress
There is another path where the object map is invalidated:
2018-09-18 23:40:13.884 7f84f67fc700 20 librbd::io::CopyupRequest: 0x7f84e83a5d30 send_object_map: oid rbd_data.10611250bd72.000000000000017f 2018-09-18 23:40:13.884 7f84f67fc700 20 librbd::ManagedLock: 0x7f84e401d020 is_lock_owner: =1 2018-09-18 23:40:13.884 7f84f67fc700 20 librbd::ObjectMap: 0x7f84e4003c30 aio_update: start=383, end=384, ->3 2018-09-18 23:40:13.884 7f84f67fc700 20 librbd::object_map::UpdateRequest: 0x7f84e803e200 update_object_map: ictx=0x55ecd0837e60, oid=rbd_object_map.10611250bd72.00000000000001b0, [383,384) = ->3 2018-09-18 23:40:13.885 7f84f67fc700 20 librbd::ManagedLock: 0x7f84e401d020 is_lock_owner: =1 2018-09-18 23:40:13.885 7f84f67fc700 20 librbd::ObjectMap: 0x7f84e4003c30 aio_update: start=383, end=384, ->1 2018-09-18 23:40:13.885 7f84f67fc700 20 librbd::object_map::UpdateRequest: 0x7f84e8321950 update_object_map: ictx=0x55ecd0837e60, oid=rbd_object_map.10611250bd72.000000000000021c, [383,384) = ->1 2018-09-18 23:40:13.891 7f84f67fc700 20 librbd::object_map::UpdateRequest: 0x7f84e8321950 handle_update_object_map: r=-2 2018-09-18 23:40:13.891 7f84f67fc700 20 librbd::object_map::Request: 0x7f84e8321950 should_complete: r=-2 2018-09-18 23:40:13.891 7f84f67fc700 -1 librbd::object_map::Request: failed to update object map: (2) No such file or directory 2018-09-18 23:40:13.891 7f84f67fc700 -1 librbd::object_map::InvalidateRequest: 0x7f84e806df80 invalidating object map in-memory 2018-09-18 23:40:13.891 7f84f67fc700 -1 librbd::object_map::InvalidateRequest: 0x7f84e806df80 invalidating object map on-disk
Updated by Jason Dillaman over 5 years ago
- Status changed from In Progress to Fix Under Review
Second PR: https://github.com/ceph/ceph/pull/24253
Updated by Mykola Golub over 5 years ago
- Status changed from Fix Under Review to Pending Backport
Updated by Nathan Cutler over 5 years ago
- Copied to Backport #36224: luminous: [rbd-mirror] object map is getting invalidated during rbd-mirror-fsx-workunit test added
Updated by Nathan Cutler over 5 years ago
- Copied to Backport #36225: mimic: [rbd-mirror] object map is getting invalidated during rbd-mirror-fsx-workunit test added
Updated by Nathan Cutler over 5 years ago
- Status changed from Pending Backport to Resolved
Actions