Closed Emmenemoi closed 8 years ago
I don't know if it is related but: Even if the VDI is not marked "read only", it is attached RO to a VM:
sm-config (MRO): attached: true; host_OpaqueRef:2dacdcbe-d559-2bd0-1815-809e88072bcb: RO
Can't find a reason.
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|5 ||xenstore_watch] xenstore watch path=/vm/53514d1a-d2ff-dc80-9bc8-61bb2d31e57e/rtc/timeoffset token=xenopsd-xc:domain-12 Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |events|xenops_server] Received an event on managed VM 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |queue|xenops_server] Queue.push ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] onto redirected 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e:[ ["Atomic", ["VM_unpause", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"]], ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] ] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |events|xenops_server] Received an event on managed VM 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |queue|xenops_server] Queue.push ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] onto redirected 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e:[ ["Atomic", ["VM_unpause", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"]], ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] ] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.250000] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["VBD_set_active", ["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], true] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] VBD.set_active 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e.xvda true Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] VBD_DB.signal 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e.xvda Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.333333] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["Parallel", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", []] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] begin_Parallel:task=262.atoms=0.(VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] end_Parallel:task=262.atoms=0.(VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.416667] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["Parallel", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", [["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]]] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] begin_Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] queue_atomics_and_wait: Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e): chunk of 1 atoms Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |queue|xenops_server] Queue.push ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]] onto Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e).chunk=0.atom=0:[ ] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 ||xenops_server] Queue.pop returned ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops_server] Task 267 reference Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e): ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops_server] VBD.epoch_begin ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [ info|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops] Processing disk SR=2C740292-44FC-40F6-9949-1F68E59B9024 VDI=afba13c0-9906-459f-9b5d-3d9d9f3acf2a Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|8 ||scheduler] Scheduler sleep until 1470762704 (another 24 seconds) Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] Processing event: ["Task", "262"] Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] xenops event on Task 262 Aug 9 19:11:19 xenserver-test2 xapi: [ info|xenserver-test2|2574 ||storage_impl] VDI.epoch_begin dbg:Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) sr:2C740292-44FC-40F6-9949-1F68E59B9024 vdi:afba13c0-9906-459f-9b5d-3d9d9f3acf2a persistent:true Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 ||dummytaskhelper] task VDI.epoch_begin D:f24d88170fde created by task R:ask=262.toms Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|8 ||scheduler] Scheduler sleep until 1470762704 (another 24 seconds) Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 |VDI.epoch_begin D:f24d88170fde|sm] SM rbd vdi_epoch_begin sr=OpaqueRef:717833f2-b3c8-a0da-b5a3-abbe26981e47 vdi=OpaqueRef:82153e6e-58e1-ee6f-4926-b69391a33650 Aug 9 19:11:19 xenserver-test2 xapi: [ info|xenserver-test2|2575 |sm_exec D:b9d89462526d|xapi] Session.create trackid=e5d14fd9bbe0f238d304c130c60bfb73 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 |sm_exec D:b9d89462526d|mscgen] xapi=>xapi [label="pool.get_all"]; Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] Processing event: ["Vbd", ["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"]]
Seems to be a Xen orchestra bug, attaching VDI in RO mode even if not indicated as such...
I don't know if it is related but: Even if the VDI is not marked "read only", it is attached RO to a VM:
Can't find a reason.
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|5 ||xenstore_watch] xenstore watch path=/vm/53514d1a-d2ff-dc80-9bc8-61bb2d31e57e/rtc/timeoffset token=xenopsd-xc:domain-12 Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |events|xenops_server] Received an event on managed VM 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |queue|xenops_server] Queue.push ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] onto redirected 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e:[ ["Atomic", ["VM_unpause", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"]], ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] ] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |events|xenops_server] Received an event on managed VM 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |queue|xenops_server] Queue.push ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] onto redirected 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e:[ ["Atomic", ["VM_unpause", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"]], ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] ] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.250000] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["VBD_set_active", ["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], true] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] VBD.set_active 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e.xvda true Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] VBD_DB.signal 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e.xvda Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.333333] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["Parallel", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", []] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] begin_Parallel:task=262.atoms=0.(VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] end_Parallel:task=262.atoms=0.(VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.416667] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["Parallel", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", [["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]]] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] begin_Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] queue_atomics_and_wait: Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e): chunk of 1 atoms Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |queue|xenops_server] Queue.push ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]] onto Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e).chunk=0.atom=0:[ ] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 ||xenops_server] Queue.pop returned ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops_server] Task 267 reference Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e): ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops_server] VBD.epoch_begin ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024\/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"] Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [ info|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops] Processing disk SR=2C740292-44FC-40F6-9949-1F68E59B9024 VDI=afba13c0-9906-459f-9b5d-3d9d9f3acf2a Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|8 ||scheduler] Scheduler sleep until 1470762704 (another 24 seconds) Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] Processing event: ["Task", "262"] Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] xenops event on Task 262 Aug 9 19:11:19 xenserver-test2 xapi: [ info|xenserver-test2|2574 ||storage_impl] VDI.epoch_begin dbg:Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) sr:2C740292-44FC-40F6-9949-1F68E59B9024 vdi:afba13c0-9906-459f-9b5d-3d9d9f3acf2a persistent:true Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 ||dummytaskhelper] task VDI.epoch_begin D:f24d88170fde created by task R:ask=262.toms Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|8 ||scheduler] Scheduler sleep until 1470762704 (another 24 seconds) Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 |VDI.epoch_begin D:f24d88170fde|sm] SM rbd vdi_epoch_begin sr=OpaqueRef:717833f2-b3c8-a0da-b5a3-abbe26981e47 vdi=OpaqueRef:82153e6e-58e1-ee6f-4926-b69391a33650 Aug 9 19:11:19 xenserver-test2 xapi: [ info|xenserver-test2|2575 |sm_exec D:b9d89462526d|xapi] Session.create trackid=e5d14fd9bbe0f238d304c130c60bfb73 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 |sm_exec D:b9d89462526d|mscgen] xapi=>xapi [label="pool.get_all"]; Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] Processing event: ["Vbd", ["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"]]