DanVM99
Enthusiast
Enthusiast

Thanks for your input but I think our issue differs from yours in so much as our VMs seem to be connecting to the manager rather than re-attempting connection like yours. They just don't get the AppStacks for some reason. I've included a lager chunck of our example fail log in case anyone notices any commonality with their own. It begins from the point a user first logs on to a VM. I've not included the prior section where the VM is originally provisioned and connects successfully to the AppVols Manager.

[2019-06-03 07:41:10.961 UTC] [svservice:P1124:T1128] *** Started

[2019-06-03 07:41:10.961 UTC] [svservice:P1124:T1128] Running from: C:\Program Files\CloudVolumes\Agent\svservice.exe (release build)

[2019-06-03 07:41:10.961 UTC] [svservice:P1124:T1208] Checking agent version from "C:\Program Files\CloudVolumes\Agent\VERSION32.txt"

[2019-06-03 07:41:10.961 UTC] [svservice:P1124:T1208] Build: "Release-Agent-Build-32-2_16_0" (letter U)

[2019-06-03 07:41:10.961 UTC] [svservice:P1124:T1208] Build version: "2.16.0.23U"

[2019-06-03 07:41:10.961 UTC] [svservice:P1124:T1208] CheckOfflineVHDMode: dwResetWritableDays was set to (0) days, turn off offline mode!

[2019-06-03 07:41:10.961 UTC] [svservice:P1124:T1208] VHD offline mode was off!

[2019-06-03 07:41:10.961 UTC] [svservice:P1124:T1208] ServiceInit starting

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] Running on Windows 6.1 build 7601 (service pack 1.0)

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] OS is a workstation

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] Architecture: x86 (2 processors)

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] Running as: DOMAIN\WINDOWS7-099$ (NameSamCompatible)

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] Setting status to SERVICE_START_PENDING

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] MachineSID is "S-1-5-21-3842748544-3961479084-860730781"

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] Hypervisor configured as: vcenter

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] Successfully created RunKey event

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] CleanUpSystemDrive: Flag CleanSystemWritable was configured, auto cleanup the system writable directories...

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] Moving C:\SnapVolumesTemp to C:\SnapVolumesTemp.old

[2019-06-03 07:41:10.976 UTC] [svservice:P1124:T1208] CleanUpSystemDrive: deleted "C:\SnapVolumesTemp"

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] Processing of Scheduled Tasks is disabled

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] Using 8 worker threads to communicate with driver

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] InitializeWmi: called

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] UpdateInteractiveSessionCount: SessionId 0 Name(Services) State(4)

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] UpdateInteractiveSessionCount: SessionId 1 Name(Console) State(2)

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] UpdateInteractiveSessionCount: Found 0 active / 2 total user session(s)

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] Setting the following data in Run key for svservice : "C:\Program Files\CloudVolumes\Agent\svservice.exe"fromrunkey

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] HttpComputerStartup: called 0 logged in (computer startup)

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] svdriver is running

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1208] Becoming trusted installer

[2019-06-03 07:41:10.992 UTC] [svservice:P1124:T1272] HandleNGVC: NGVC not present, error 2

[2019-06-03 07:41:11.039 UTC] [svservice:P1124:T1208] Enter : BuildSecurityDescriptorForIPC

[2019-06-03 07:41:11.039 UTC] [svservice:P1124:T1208] Exit : BuildSecurityDescriptorForIPC

[2019-06-03 07:41:11.039 UTC] [svservice:P1124:T1208] IPC server initialize success!

[2019-06-03 07:41:11.039 UTC] [svservice:P1124:T1208] ServiceInit completed successfully

[2019-06-03 07:41:11.039 UTC] [svservice:P1124:T1208] ServiceMain now running

[2019-06-03 07:41:11.039 UTC] [svservice:P1124:T1208] Setting status to SERVICE_RUNNING

[2019-06-03 07:41:11.101 UTC] [svservice:P1124:T1196] OnCreateSession called (Session ID 1, Handle 001511E0, Params 015FF5EC, Context 00000000)

[2019-06-03 07:43:13.300 UTC] [svservice:P1124:T1272] GetComputerUuid: unable to locate UUID

[2019-06-03 07:43:13.300 UTC] [svservice:P1124:T1272] HttpComputerStartupThread: failed (computer startup)

[2019-06-03 07:44:22.573 UTC] [svservice:P1124:T1128] Received SERVICE_CONTROL_INTERROGATE

[2019-06-03 07:44:22.573 UTC] [svservice:P1124:T1128] Current status being sent to SCM is 4

[2019-06-03 07:48:00.362 UTC] [svservice:P1124:T4616] OnLogon called (Session ID 1, Handle 001511E0, Params 0157F2D4, Context 00000000)

[2019-06-03 07:48:00.362 UTC] [svservice:P1124:T4616] OnLogon: DOMAIN\USER (NameSamCompatible)

[2019-06-03 07:48:00.393 UTC] [svservice:P1124:T4616] OnLogon: CN=USER'S NAME,OU=Users,OU=DEPARTMENT,OU=Departments,DC=DOMAIN,DC=DOMAIN,DC=local (NameFullyQualifiedDN)

[2019-06-03 07:48:00.393 UTC] [svservice:P1124:T4616] OnLogon: USER@EXTDOMAIN (NameUserPrincipal)

[2019-06-03 07:48:00.393 UTC] [svservice:P1124:T4616] NotifyLoginStarted failed: error 0x80070002

[2019-06-03 07:48:00.393 UTC] [svservice:P1124:T4616] IsDomainJoinedComputer: NetGetJoinInformation() success, domain name DOMAIN and type is 3

[2019-06-03 07:48:00.393 UTC] [svservice:P1124:T4616] GetUserComputerInfo: user:"USER" computer:"windows7-099" userdomain:"DOMAIN" computerdomain: "DOMAIN"

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] GetUserProfileDirectoryW failed: error code 2

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] Logged in user is USER

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] OnLogon: skipping scripts because filtering is inactive

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] GetViewClientIdValue: Unable to open key Volatile Environment\1: error 2

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] GetViewClientIdValue: Pool ID value in key Software\VMware, Inc.\VMware VDM\SessionData\1 is Windows7

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] HttpUserLogin: called 0 logged in (user login)

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] svdriver is running

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] HttpUserLogin: skipping notifying manager of user login (computer-startup failed)

[2019-06-03 07:48:00.409 UTC] [svservice:P1124:T4616] OnLogon : succeeded

[2019-06-03 07:48:06.848 UTC] [svservice:P1124:T1128] Received SERVICE_CONTROL_INTERROGATE

[2019-06-03 07:48:06.848 UTC] [svservice:P1124:T1128] Current status being sent to SCM is 4

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T6016] OnStartShell called (Session ID 1, Handle 001511E0, Params 02B5F688, Context 00000000)

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T6016] OnStartShell: DOMAIN\USER (NameSamCompatible)

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T6016] NotifyLoginCompleted failed: error 0x80070002

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T6016] HttpFileShareRequest WinHttp over SSL is disabled. Log collection to file share not supported.

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T6016] handleFileShareStr: File share info received from manager is empty.

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T6016] OnStartShell: Error Failed to Start DCT Logger

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T2920] Waiting 0 second(s) for a new volume

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T2920] Activate filtering (called by DelayActivateWorker)

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T1256] MeasureTime::RecordCenter: Start recording  GUID:{58fffd46-2b8f-11e9-af91-806e6f6e6963} Type:0

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T1256] Preload volume event (startup): "\Device\HarddiskVolume2" GUID {58fffd46-2b8f-11e9-af91-806e6f6e6963} Hive  (1 logged in, SystemVolume 1, VolumeType 0)

[2019-06-03 07:49:14.360 UTC] [svservice:P1124:T1256] Sending reply to SVCMD_ID_NEW_VOLUME_PRE (Message 13, Size 0)

[2019-06-03 07:49:23.157 UTC] [svservice:P5988:T4296] *** Started

[2019-06-03 07:49:23.157 UTC] [svservice:P5988:T4296] Entered fromrunkey case

[2019-06-03 07:49:23.157 UTC] [svservice:P5988:T4296] Successfully opened runkey event.

[2019-06-03 07:51:16.428 UTC] [svservice:P1124:T1128] Received SERVICE_CONTROL_INTERROGATE

[2019-06-03 07:51:16.428 UTC] [svservice:P1124:T1128] Current status being sent to SCM is 4

[2019-06-03 08:19:27.858 UTC] [svservice:P1124:T6016] OnLock called (Session ID 1, Handle 001511E0, Params 02B5F688, Context 00000000)

[2019-06-03 08:49:27.910 UTC] [svservice:P1124:T6016] OnUnlock called (Session ID 1, Handle 001511E0, Params 02B5F688, Context 00000000)

[2019-06-03 10:14:39.333 UTC] [svservice:P1124:T6016] OnLock called (Session ID 1, Handle 001511E0, Params 02B5F688, Context 00000000)

[2019-06-03 10:17:40.131 UTC] [svservice:P1124:T6468] OnUnlock called (Session ID 1, Handle 001511E0, Params 015FF008, Context 00000000)

[2019-06-03 11:24:42.440 UTC] [svservice:P1124:T6468] OnLock called (Session ID 1, Handle 001511E0, Params 015FF008, Context 00000000)

[2019-06-03 11:44:14.937 UTC] [svservice:P1124:T6468] OnUnlock called (Session ID 1, Handle 001511E0, Params 015FF008, Context 00000000)

Reply
0 Kudos