XO CE migrate fails for WinServer 2019 VM - "Internal Error"

olivierlambert

Hi,

I already answered in your ticket. This INTERNAL_ERROR is very likely a message coming from your hosts.

Zevgeny

I didn't make a ticket, are you mixing me up with someone else?

What does "coming from my hosts" mean? Is there a way to fix it?

olivierlambert

We had a similar ticket few hours ago, so I thought it was you

When you have a message in caps, it's not an error raised by Xen Orchestra but the host itself. Check /var/log/xensource.log on both origin and destination.

Zevgeny

@olivierlambert

Ok, thanks. Looking at the logs, on the destination I have:

May 21 16:11:03 xcp-city xapi: [ info||26394 |sm_exec D:752d1fc8c534|xapi] Session.destroy trackid=3a03a0a503d1835c77a2b5f0fd6a72e7
May 21 16:11:03 xcp-city xapi: [error||26394 ||backtrace] SR.update_snapshot_info_dest D:d6734facb4b7 failed with exception Storage_error ([S(Vdi_does_not_exist);S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)])
May 21 16:11:03 xcp-city xapi: [error||26394 ||backtrace] Raised Storage_error ([S(Vdi_does_not_exist);S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)])
May 21 16:11:03 xcp-city xapi: [error||26394 ||backtrace] 1/1 xapi Raised at file (Thread 26394 has no backtrace table. Was with_backtraces called?, line 0
May 21 16:11:03 xcp-city xapi: [error||26394 ||backtrace]
May 21 16:11:03 xcp-city xapi: [error||26394 ||storage_interface] Storage_error ([S(Vdi_does_not_exist);S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)]) (File "storage/storage_interface.ml", line 420, characters 51-58)
May 21 16:11:03 xcp-city xapi: [error||26393 INET :::80|Querying services D:201bbc002f53|storage_interface] Storage_error ([S(Vdi_does_not_exist);S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)]) (File "storage/storage_interface.ml", line 415, characters 50-57)
May 21 16:11:03 xcp-city xapi: [error||26393 INET :::80|Querying services D:201bbc002f53|storage_interface] Storage_error ([S(Vdi_does_not_exist);S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)]) (File "storage/storage_interface.ml", line 420, characters 51-58)
May 21 16:11:03 xcp-city xapi: [debug||26431 INET :::80|VDI.destroy R:0ad894504975|audit] VDI.destroy: VDI = '89138ba9-5f99-4aff-b31e-eac8cfa8b770'
May 21 16:11:03 xcp-city xapi: [debug||26431 INET :::80|VDI.destroy R:0ad894504975|xapi] Marking SR for VDI.destroy (task=OpaqueRef:0ad89450-4975-4351-8aba-d7539053149e)
May 21 16:11:03 xcp-city xapi: [ info||26431 INET :::80|VDI.destroy R:0ad894504975|storage_impl] VDI.destroy dbg:OpaqueRef:0ad89450-4975-4351-8aba-d7539053149e sr:804aa716-a6a4-4a3f-eb61-c5ed8cf3d5d1 vdi:89138ba9-5f99-4aff-b31e-eac8cfa8b770
May 21 16:11:03 xcp-city xapi: [debug||26432 ||dummytaskhelper] task VDI.destroy D:2cae65adf172 created by task R:0ad894504975
May 21 16:11:03 xcp-city xapi: [debug||26432 |VDI.destroy D:2cae65adf172|sm] SM ext vdi_delete sr=OpaqueRef:092deaa1-1231-4582-af4a-2dd534bed230 vdi=OpaqueRef:0e9a41bf-d3ba-40d5-9ca4-093993c5e26f
May 21 16:11:03 xcp-city xapi: [ info||26432 |sm_exec D:3e5a4b7ceb3f|xapi] Session.create trackid=4362bd9f5977710ee42e782266f47978 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49

On the source I have:

May 21 16:11:03 xcp-ks xapi: [debug||659737 INET :::80|Querying services D:d12ab4a9d5ab|storage_utils] Got failure: checking for redirect, call was: -> SR.update_snapshot_info_dest({snapshot_pairs:{89138ba9-5f99-4aff-b31e-eac8cfa8b770:{sm_config:{};sharable:B(false);persistent:B(true);physical_utilisation:I(27865494016);virtual_size:I(429496729600);cbt_enabled:B(false);read_only:B(false);snapshot_of:S(5c6f3101-d882-424d-a9d6-2eab74d50580);snapshot_time:S(20200517T16:57:15Z);is_a_snapshot:B(true);metadata_of_pool:S(OpaqueRef:NULL);ty:S(user);name_description:S(Windows Server 2019);name_label:S(WinServer2019_1);content_id:S(14404412-0937-8864-37ab-a172202c4fea);uuid:S(f63e8763-1e05-4144-8868-97d94aedd9bb);vdi:S(f63e8763-1e05-4144-8868-97d94aedd9bb)}};src_vdi:{sm_config:{read-caching-reason-c3a60480-69b0-4e62-bbcc-556735cbc87a:S(NO_RO_IMAGE);host_OpaqueRef:fc79e865-1cad-4ce1-99f7-25c2fcb074dd:S(RW);read-caching-enabled-on-c3a60480-69b0-4e62-bbcc-556735cbc87a:S(false)};sharable:B(false);persistent:B(true);physical_utilisation:I(27865494016);virtual_size:I(429496729600);cbt_enabled:B(false);read_only:B(false);snapshot_of:S();snapshot_time:S(19700101T00:00:00Z);is_a_snapshot:B(false);metadata_of_pool:S();ty:S(user);name_description:S(Windows Server 2019);name_label:S(WinServer2019_1);content_id:S(5c6f3101-d882-424d-a9d6-2eab74d50580);uuid:S(5c6f3101-d882-424d-a9d6-2eab74d50580);vdi:S(5c6f3101-d882-424d-a9d6-2eab74d50580)};vdi:S(903e8b04-97b3-4e38-9329-5e52ba9a9b6f);sr:S(ca984ce3-ae6a-d8c5-6233-fa09c777d811);dbg:S(Async.VM.migrate_send R:7b3970459a73)}), results.contents: ["Vdi_does_not_exist","89138ba9-5f99-4aff-b31e-eac8cfa8b770"]
May 21 16:11:03 xcp-ks xapi: [debug||659737 INET :::80|Querying services D:d12ab4a9d5ab|storage_utils] Not a redirect: -> SR.update_snapshot_info_dest({snapshot_pairs:{89138ba9-5f99-4aff-b31e-eac8cfa8b770:{sm_config:{};sharable:B(false);persistent:B(true);physical_utilisation:I(27865494016);virtual_size:I(429496729600);cbt_enabled:B(false);read_only:B(false);snapshot_of:S(5c6f3101-d882-424d-a9d6-2eab74d50580);snapshot_time:S(20200517T16:57:15Z);is_a_snapshot:B(true);metadata_of_pool:S(OpaqueRef:NULL);ty:S(user);name_description:S(Windows Server 2019);name_label:S(WinServer2019_1);content_id:S(14404412-0937-8864-37ab-a172202c4fea);uuid:S(f63e8763-1e05-4144-8868-97d94aedd9bb);vdi:S(f63e8763-1e05-4144-8868-97d94aedd9bb)}};src_vdi:{sm_config:{read-caching-reason-c3a60480-69b0-4e62-bbcc-556735cbc87a:S(NO_RO_IMAGE);host_OpaqueRef:fc79e865-1cad-4ce1-99f7-25c2fcb074dd:S(RW);read-caching-enabled-on-c3a60480-69b0-4e62-bbcc-556735cbc87a:S(false)};sharable:B(false);persistent:B(true);physical_utilisation:I(27865494016);virtual_size:I(429496729600);cbt_enabled:B(false);read_only:B(false);snapshot_of:S();snapshot_time:S(19700101T00:00:00Z);is_a_snapshot:B(false);metadata_of_pool:S();ty:S(user);name_description:S(Windows Server 2019);name_label:S(WinServer2019_1);content_id:S(5c6f3101-d882-424d-a9d6-2eab74d50580);uuid:S(5c6f3101-d882-424d-a9d6-2eab74d50580);vdi:S(5c6f3101-d882-424d-a9d6-2eab74d50580)};vdi:S(903e8b04-97b3-4e38-9329-5e52ba9a9b6f);sr:S(ca984ce3-ae6a-d8c5-6233-fa09c777d811);dbg:S(Async.VM.migrate_send R:7b3970459a73)})
May 21 16:11:03 xcp-ks xapi: [error||659737 INET :::80|Querying services D:d12ab4a9d5ab|storage_interface] Storage_error ([S(Vdi_does_not_exist);S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)]) (File "storage/storage_interface.ml", line 415, characters 50-57)
May 21 16:11:03 xcp-ks xapi: [error||659737 INET :::80|Querying services D:d12ab4a9d5ab|storage_interface] Storage_error ([S(Vdi_does_not_exist);S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)]) (File "storage/storage_interface.ml", line 420, characters 51-58)
May 21 16:11:03 xcp-ks xapi: [ info||659781 INET :::80|session.logout D:4442ecf278e4|xapi] Session.destroy trackid=6a5d0e22ea7dba90ac67ed8c0793d10d
May 21 16:11:03 xcp-ks xapi: [debug||655224 ||storage_utils] Got failure: checking for redirect, call was: -> SR.update_snapshot_info_src({snapshot_pairs:{f63e8763-1e05-4144-8868-97d94aedd9bb:S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)};dest_vdi:S(903e8b04-97b3-4e38-9329-5e52ba9a9b6f);dest:S(ca984ce3-ae6a-d8c5-6233-fa09c777d811);url:S(http://192.168.176.194/services/SM?session_id=OpaqueRef:06fb504b-e893-46d7-a468-c1f3b3288293);vdi:S(5c6f3101-d882-424d-a9d6-2eab74d50580);sr:S(779795f5-d9de-7623-e993-2a8b6007cdca);dbg:S(Async.VM.migrate_send R:7b3970459a73)}), results.contents: ["Vdi_does_not_exist","89138ba9-5f99-4aff-b31e-eac8cfa8b770"]
May 21 16:11:03 xcp-ks xapi: [debug||655224 ||storage_utils] Not a redirect: -> SR.update_snapshot_info_src({snapshot_pairs:{f63e8763-1e05-4144-8868-97d94aedd9bb:S(89138ba9-5f99-4aff-b31e-eac8cfa8b770)};dest_vdi:S(903e8b04-97b3-4e38-9329-5e52ba9a9b6f);dest:S(ca984ce3-ae6a-d8c5-6233-fa09c777d811);url:S(http://192.168.176.194/services/SM?session_id=OpaqueRef:06fb504b-e893-46d7-a468-c1f3b3288293);vdi:S(5c6f3101-d882-424d-a9d6-2eab74d50580);sr:S(779795f5-d9de-7623-e993-2a8b6007cdca);dbg:S(Async.VM.migrate_send R:7b3970459a73)})

My VM has some snapshots (taken with XO), would that cause problems with the migration? Why does it work in XCP-ng Center?

olivierlambert

@Zevgeny said in XO CE migrate fails for WinServer 2019 VM - "Internal Error":

Why does it work in XCP-ng Center?

This is a good question It might be indeed related to snaphots. Maybe XCP-ng Center is managing this in a different way

How many snapshots do you have for this VM?

Zevgeny

@olivierlambert Just 1 snapshot.

Previously we were using VirtualBox (we are just starting to move out of the cardboard and duct tape level of IT infra... ), and snapshots were terrifyingly scary in how often they break things.

Is this the case with XCP-NG? Should we avoid snapshots?

olivierlambert

It might be just a missing param in some cases of snapshots for a live migration. Snapshots are the way to do many things in XCP-ng, and it works.

Is there a way to remove the snapshot, and test the migration for this VM (in XO)?

I'd like to understand the exact cases when XO can't migrate vs XCP-ng Center, so we could spot the difference.

Zevgeny

@olivierlambert I finally got the thing to where I wanted after many hours, so maybe I'll make a copy of it and then try to migrate the copy.

Zevgeny

@olivierlambert Hmm, I successfully moved the copy, took a snapshot, successfully moved it again.
Then I tried the original problem VM, and was able to move it as well.

The problem VM was actively being used / run, so I guess things fixed themselves after its state changed? I have no idea.

Hopefully, it never happens again, sorry for the false alarm.

olivierlambert

Hard to tell. If it happens again, try immediately to compare XO behavior with other clients to see if we can tell where is the problem