Details
-
Bug
-
Status: Resolved
-
Critical
-
Resolution: Fixed
-
4.5.0
-
Security Level: Public (Anyone can view this level - this is the default.)
-
None
Description
Failed to create volume snapshot after vm live migration across clusters
Steps to reproduce:
================
1.Bring up cs in advanced zone with two xen clusters and at-least one host in each cluster
2.Deploy one guest vm using default cent os template
3.Take snapshot of the root disk
4.Now live migrate vm to another cluster so that it will be migrated along with storage
5.Again take snapshot on the root volume
Expected Behavior:
===============
Snapshot creation shall succeed and shall backup to secondary storage
Actual Behavior:
==============
Snapshot is created on primary but failed to copy to secondary. So snapshot creation failed with exceptions.
Observations:
============
After live migrating vm with storage we are not changing the volume id and uuid in volumes table. During vm live migration volume state remains in "Migrating" state and after completion it comes to "Ready" state.
1.When wee created snapshot on the root disk vm was in cluster1 so snapshot was created in cluster1's primary storage.
2.After that we live migrated the vm to another cluster and created snapshot another snapshot on the root disk. This time snapshot was created on cluster2's primary storage.
May be this vhd file on this primary storage did not find any parent vhd file so vhd scan might have deleted this vhd.
I could found the following lines from xenserver SMlog file:
Nov 21 04:58:13 localhost SMGC: [21457] Got sm-config for *837da6ea(20.000G/112.262M):
Nov 21 04:58:13 localhost SMGC: [21457] Found 1 VDIs for deletion:
Nov 21 04:58:13 localhost SMGC: [21457] *49341e2f(20.000G/34.110M)
Nov 21 04:58:13 localhost SMGC: [21457] Deleting unlinked VDI *49341e2f(20.000G/34.110M)
Nov 21 04:58:13 localhost SMGC: [21457] Checking with slave: ('OpaqueRef:17fa526d-4f74-6d9
I guess when CS tried to copy the snapshot to secondary storage it could not found the vhd hence it failed with NPE.
Please look for async job-35 in the attached MS log file.
Following is the log snippet from xenserver SMlog file:
==========================================
Nov 21 04:57:07 localhost SM: [20944] vdi_snapshot {'sr_uuid': '1f273ffb-3583-4a91-0c30-faa4951e7df8', 'subtask_of': 'DummyRef:|6bb04f6c-1a9a-950e-77cb-067eb7a29e3f|VDI.snapshot', 'vdi_ref': 'OpaqueRef:9583c77d-e9c5-144a-823c-599db4ba59f4', 'vdi_on_boot': 'persist', 'args': [], 'o_direct': False, 'vdi_location': '1cf9e9f7-862e-4426-9416-584987b9cfbd', 'host_ref': 'OpaqueRef:4366ea2d-224b-fa03-65d6-a53c18b0c77f', 'session_ref': 'OpaqueRef:45e50d1a-37cf-aa1d-30ec-e77927acfab5', 'device_config':
, 'command': 'vdi_snapshot', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:c32edd0d-b0d7-7e28-9385-a4a6100f116b', 'driver_params': {}, 'vdi_uuid': '1cf9e9f7-862e-4426-9416-584987b9cfbd'}
Nov 21 04:57:07 localhost SM: [20944] Pause request for 1cf9e9f7-862e-4426-9416-584987b9cfbd
Nov 21 04:57:07 localhost SM: [20944] Calling tap-pause on host OpaqueRef:4366ea2d-224b-fa03-65d6-a53c18b0c77f
Nov 21 04:57:07 localhost SM: [20955] lock: opening lock file /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:57:07 localhost SM: [20955] lock: acquired /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:57:07 localhost SM: [20955] Pause for 1cf9e9f7-862e-4426-9416-584987b9cfbd
Nov 21 04:57:07 localhost SM: [20955] Calling tap pause with minor 1
Nov 21 04:57:07 localhost SM: [20955] ['/usr/sbin/tap-ctl', 'pause', '-p', '18621', '-m', '1']
Nov 21 04:57:07 localhost SM: [20955] = 0
Nov 21 04:57:07 localhost SM: [20955] lock: released /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:57:07 localhost SM: [20955] lock: closed /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:57:07 localhost SM: [20944] FileVDI._snapshot for 1cf9e9f7-862e-4426-9416-584987b9cfbd (type 2)
Nov 21 04:57:07 localhost SM: [20944] ['uuidgen', '-r']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] ['/usr/bin/vhd-util', 'query', '--debug', '-d', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1cf9e9f7-862e-4426-9416-584987b9cfbd.vhd']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] ['uuidgen', '-r']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] ['/usr/sbin/td-util', 'snapshot', 'vhd', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1cf9e9f7-862e-4426-9416-584987b9cfbd.vhd', '49341e2f-2b34-4f40-aa8a-0486a6cd14f8.vhd']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] ['/usr/sbin/td-util', 'snapshot', 'vhd', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/2caf017c-a653-4b05-92fb-b8b29285fbb5.vhd', '49341e2f-2b34-4f40-aa8a-0486a6cd14f8.vhd']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] ['/usr/bin/vhd-util', 'set', '--debug', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/49341e2f-2b34-4f40-aa8a-0486a6cd14f8.vhd', '-f', 'hidden', '-v', '1']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] ['/usr/sbin/td-util', 'query', 'vhd', '-p', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1cf9e9f7-862e-4426-9416-584987b9cfbd.vhd']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] ['/usr/sbin/td-util', 'query', 'vhd', '-p', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/2caf017c-a653-4b05-92fb-b8b29285fbb5.vhd']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] ['/usr/sbin/td-util', 'query', 'vhd', '-p', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/49341e2f-2b34-4f40-aa8a-0486a6cd14f8.vhd']
Nov 21 04:57:07 localhost SM: [20944] pread SUCCESS
Nov 21 04:57:07 localhost SM: [20944] vdi_clone: introduced VDI: OpaqueRef:5f81e622-efd1-b8fa-5a62-26f30336bed5 (2caf017c-a653-4b05-92fb-b8b29285fbb5)
Nov 21 04:57:07 localhost SM: [20944] vdi_clone: introduced VDI: OpaqueRef:6cf2dd9e-efe6-ef1b-493c-0b3e06e682da (49341e2f-2b34-4f40-aa8a-0486a6cd14f8)
Nov 21 04:57:07 localhost SM: [20944] Unpause request for 1cf9e9f7-862e-4426-9416-584987b9cfbd secondary=None
Nov 21 04:57:07 localhost SM: [20944] Calling tap-unpause on host OpaqueRef:4366ea2d-224b-fa03-65d6-a53c18b0c77f
Nov 21 04:57:07 localhost SM: [20991] lock: opening lock file /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:57:07 localhost SM: [20991] lock: acquired /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:57:07 localhost SM: [20991] Unpause for 1cf9e9f7-862e-4426-9416-584987b9cfbd
Nov 21 04:57:07 localhost SM: [20991] Realpath: /var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1cf9e9f7-862e-4426-9416-584987b9cfbd.vhd
Nov 21 04:57:07 localhost SM: [20991] Calling tap unpause with minor 1
Nov 21 04:57:07 localhost SM: [20991] ['/usr/sbin/tap-ctl', 'unpause', '-p', '18621', '-m', '1', '-a', 'vhd:/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1cf9e9f7-862e-4426-9416-584987b9cfbd.vhd']
Nov 21 04:57:08 localhost SM: [21001] ['/usr/sbin/td-util', 'query', 'vhd', '-vpfb', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/2caf017c-a653-4b05-92fb-b8b29285fbb5.vhd']
Nov 21 04:57:08 localhost SM: [21001] pread SUCCESS
Nov 21 04:57:08 localhost SM: [21001] lock: closed /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:57:08 localhost SM: [21022] lock: opening lock file /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:57:08 localhost SM: [21022] lock: acquired /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:57:08 localhost SM: [21022] ['/usr/sbin/td-util', 'query', 'vhd', '-vpfb', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/2caf017c-a653-4b05-92fb-b8b29285fbb5.vhd']
Nov 21 04:57:08 localhost SM: [21022] pread SUCCESS
Nov 21 04:57:08 localhost SM: [21022] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:57:08 localhost SM: [21022] vdi_update {'sr_uuid': '1f273ffb-3583-4a91-0c30-faa4951e7df8', 'subtask_of': 'OpaqueRef:801b873e-525e-79b1-ed9e-59174ba805a1', 'vdi_ref': 'OpaqueRef:5f81e622-efd1-b8fa-5a62-26f30336bed5', 'vdi_on_boot': 'persist', 'args': [], 'o_direct': False, 'vdi_location': '2caf017c-a653-4b05-92fb-b8b29285fbb5', 'host_ref': 'OpaqueRef:4366ea2d-224b-fa03-65d6-a53c18b0c77f', 'session_ref': 'OpaqueRef:818180cb-850c-2bbd-f66a-befeaf00c8f2', 'device_config':
, 'command': 'vdi_update', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:c32edd0d-b0d7-7e28-9385-a4a6100f116b', 'vdi_uuid': '2caf017c-a653-4b05-92fb-b8b29285fbb5'}
Nov 21 04:57:08 localhost SM: [21022] ['/usr/sbin/td-util', 'query', 'vhd', '-vpfb', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/2caf017c-a653-4b05-92fb-b8b29285fbb5.vhd']
Nov 21 04:57:08 localhost SM: [21022] pread SUCCESS
Nov 21 04:57:08 localhost SM: [21022] lock: closed /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:02 localhost SM: [21450] lock: opening lock file /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:02 localhost SM: [21450] lock: acquired /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:02 localhost SM: [21450] sr_scan {'sr_uuid': '1f273ffb-3583-4a91-0c30-faa4951e7df8', 'subtask_of': 'DummyRef:|184be5c5-dd11-de09-44a4-9c35491d9d39|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:4366ea2d-224b-fa03-65d6-a53c18b0c77f', 'session_ref': 'OpaqueRef:b8af9168-34f8-7b83-c5f4-9787635da3eb', 'device_config':
, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:c32edd0d-b0d7-7e28-9385-a4a6100f116b'}
Nov 21 04:58:02 localhost SM: [21450] ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/*.vhd']
Nov 21 04:58:02 localhost SM: [21450] pread SUCCESS
Nov 21 04:58:02 localhost SM: [21450] ['ls', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8', '-1', '--color=never']
Nov 21 04:58:02 localhost SM: [21450] pread SUCCESS
Nov 21 04:58:02 localhost SM: [21450] lock: opening lock file /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/running
Nov 21 04:58:02 localhost SM: [21450] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/running, acquired: True (exists: True)
Nov 21 04:58:02 localhost SM: [21450] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/running
Nov 21 04:58:02 localhost SM: [21450] Kicking GC
Nov 21 04:58:03 localhost SM: [21450] lock: closed /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/running
Nov 21 04:58:03 localhost SM: [21457] lock: opening lock file /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:03 localhost SM: [21450] utilisation 17082880 <> 33847808
Nov 21 04:58:03 localhost SM: [21450] utilisation 35766784 <> 33847808
Nov 21 04:58:03 localhost SM: [21450] utilisation 78790656 <> 78749696
Nov 21 04:58:03 localhost SM: [21450] VDIs changed on disk: ['1cf9e9f7-862e-4426-9416-584987b9cfbd', '49341e2f-2b34-4f40-aa8a-0486a6cd14f8', '943c7084-923a-4472-8205-59a49ea207c1']
Nov 21 04:58:03 localhost SM: [21450] Updating VDI with location=1cf9e9f7-862e-4426-9416-584987b9cfbd uuid=1cf9e9f7-862e-4426-9416-584987b9cfbd
Nov 21 04:58:03 localhost SMGC: [21457] Found 0 cache files
Nov 21 04:58:03 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr, acquired: False (exists: True)
Nov 21 04:58:03 localhost SM: [21450] Updating VDI with location=49341e2f-2b34-4f40-aa8a-0486a6cd14f8 uuid=49341e2f-2b34-4f40-aa8a-0486a6cd14f8
Nov 21 04:58:03 localhost SM: [21450] Updating VDI with location=943c7084-923a-4472-8205-59a49ea207c1 uuid=943c7084-923a-4472-8205-59a49ea207c1
Nov 21 04:58:03 localhost SM: [21450] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:03 localhost SM: [21450] lock: closed /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:06 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr, acquired: True (exists: True)
Nov 21 04:58:06 localhost SM: [21457] ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/*.vhd']
Nov 21 04:58:06 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:06 localhost SMGC: [21457] SR 1f27 ('9c0576b9-d3e8-3023-bed9-1e9a46a40d54') (11 VDIs in 3 VHD trees):
Nov 21 04:58:06 localhost SMGC: [21457] *5c212631(2.441G/2.446G)
Nov 21 04:58:06 localhost SMGC: [21457] 943c7084(2.441G/75.141M)
Nov 21 04:58:06 localhost SMGC: [21457] 3b8d1b52(2.441G/9.500K)
Nov 21 04:58:06 localhost SMGC: [21457] *745072fa(20.000G/1.638G)
Nov 21 04:58:06 localhost SMGC: [21457] 80df1dcc(20.000G/45.500K)
Nov 21 04:58:06 localhost SMGC: [21457] *837da6ea(20.000G/112.262M)
Nov 21 04:58:06 localhost SMGC: [21457] 4c71ec2e(20.000G/45.500K)
Nov 21 04:58:06 localhost SMGC: [21457] *1ba82e64(20.000G/1.646G)
Nov 21 04:58:06 localhost SMGC: [21457] *49341e2f(20.000G/34.110M)
Nov 21 04:58:06 localhost SMGC: [21457] 1cf9e9f7(20.000G/16.292M)
Nov 21 04:58:06 localhost SMGC: [21457] 2caf017c(20.000G/45.500K)
Nov 21 04:58:06 localhost SMGC: [21457]
Nov 21 04:58:06 localhost SM: [21457] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:06 localhost SMGC: [21457] Removed vhd-blocks from *49341e2f(20.000G/34.110M)
Nov 21 04:58:06 localhost SM: [21457] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:06 localhost SMGC: [21457] Removed vhd-blocks from *49341e2f(20.000G/34.110M)
Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *49341e2f(20.000G/34.110M):
Nov 21 04:58:06 localhost SM: [21457] ['/usr/bin/vhd-util', 'read', '--debug', '-B', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/49341e2f-2b34-4f40-aa8a-0486a6cd14f8.vhd']
Nov 21 04:58:06 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:06 localhost SMGC: [21457] Set vhd-blocks = eJxjYAABAQGGUUBDQGnwEtI/VKJPREBAgINRgHGg3YEL0Csc6R1fLHS2b+gAAHQGANM= for *49341e2f(20.000G/34.110M)
Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *49341e2f(20.000G/34.110M):
Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *1ba82e64(20.000G/1.646G):
{'base_mirror': 'a847ec21-9d04-4a8c-5e7f-cf52b2f56b75/3b790b0e-6216-4277-a4ce-62aee1d03a35', 'vhd-blocks': 'eJz7398BBHv/A8HX0NDQAAYwEIBQDCIMDPIgqe//P8D4MFoAmY+kHkVeAE2eWBqPfrzmItkPdDeU/ofgE9JPKxpovxyR6rD6U1RQEOj+j4KiAoKSHxsFBND1iV8QhMYTBKDTKOHx/wAjhP4Ai99/IPqHAAF34ZEnlhaVnCj/V1BQkIj4E2BgpGo8EBXvoHD4Rx378NJioHD/Qdf0hyu/kpTPRKAscsMXlYbxBhAwAgAY6lZ1'}Nov 21 04:58:06 localhost SMGC: [21457] Num combined blocks = 841
Nov 21 04:58:06 localhost SMGC: [21457] Coalesced size = 1.646G
Nov 21 04:58:06 localhost SMGC: [21457] Coalesce candidate: *49341e2f(20.000G/34.110M) (tree height 3)
Nov 21 04:58:06 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/running, acquired: True (exists: True)
Nov 21 04:58:06 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr, acquired: True (exists: True)
Nov 21 04:58:06 localhost SM: [21457] ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/*.vhd']
Nov 21 04:58:06 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:06 localhost SMGC: [21457] SR 1f27 ('9c0576b9-d3e8-3023-bed9-1e9a46a40d54') (11 VDIs in 3 VHD trees): no changes
Nov 21 04:58:06 localhost SM: [21457] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *5c212631(2.441G/2.446G):
Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *745072fa(20.000G/1.638G):
{'vhd-blocks': 'eJz7398BBHv/A8HX0NDQAAYwEIBQDCIMDPIgqe//P8D4MFoAmY+kHkVeAE2eWBqPfrzmItkPdDeU/ofgE9JPKxpovxyR6rD6U1RQEOj+j4KiAgKSHxsFBND1iV8QhMYTBKDTKOHx/wAjhP4Ai99/IPqHAAF34ZEnlhaVnCD/V1BQkIj4E2BgpGo8EBXvoHD4Rx378NJioHD/Qdf0hyu/kpXPqKAeiTeAgBEAAsJWXw=='}Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *1ba82e64(20.000G/1.646G):
{'base_mirror': 'a847ec21-9d04-4a8c-5e7f-cf52b2f56b75/3b790b0e-6216-4277-a4ce-62aee1d03a35', 'vhd-blocks': 'eJz7398BBHv/A8HX0NDQAAYwEIBQDCIMDPIgqe//P8D4MFoAmY+kHkVeAE2eWBqPfrzmItkPdDeU/ofgE9JPKxpovxyR6rD6U1RQEOj+j4KiAoKSHxsFBND1iV8QhMYTBKDTKOHx/wAjhP4Ai99/IPqHAAF34ZEnlhaVnCj/V1BQkIj4E2BgpGo8EBXvoHD4Rx378NJioHD/Qdf0hyu/kpTPRKAscsMXlYbxBhAwAgAY6lZ1'}Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *49341e2f(20.000G/34.110M):
{'vhd-parent': '1ba82e64-3a86-4cb0-b708-d6ddffe02214', 'vhd-blocks': 'eJxjYAABAQGGUUBDQGnwEtI/VKJPREBAgINRgHGg3YEL0Csc6R1fLHS2b+gAAHQGANM='}Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *837da6ea(20.000G/112.262M):
{'vhd-parent': '745072fa-345a-4a7b-99a3-0c3789831146', 'vhd-blocks': 'eJxrYAAB0QcMKECEEUKzMAxNIAClWdD4AwUotV9EQFCCgVGRQQSHUSI47MNlL7o8vcJHVFBQqlFQkJFO1pEM6BUO9E6PtM7HA52/yAcAa1ED4w=='}Nov 21 04:58:06 localhost SMGC: [21457] Removed vhd-blocks from *49341e2f(20.000G/34.110M)
Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *49341e2f(20.000G/34.110M):
Nov 21 04:58:06 localhost SM: [21457] ['/usr/bin/vhd-util', 'read', '--debug', '-B', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/49341e2f-2b34-4f40-aa8a-0486a6cd14f8.vhd']
Nov 21 04:58:06 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:06 localhost SMGC: [21457] Set vhd-blocks = eJxjYAABAQGGUUBDQGnwEtI/VKJPREBAgINRgHGg3YEL0Csc6R1fLHS2b+gAAHQGANM= for *49341e2f(20.000G/34.110M)
Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *49341e2f(20.000G/34.110M):
Nov 21 04:58:06 localhost SMGC: [21457] Got sm-config for *1ba82e64(20.000G/1.646G):
{'base_mirror': 'a847ec21-9d04-4a8c-5e7f-cf52b2f56b75/3b790b0e-6216-4277-a4ce-62aee1d03a35', 'vhd-blocks': 'eJz7398BBHv/A8HX0NDQAAYwEIBQDCIMDPIgqe//P8D4MFoAmY+kHkVeAE2eWBqPfrzmItkPdDeU/ofgE9JPKxpovxyR6rD6U1RQEOj+j4KiAoKSHxsFBND1iV8QhMYTBKDTKOHx/wAjhP4Ai99/IPqHAAF34ZEnlhaVnCj/V1BQkIj4E2BgpGo8EBXvoHD4Rx378NJioHD/Qdf0hyu/kpTPRKAscsMXlYbxBhAwAgAY6lZ1'}Nov 21 04:58:06 localhost SMGC: [21457] Num combined blocks = 841
Nov 21 04:58:06 localhost SMGC: [21457] Coalesced size = 1.646G
Nov 21 04:58:06 localhost SMGC: [21457] Coalesce candidate: *49341e2f(20.000G/34.110M) (tree height 3)
Nov 21 04:58:06 localhost SMGC: [21457] Coalescing *49341e2f(20.000G/34.110M) -> *1ba82e64(20.000G/1.646G)
Nov 21 04:58:06 localhost SM: [21457] ['/usr/bin/vhd-util', 'check', '--debug', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/49341e2f-2b34-4f40-aa8a-0486a6cd14f8.vhd']
Nov 21 04:58:06 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:06 localhost SM: [21457] ['/usr/bin/vhd-util', 'check', '--debug', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1ba82e64-3a86-4cb0-b708-d6ddffe02214.vhd', '-B']
Nov 21 04:58:06 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:06 localhost SMGC: [21457] Running VHD coalesce on *49341e2f(20.000G/34.110M)
Nov 21 04:58:06 localhost SM: [21526] ['/usr/bin/vhd-util', 'coalesce', '--debug', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/49341e2f-2b34-4f40-aa8a-0486a6cd14f8.vhd']
Nov 21 04:58:11 localhost SM: [21526] pread SUCCESS
Nov 21 04:58:11 localhost SM: [21526] IPCFlag: set 1f273ffb-3583-4a91-0c30-faa4951e7df8:success
Nov 21 04:58:11 localhost SMGC: [21457] Child process completed successfully
Nov 21 04:58:11 localhost SM: [21457] IPCFlag: clear 1f273ffb-3583-4a91-0c30-faa4951e7df8:success
Nov 21 04:58:11 localhost SM: [21457] ['/usr/bin/vhd-util', 'check', '--debug', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1ba82e64-3a86-4cb0-b708-d6ddffe02214.vhd', '-B']
Nov 21 04:58:11 localhost SM: [21457] pread SUCCESS
@
Nov 21 04:58:11 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr, acquired: True (exists: True)
Nov 21 04:58:11 localhost SM: [21457] ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/*.vhd']
Nov 21 04:58:11 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:11 localhost SMGC: [21457] SR 1f27 ('9c0576b9-d3e8-3023-bed9-1e9a46a40d54') (11 VDIs in 3 VHD trees): no changes
Nov 21 04:58:11 localhost SMGC: [21457] Relinking 1cf9e9f7(20.000G/16.292M) from *49341e2f(20.000G/34.110M) to *1ba82e64(20.000G/1.646G)
Nov 21 04:58:11 localhost SM: [21457] ['/usr/bin/vhd-util', 'modify', '--debug', '-p', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1ba82e64-3a86-4cb0-b708-d6ddffe02214.vhd', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1cf9e9f7-862e-4426-9416-584987b9cfbd.vhd']
Nov 21 04:58:12 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:12 localhost SMGC: [21457] Set vhd-parent = 1ba82e64-3a86-4cb0-b708-d6ddffe02214 for 1cf9e9f7(20.000G/16.292M)
Nov 21 04:58:12 localhost SMGC: [21457] Updated the vhd-parent field for child 1cf9e9f7-862e-4426-9416-584987b9cfbd with 1ba82e64-3a86-4cb0-b708-d6ddffe02214
Nov 21 04:58:12 localhost SMGC: [21457] Relinking 2caf017c(20.000G/45.500K) from *49341e2f(20.000G/34.110M) to *1ba82e64(20.000G/1.646G)
Nov 21 04:58:12 localhost SM: [21457] ['/usr/bin/vhd-util', 'modify', '--debug', '-p', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1ba82e64-3a86-4cb0-b708-d6ddffe02214.vhd', '-n', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/2caf017c-a653-4b05-92fb-b8b29285fbb5.vhd']
Nov 21 04:58:12 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:12 localhost SMGC: [21457] Set vhd-parent = 1ba82e64-3a86-4cb0-b708-d6ddffe02214 for 2caf017c(20.000G/45.500K)
Nov 21 04:58:12 localhost SMGC: [21457] Updated the vhd-parent field for child 2caf017c-a653-4b05-92fb-b8b29285fbb5 with 1ba82e64-3a86-4cb0-b708-d6ddffe02214
Nov 21 04:58:12 localhost SM: [21457] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:12 localhost SMGC: [21457] Reloading VDI 1cf9e9f7(20.000G/16.292M)
Nov 21 04:58:12 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr, acquired: True (exists: True)
Nov 21 04:58:12 localhost SM: [21457] Refresh request for 1cf9e9f7-862e-4426-9416-584987b9cfbd
Nov 21 04:58:12 localhost SM: [21457] Calling tap-refresh on host OpaqueRef:4366ea2d-224b-fa03-65d6-a53c18b0c77f
Nov 21 04:58:12 localhost SM: [21570] lock: opening lock file /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:58:12 localhost SM: [21570] lock: acquired /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:58:12 localhost SM: [21570] Pause for 1cf9e9f7-862e-4426-9416-584987b9cfbd
Nov 21 04:58:12 localhost SM: [21570] Calling tap pause with minor 1
Nov 21 04:58:12 localhost SM: [21570] ['/usr/sbin/tap-ctl', 'pause', '-p', '18621', '-m', '1']
Nov 21 04:58:12 localhost SM: [21570] = 0
Nov 21 04:58:12 localhost SM: [21570] lock: released /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:58:12 localhost SM: [21570] lock: acquired /var/lock/sm/1cf9e9f7-862e-4426-9416-584987b9cfbd/vdi
Nov 21 04:58:12 localhost SM: [21570] Unpause for 1cf9e9f7-862e-4426-9416-584987b9cfbd
Nov 21 04:58:12 localhost SM: [21570] Realpath: /var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/1cf9e9f7-862e-4426-9416-584987b9cfbd.vhd
Nov 21 04:58:12 localhost SM: [21570] Calling tap unpause with minor 1
Nov 21 04:58:13 localhost SM: [21457] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/running
Nov 21 04:58:13 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr, acquired: True (exists: True)
Nov 21 04:58:13 localhost SM: [21457] ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/*.vhd']
Nov 21 04:58:13 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:13 localhost SMGC: [21457] SR 1f27 ('9c0576b9-d3e8-3023-bed9-1e9a46a40d54') (11 VDIs in 3 VHD trees): showing only VHD trees that changed:
Nov 21 04:58:13 localhost SMGC: [21457] *1ba82e64(20.000G/1.646G)
Nov 21 04:58:13 localhost SMGC: [21457] 1cf9e9f7(20.000G/18.079M)
Nov 21 04:58:13 localhost SMGC: [21457] 2caf017c(20.000G/45.500K)
Nov 21 04:58:13 localhost SMGC: [21457] *49341e2f(20.000G/34.110M)
Nov 21 04:58:13 localhost SMGC: [21457]
Nov 21 04:58:13 localhost SM: [21457] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:13 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/running, acquired: True (exists: True)
Nov 21 04:58:13 localhost SM: [21457] lock: tried lock /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr, acquired: True (exists: True)
Nov 21 04:58:13 localhost SM: [21457] ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/var/run/sr-mount/1f273ffb-3583-4a91-0c30-faa4951e7df8/*.vhd']
Nov 21 04:58:13 localhost SM: [21457] pread SUCCESS
Nov 21 04:58:13 localhost SMGC: [21457] SR 1f27 ('9c0576b9-d3e8-3023-bed9-1e9a46a40d54') (11 VDIs in 3 VHD trees): no changes
Nov 21 04:58:13 localhost SM: [21457] lock: released /var/lock/sm/1f273ffb-3583-4a91-0c30-faa4951e7df8/sr
Nov 21 04:58:13 localhost SMGC: [21457] Got sm-config for *5c212631(2.441G/2.446G):
Nov 21 04:58:13 localhost SMGC: [21457] Got sm-config for *745072fa(20.000G/1.638G):
{'vhd-blocks': 'eJz7398BBHv/A8HX0NDQAAYwEIBQDCIMDPIgqe//P8D4MFoAmY+kHkVeAE2eWBqPfrzmItkPdDeU/ofgE9JPKxpovxyR6rD6U1RQEOj+j4KiAgKSHxsFBND1iV8QhMYTBKDTKOHx/wAjhP4Ai99/IPqHAAF34ZEnlhaVnCD/V1BQkIj4E2BgpGo8EBXvoHD4Rx378NJioHD/Qdf0hyu/kpXPqKAeiTeAgBEAAsJWXw=='}Nov 21 04:58:13 localhost SMGC: [21457] Got sm-config for *1ba82e64(20.000G/1.646G):
{'base_mirror': 'a847ec21-9d04-4a8c-5e7f-cf52b2f56b75/3b790b0e-6216-4277-a4ce-62aee1d03a35', 'vhd-blocks': 'eJz7398BBHv/A8HX0NDQAAYwEIBQDCIMDPIgqe//P8D4MFoAmY+kHkVeAE2eWBqPfrzmItkPdDeU/ofgE9JPKxpovxyR6rD6U1RQEOj+j4KiAoKSHxsFBND1iV8QhMYTBKDTKOHx/wAjhP4Ai99/IPqHAAF34ZEnlhaVnCj/V1BQkIj4E2BgpGo8EBXvoHD4Rx378NJioHD/Qdf0hyu/kpTPRKAscsMXlYbxBhAwAgAY6lZ1'}Nov 21 04:58:13 localhost SMGC: [21457] Got sm-config for *837da6ea(20.000G/112.262M):
{'vhd-parent': '745072fa-345a-4a7b-99a3-0c3789831146', 'vhd-blocks': 'eJxrYAAB0QcMKECEEUKzMAxNIAClWdD4AwUotV9EQFCCgVGRQQSHUSI47MNlL7o8vcJHVFBQqlFQkJFO1pEM6BUO9E6PtM7HA52/yAcAa1ED4w=='}Nov 21 04:58:13 localhost SMGC: [21457] Found 1 VDIs for deletion:
Nov 21 04:58:13 localhost SMGC: [21457] *49341e2f(20.000G/34.110M)
Nov 21 04:58:13 localhost SMGC: [21457] Deleting unlinked VDI *49341e2f(20.000G/34.110M)