2 Replies Latest reply on Jan 17, 2018 2:55 PM by kstieers

    With "Remove temp files" checked, tracker doesn't get updated that job is done

    kstieers Rookie

      I've been doing some test pushes of the IVA18-002 tool using 9.3.0 build 4510 and came across an issue.

       

      The tracker never gets the final updates, so it still says "Deployment opearation executing", even though the patch progress is executed.

       

      I think there's either a timing or order of operations issue..

      Dplyevts.log shows some successful updates as the files are pushed, job schedule, started, but it fails at the end.

      STdeploy.log shows the file clean up, which happens before the last update to track is supposed to be sent.

      (snips below)

       

      So is this a bug? (e.g. the order got changed?) or just a timing thing because its one small patch???

       

       

       

       

       

       

      Here's a snip from dplyevts.log with a few successful updates and then the failed one:

       

      2018-01-17T17:29:01.9336112Z 0d2c I TrackerAddress.cpp:49 Read 2 messages from 'e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.tracker'.

      2018-01-17T17:29:01.9336112Z 0d2c I DplyEvts.cpp:291 PingBack updates code - tracker(https://e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6:3121/ST/Console/Deployment/Tracker/v92)  deploymentId(e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6), machineId(28672), status(43), failure(false), terminal(false).

      2018-01-17T17:29:01.9336112Z 0d2c I SequenceState.cpp:30 Sequence state file 'C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.sequence.txt' does not exist, reverting sequence to default.

      2018-01-17T17:29:01.9336112Z 0d2c I PingBack.cpp:53 Sending data to 'https://SHAVLIK1:3121/ST/Console/Deployment/Tracker/v92'.

      2018-01-17T17:29:01.9336112Z 0d2c W HttpDownload.cpp:560 IE Proxy not found: 2.

      2018-01-17T17:29:01.9336112Z 0d2c E HttpDownload.cpp:492 AttemptIEProxySession failed.

      2018-01-17T17:29:02.1052134Z 0d2c I TrackerAddress.cpp:49 Read 2 messages from 'e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.tracker'.

      2018-01-17T17:29:02.1052134Z 0d2c I DplyEvts.cpp:244 PingBack updates no code - tracker(https://e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6:3121/ST/Console/Deployment/Tracker/v92)  deploymentId(e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6), machineId(28672), patchId(143123), status(4), failure(false), terminal(false).

      2018-01-17T17:29:02.1052134Z 0d2c I SequenceState.cpp:48 Read sequence 15001 from 'C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.sequence.txt'.

      2018-01-17T17:29:02.1052134Z 0d2c I PingBack.cpp:53 Sending data to 'https://SHAVLIK1:3121/ST/Console/Deployment/Tracker/v92'.

      2018-01-17T17:29:02.1208136Z 0d2c W HttpDownload.cpp:560 IE Proxy not found: 2.

      2018-01-17T17:29:02.1208136Z 0d2c E HttpDownload.cpp:492 AttemptIEProxySession failed.

      2018-01-17T17:29:02.4952184Z 0d2c I TrackerAddress.cpp:49 Read 2 messages from 'e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.tracker'.

      2018-01-17T17:29:02.4952184Z 0d2c I DplyEvts.cpp:266 PingBack updates code - tracker(https://e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6:3121/ST/Console/Deployment/Tracker/v92)  deploymentId(e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6), machineId(28672), patchId(143123), status(5), failure(false), terminal(true), returnCode(0).

      2018-01-17T17:29:02.4952184Z 0d2c I SequenceState.cpp:48 Read sequence 15002 from 'C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.sequence.txt'.

      2018-01-17T17:29:02.4952184Z 0d2c I PingBack.cpp:53 Sending data to 'https://SHAVLIK1:3121/ST/Console/Deployment/Tracker/v92'.

      2018-01-17T17:29:02.5108186Z 0d2c W HttpDownload.cpp:560 IE Proxy not found: 2.

      2018-01-17T17:29:02.5108186Z 0d2c E HttpDownload.cpp:492 AttemptIEProxySession failed.

      2018-01-17T17:29:02.7136212Z 0d2c I DplyEvts.cpp:70 Checking for necessary services.

      2018-01-17T17:29:03.7432344Z 0d2c I DplyEvts.cpp:54 SvcIsRunning service name: LanmanServer, status: Running.

      2018-01-17T17:29:03.7432344Z 0d2c I DplyEvts.cpp:54 SvcIsRunning service name: LanmanWorkstation, status: Running.

      2018-01-17T17:29:03.7432344Z 0d2c I DplyEvts.cpp:54 SvcIsRunning service name: RemoteRegistry, status: Running.

      2018-01-17T17:29:03.7432344Z 0d2c E TrackerAddress.cpp:34 Tracker address file 'C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.tracker' does not exist.

      2018-01-17T17:29:03.7432344Z 0d2c I DplyEvts.cpp:291 PingBack updates code - tracker(https://e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6:3121/ST/Console/Deployment/Tracker/v92)  deploymentId(e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6), machineId(28672), status(99), failure(false), terminal(true).

      2018-01-17T17:29:03.7432344Z 0d2c I SequenceState.cpp:30 Sequence state file 'C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.sequence.txt' does not exist, reverting sequence to default.

      2018-01-17T17:29:03.7432344Z 0d2c W HttpDownload.cpp:560 IE Proxy not found: 2.

      2018-01-17T17:29:03.7432344Z 0d2c E HttpDownload.cpp:492 AttemptIEProxySession failed.

      2018-01-17T17:29:03.7432344Z 0d2c E HttpDownload.cpp:1029 WinHttpSendRequest failed: 12007.

      2018-01-17T17:29:03.7432344Z 0d2c E HttpDownload.cpp:500 AttemptStraightSession failed.

       

       

       

      And here's the STDEPLOY.LOG with the deletion happening just before the last tracker update

       

      2018-01-17T17:29:02.5888196Z 0d2c I STPackageDeployer.cpp:1236 Patch file 'C:\WINDOWS\ProPatches\Patches\KB4072699.exe' install operation completed. Cooked result='5'. RebootRequired='false'

      2018-01-17T17:29:02.5888196Z 0d2c I STPackageDeployer.cpp:1964 Done deploying patches...

      2018-01-17T17:29:02.5888196Z 0d2c I STPackageDeployer.cpp:1966 Deploying product instances patches...

      2018-01-17T17:29:02.5888196Z 0d2c I STPackageDeployer.cpp:2006 Done deploying product instances patches...

      2018-01-17T17:29:02.5888196Z 0d2c W SingleInstanceLock.cpp:28 Waiting for another deployment to finish.

      2018-01-17T17:29:02.5888196Z 0d2c I SingleInstanceLock.cpp:36 Exclusively continuing deployment.

      2018-01-17T17:29:02.5888196Z 0d2c V STPackageDeployer.cpp:85 Initiating patch store servicing.

      2018-01-17T17:29:02.5888196Z 0d2c V STPackageDeployer.cpp:106 Patch store servicing complete.

      2018-01-17T17:29:02.5888196Z 0d2c I STPackageDeployer.cpp:1336 Postboot actions filename='PostBootTasks.xml' does not exist on the file system

      2018-01-17T17:29:02.5888196Z 0d2c I STPackageDeployer.cpp:1342 Remove temp files flag is set. Pingbacks pending='false'. Sandbox cleanup deferred if true.

      2018-01-17T17:29:02.5888196Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Patches\KB4072699.exe'

      2018-01-17T17:29:02.5888196Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\7z.dll'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\cl5.exe'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\deployPackage-28672.zip'

      2018-01-17T17:29:02.7136212Z 0d2c I Sandbox.cpp:75 DoSandboxCleanup: Cannot delete filename='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\dplyevts.dll', file in use. Scheduled delete at next bootup.

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.sequence.txt'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6.tracker'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\InstallPatches-28672.bat'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\KB4072699.exe_install.bat'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\safereboot.exe'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\safereboot64.exe'

      2018-01-17T17:29:02.7136212Z 0d2c I Sandbox.cpp:75 DoSandboxCleanup: Cannot delete filename='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\stdeploy.exe', file in use. Scheduled delete at next bootup.

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\stdeploy.exe.config'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\STDeployerCore.dll'

      2018-01-17T17:29:02.7136212Z 0d2c V Sandbox.cpp:66 DoSandboxCleanup: Deleted file='C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21\ToDelete.txt'

      2018-01-17T17:29:02.7136212Z 0d2c E STPackageDeployer.cpp:507 Reboot disallowed or not required. externalRebootOption = '2', deployer requested reboot: false

      2018-01-17T17:29:02.7136212Z 0d2c V DeployStatusReporter.cpp:128 Queueing online machine status msg. DeploymentId='e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6', machineId='28672', status='99', isFinal='true'

      2018-01-17T17:29:02.7136212Z 0d2c S StatusClient.cpp:109 Entering STDeployment::CStatusClient::ReportMachineStatusOnline.

      2018-01-17T17:29:03.7432344Z 0d2c V SchedClt.cpp:148 CSchedClt(): schedulerType=1, jobCreator=STPackageDeployer, jobName=LaunchSTDeployForOnlineStatusRetry (e294d7ce-7f0e-4da1-a9de-8ae9357ea0d6), comment=Schedule STDeploy.exe to retry status reports..

      2018-01-17T17:29:03.7432344Z 0d2c I STPackageDeployer.cpp:1002 'STDeploy.exe package="deployPackage-28672.zip" relaunchSandbox="C:\WINDOWS\ProPatches\Installation\InstallationSandbox#2018-01-17-T-17-28-21" relaunchReason="finalStatusRetry=1"' scheduled to in 5 minutes.

      2018-01-17T17:29:03.7432344Z 0d2c S DeployExeStates.cpp:409 Leaving STDeploy::CInitialExecutionPackageDeploy::DoStatefulRemediateActions.

      2018-01-17T17:29:03.7432344Z 0d2c I STDeploy.cpp:365 Current remediation phase completed. Process exit code: 0.

      2018-01-17T17:29:03.7432344Z 0d2c S STDeploy.cpp:257 Leaving wmain.