Host-based backup of VMware vSphere VMs.
Post Reply
Asahi
Expert
Posts: 143
Liked: 7 times
Joined: Jun 03, 2016 5:44 am
Full Name: Iio Asahi
Location: Japan
Contact:
Contact Asahi

Upload operation of .tmp files using VIX after starting data transfer task

Post by Asahi »

Hi,

Can someone please help me with the AAIP quiescence process via VMware Tools (VIX). :D
I understand that in an environment where there is no RPC communication with the VM, the runtime process is uploaded to the guest OS via VIX for quiescence processing.
https://helpcenter.veeam.com/docs/backu ... ml?ver=110

Once the quiescent process is finished, the data transfer task would then be executed.
The following log indicates that the data transfer task has started.
===
[26.05.2022 20:25:35] <43> Info [AP] (4b59) command: 'Invoke: DataTransfer.SyncDisk
===

However, looking at the task log, it appears that it is continuously uploading .tmp files to the guest OS and ESXi hosts even after the data transfer task has started.
It is always logged between "VSSControl: KeepSnapshot started" and "VSSControl: KeepSnapshot completed", which is running continuously until the data transfer task is completed.

Code: Select all

===
[26.05.2022 20:25:47] <27> Info                   [AP] (a6a2) output: --asyncNtf:disk_capacity: '536870912000'
[26.05.2022 20:25:47] <33> Info                   [AP] (4b59) output: --asyncNtf:disk_capacity: '536870912000'
[26.05.2022 20:25:47] <31> Info                   [AP] (8004) output: --asyncNtf:disk_capacity: '536870912000'
[26.05.2022 20:25:47] <52> Info                   [AP] (0237) output: --asyncNtf:disk_capacity: '536870912000'
[26.05.2022 20:26:01] <51> Info                   [AP] (4b59) output: --size: 536870912000
[26.05.2022 20:26:01] <52> Info                   [AP] (4b59) output: --pex:0;1048576;0;1048576;0;32;97;0;0;0;0;0;132980379615210000
[26.05.2022 20:26:28] <54> Info                   [AP] (4b59) output: --pex:0;862978048;185597952;605028352;185597952;74949830;89;64;36;99;2;97;132980379886790000
[26.05.2022 20:26:45] <41> Info         [b]VSSControl: KeepSnapshot started[/b], ttl 1200 sec
[26.05.2022 20:26:45]  26640  Info             Uploading file [C:\Windows\TEMP\ifdCEEF.tmp] to guest [vm-xxxx] destination [C:\Users\ADMINI~1\AppData\Local\Temp\{4006b84a-96f5-4f83-97a8-9850e10e7f26}]
[26.05.2022 20:26:45]  26640  Info             Uploading file [C:\Windows\TEMP\ifdCEEF.tmp] to [https://esxihostname:443/]
[26.05.2022 20:26:45]  26640  Info             Active file HTTP session was registered [{f1a7f00e-7b3e-421a-9e3f-a40f078ed2fc}].
[26.05.2022 20:26:45]  26640  Info             Writing file [C:\Windows\TEMP\ifdCEEF.tmp] of size [44] to the HTTP server
[26.05.2022 20:26:45]  26640  Info             Sending HTTP request with Content-Length [44] to the HTTP server
[26.05.2022 20:26:45]  26640  Info             Sending HTTP request with Content-Length [44] to the HTTP server. Ok.
[26.05.2022 20:26:45]  26640  Info             Uploaded 100%
[26.05.2022 20:26:45]  26640  Info             Receiving response from the HTTP server, receive timeout (sec): 60
[26.05.2022 20:26:45]  26640  Info             Receiving response from the HTTP server, receive timeout (sec): 60. Ok.
[26.05.2022 20:26:45]  26640  Info             Writing file [C:\Windows\TEMP\ifdCEEF.tmp] of size [44] to the HTTP server. Ok.
[26.05.2022 20:26:45]  26640  Info             Uploading file [C:\Windows\TEMP\ifdCEEF.tmp] to [https://esxihostname:443/guestFile?id=34&token=520447fb-9f34-cec6-7bff-a1f735b71edd34]. Ok.
[26.05.2022 20:26:45]  26640  Info             Active files transfer session [{f1a7f00e-7b3e-421a-9e3f-a40f078ed2fc}] was successfully unregistered.
[26.05.2022 20:26:45]  26640  Info             Uploading file [C:\Windows\TEMP\ifdCEEF.tmp] to guest [vm-xxxx] destination [C:\Users\ADMINI~1\AppData\Local\Temp\{4006b84a-96f5-4f83-97a8-9850e10e7f26}]. Ok.
[26.05.2022 20:26:45]  26640  Info             Setting "execute" permission for file [C:\Users\ADMINI~1\AppData\Local\Temp\{f34bbd16-51e9-425e-a81b-806432cf0380}]
[26.05.2022 20:26:45]  26640  Info             Changing guest [vm-xxxx] file [C:\Users\ADMINI~1\AppData\Local\Temp\{f34bbd16-51e9-425e-a81b-806432cf0380}] attributes
[26.05.2022 20:26:45]  26640  Info             Changing guest [vm-xxxx] file [C:\Users\ADMINI~1\AppData\Local\Temp\{f34bbd16-51e9-425e-a81b-806432cf0380}] attributes. Failed.
[26.05.2022 20:26:45]  26640  Info             Setting "execute" permission for file [C:\Users\ADMINI~1\AppData\Local\Temp\{f34bbd16-51e9-425e-a81b-806432cf0380}]. Failed.
[26.05.2022 20:26:45]  26640  Info             Could not set "execute" permission for file [C:\Users\ADMINI~1\AppData\Local\Temp\{f34bbd16-51e9-425e-a81b-806432cf0380}]
[26.05.2022 20:26:45]  26640  Info             Could not change guest [vm-xxxx] file [C:\Users\ADMINI~1\AppData\Local\Temp\{f34bbd16-51e9-425e-a81b-806432cf0380}] attributes
[26.05.2022 20:26:45]  26640  Info             Could not invoke guest operation
[26.05.2022 20:26:45]  26640  Info             A specified parameter was not correct: 
[26.05.2022 20:26:45]  26640  Info             Running guest [vm-xxxx] program [C:\Users\ADMINI~1\AppData\Local\Temp\{f34bbd16-51e9-425e-a81b-806432cf0380}] with arguments [-func BlobCall -out "C:\Users\ADMINI~1\AppData\Local\Temp\{ac2c7bf2-0b42-4e8a-a639-420eb4d90ab2}" -blob ******** -glogin "administrator" -gpwd ********]
[26.05.2022 20:26:45]  26640  Info             Waiting for guest [vm-xxxx] process with PID [9368] to finish, timeout: 3600000, tryRate: 1000
[26.05.2022 20:26:45]  26640  Info             Getting status of the guest [vm-xxxx] process with PID [9368], timeout: 3600000
[26.05.2022 20:26:45]  26640  Info             Listing processes with PIDs [9368,] in guest [vm-xxxx]
[26.05.2022 20:26:45]  26640  Info             Listing processes with PIDs [9368,] in guest [vm-xxxx]. Ok.
[26.05.2022 20:26:45]  26640  Info             Getting status of the guest [vm-xxxx] process with PID [9368], timeout: 3600000. Ok.
[26.05.2022 20:26:46]  26640  Info             Getting status of the guest [vm-xxxx] process with PID [9368], timeout: 3598957
[26.05.2022 20:26:46]  26640  Info             Listing processes with PIDs [9368,] in guest [vm-xxxx]
[26.05.2022 20:26:46]  26640  Info             Listing processes with PIDs [9368,] in guest [vm-xxxx]. Ok.
[26.05.2022 20:26:46]  26640  Info             Getting status of the guest [vm-xxxx] process with PID [9368], timeout: 3598957. Ok.
[26.05.2022 20:26:46]  26640  Info             Waiting for guest [vm-xxxx] process with PID [9368] to finish, timeout: 3600000, tryRate: 1000. Ok.
[26.05.2022 20:26:46]  26640  Info             Running guest [vm-xxxx] program [C:\Users\ADMINI~1\AppData\Local\Temp\{f34bbd16-51e9-425e-a81b-806432cf0380}] with arguments [-func BlobCall -out "C:\Users\ADMINI~1\AppData\Local\Temp\{ac2c7bf2-0b42-4e8a-a639-420eb4d90ab2}" -blob ******** -glogin "administrator" -gpwd ********]. Ok.
[26.05.2022 20:26:46]  26640  Info             Downloading file [C:\Users\ADMINI~1\AppData\Local\Temp\{ac2c7bf2-0b42-4e8a-a639-420eb4d90ab2}] from guest [vm-xxxx] destination [C:\Windows\TEMP\ifdCFFA.tmp]
[26.05.2022 20:26:47]  26640  Info             Downloading file [C:\Windows\TEMP\ifdCFFA.tmp] from [https://esxihostname:443/guestFile?id=34&token=526d7acd-da26-21d4-7ee8-6c77ca42e49f34]
[26.05.2022 20:26:47]  26640  Info             Active file HTTP session was registered [{9aaaf9e0-489b-4f19-a4d1-186dc5f79a88}].
[26.05.2022 20:26:47]  26640  Info             Reading file [C:\Windows\TEMP\ifdCFFA.tmp] of size [66] from the HTTP server
[26.05.2022 20:26:47]  26640  Info             Sending HTTP request with Content-Length [66] to the HTTP server
[26.05.2022 20:26:47]  26640  Info             Sending HTTP request with Content-Length [66] to the HTTP server. Ok.
[26.05.2022 20:26:47]  26640  Info             Receiving response from the HTTP server, receive timeout (sec): 60
[26.05.2022 20:26:47]  26640  Info             Receiving response from the HTTP server, receive timeout (sec): 60. Ok.
[26.05.2022 20:26:47]  26640  Info             Downloaded 100%
[26.05.2022 20:26:47]  26640  Info             Reading file [C:\Windows\TEMP\ifdCFFA.tmp] of size [66] from the HTTP server. Ok.
[26.05.2022 20:26:47]  26640  Info             Downloading file [C:\Windows\TEMP\ifdCFFA.tmp] from [https://esxihostname:443/guestFile?id=34&token=526d7acd-da26-21d4-7ee8-6c77ca42e49f34]. Ok.
[26.05.2022 20:26:47]  26640  Info             Active files transfer session [{9aaaf9e0-489b-4f19-a4d1-186dc5f79a88}] was successfully unregistered.
[26.05.2022 20:26:47]  26640  Info             Downloading file [C:\Users\ADMINI~1\AppData\Local\Temp\{ac2c7bf2-0b42-4e8a-a639-420eb4d90ab2}] from guest [vm-xxxx] destination [C:\Windows\TEMP\ifdCFFA.tmp]. Ok.
[26.05.2022 20:26:47]  26640  Info             Deleting guest [vm-xxxx] file [C:\Users\ADMINI~1\AppData\Local\Temp\{ac2c7bf2-0b42-4e8a-a639-420eb4d90ab2}]
[26.05.2022 20:26:47]  26640  Info             Deleting guest [vm-xxxx] file [C:\Users\ADMINI~1\AppData\Local\Temp\{ac2c7bf2-0b42-4e8a-a639-420eb4d90ab2}]. Ok.
[26.05.2022 20:26:47]  26640  Info             Deleting guest [vm-xxxx] file [C:\Users\ADMINI~1\AppData\Local\Temp\{4006b84a-96f5-4f83-97a8-9850e10e7f26}]
[26.05.2022 20:26:47]  26640  Info             Deleting guest [vm-xxxx] file [C:\Users\ADMINI~1\AppData\Local\Temp\{4006b84a-96f5-4f83-97a8-9850e10e7f26}]. Ok.
[26.05.2022 20:26:47] <41> Info         [b]VSSControl: KeepSnapshot completed[/b], ttl 1200 sec
===
I was under the impression that the VSS quiescence process is complete before the data transfer task starts, so the files are not continuously uploaded to the guest OS. :shock:
Will the .tmp file still be uploaded after the data transfer task is started?

Kind Regards,
Asahi,
Climb Inc.
Top
HannesK
Product Manager
Posts: 14839
Liked: 3086 times
Joined: Sep 01, 2014 11:46 am
Full Name: Hannes Kasparick
Location: Austria
Contact:
Contact HannesK

Re: Upload operation of .tmp files using VIX after starting data transfer task

Post by HannesK »

Hello,
I understand that in an environment where there is no RPC communication with the VM, the runtime process is uploaded to the guest OS via VIX for quiescence processing.
correct.

before doing any investigation... do you see any technical issue, or is it a question about log file interpretation of the "'Invoke: DataTransfer.SyncDisk" command?

If there is a technical issue, what is the case number for that problem?

Thanks,
Hannes
Top
Asahi
Expert
Posts: 143
Liked: 7 times
Joined: Jun 03, 2016 5:44 am
Full Name: Iio Asahi
Location: Japan
Contact:
Contact Asahi

Re: Upload operation of .tmp files using VIX after starting data transfer task

Post by Asahi »

Hi Hannes,

Thank you for reply.

> before doing any investigation... do you see any technical issue,
> or is it a question about log file interpretation of the "'Invoke: DataTransfer.SyncDisk" command?

I simply wanted to confirm that the behavior of uploading the .tmp to the VM and ESXi hosts after the data transfer is performed is a spec behavior of Veeam.
If it is a specificate behavior, I do not understand why the file upload is necessary.

Kind Regards,
Asahi,
Climb Inc.
Top
HannesK
Product Manager
Posts: 14839
Liked: 3086 times
Joined: Sep 01, 2014 11:46 am
Full Name: Hannes Kasparick
Location: Austria
Contact:
Contact HannesK

Re: Upload operation of .tmp files using VIX after starting data transfer task

Post by HannesK »

Hello,
If there is no problem, then it sounds good to me :-)

It makes little sense trying to interpret that kind of log entries. Please understand, that we keep some information "internal only".

Thanks for your understanding,
Hannes
Top
Post Reply

Return to “VMware vSphere”



Who is online

Users browsing this forum: No registered users and 51 guests