Deployment Solution 8.X - DSTasks Log in Automation and how it interacts with the other logs
search cancel

Deployment Solution 8.X - DSTasks Log in Automation and how it interacts with the other logs

book

Article ID: 280292

calendar_today

Updated On:

Products

Deployment Solution

Issue/Introduction

How to Troubleshoot Deployment Solutions DStask.log processes

Resolution

Premise:

In DS 8.X the DSTasks.log is used to track all DS Task related activities.  Knowing how to read it and use it in conjunction with the other logs is critical for good troubleshooting.

 

Purpose:

In this article, we will be looking primarily at the DSTasks.LOG file created in Automation.  No consideration will be made for other versions of the log file created elsewhere (e.g. on Site Servers or production agents).  Other logs in Automation will be considered mostly as they relate to this one.  This is to assist an administrator or engineer in reviewing the Tasks that DS runs to see where failures occur and help determine how to find solutions.

 

Explanation:

1) WHAT is the DSTasks.LOG, and HOW does it relate to other logs?

Location: X:\Program Files\Symantec\Deployment\Logs (while in automation)

It will be copied to the following path in production on the client being imaged,
If you run a "reboot to" task to production under the agent.

                         C:\Program Files\Altiris\Altiris Agent\Agents\Deployment\PreOS_Task_Logs.

 

DSTasks.LOG is just what it looks like, and no more.  Any DS related task is tracked verbosely through this log file.  Anything that is NOT executed as a DS task is NOT tracked in this log.  For instance, if you send a script task in Automation, that is captured only slightly by the SMP log (which is the same as the Agent log in production) but no mention of it will be in the DSTasks.LOG.  When sending a Deploy Image task, details of everything this task does is captured in DSTasks, but only the execution of the task is captured in the SMP.log.

As a very brief review of the logs, the following table may be of use:

Log File Purpose Relation to DSTasks.LOG
DSTasks Tracking all DS Tasks executed in Automation.  Always set to verbose. Same / Self
SMP Tracks all Agent activity (PECTAgent in Automation)  This is the same as the Agent.LOG files in Production Tracks only incoming tasks and outgoing statuses of those tasks.  Task will first be logged here, THEN in DSTasks.  All final statuses of tasks are captured before sending back to the SMP.
PECTAgent Tracks the initialization of the PECTAgent in Automation.  This is unique from the Agent.LOG in that PECTAgent has to do some custom actions in Automation not required in production. Almost no interaction at all with DSTasks.  Once initialized, process is handed to the SMP Logging, and DSTasks only comes in AFTER that point.
DA_Logs_date Tracks all DA related activity, depending on log level selected. DSTasks will show calling DA, but DA logs it's own activities and returns results to DSTasks.  This is similar to how SMP shows calling a DS related task, but DSTasks shows the activities of that task.
Drivers_List List of detected drivers that need to be copied to the system. DSTasks will show this log being used by DriverManager, IF DeployAnywhere successfully created it during it's /Eval run.
act_wnd Active Windows Partition information collected/created by GHConfig DSTasks will never have mention of this log, but every time you see DSTasks with GHConfiig running, it creates one of these.

 

2) What does the DSTasks.LOG look like and how do we read it?

The following log output shows a successful image deployment via Ghost:

 

[2023/05/13 13:37:16.761 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp@446 Process imaging XML
[2023/05/13 13:37:16.761 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp@566 =False
[2023/05/13 13:37:16.761 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp@576 Output @isHTTP=False
[2023/05/13 13:37:16.761 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp@693 =  -batch -sure -clone,MODE=restore,DST=1,SRC=@fullImagePath
[2023/05/13 13:37:16.761 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp@704 Input @TyepOfImage=1
[2023/05/13 13:37:16.761 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp@461 Launch Imaging Tools
[2023/05/13 13:37:16.761 708:1172 2] Function Name is util::CSMPPackage::getNearestPackageInfoXML(),file name is common\util\SMPPackage.cpp and Line no 318.Reuest XML is /Deployment/Agent/GetNearestPackageServerInfo.aspx?xml=packageserver{32211B72-9251-4F3C-92B0-0C5DCDECD0B4}192.168.1.31ce1a2294-7780-4782-88b1-b36b780d176b
[2023/05/13 13:37:17.261 708:1172 2] Function Name is util::CSMPPackage::getNearestPackageInfoXML(),file name is common\util\SMPPackage.cpp and Line no 328. Response of getNearestPackageInfoXML = falseexample.test.lab192.168.1.34d43d7a2-4620-4ba1-acae-2857c45fb47atrue\\example.test.lab\NSCap\bin\Deployment\Packages\Images\{ce1a2294-7780-4782-88b1-b36b780d176b}\cachehttp://example.test.lab/Altiris/PackageShare/pkggroup_n2sqcsl64ahkqdn2pieuhyejmyexes4k/cachehttps://example.test.lab/Altiris/PackageShare/pkggroup_n2sqcsl64ahkqdn2pieuhyejmyexes4k/cache
[2023/05/13 13:37:17.261 708:1172 2] Function Name is util::CSMPPackage::ParsePackageInfoXML(),file name is common\util\SMPPackage.cpp and Line no 343. Return XML is =falseexample.test.lab192.168.1.34d43d7a2-4620-4ba1-acae-2857c45fb47atrue\\example.test.lab\NSCap\bin\Deployment\Packages\Images\{ce1a2294-7780-4782-88b1-b36b780d176b}\cachehttp://example.test.lab/Altiris/PackageShare/pkggroup_n2sqcsl64ahkqdn2pieuhyejmyexes4k/cachehttps://example.test.lab/Altiris/PackageShare/pkggroup_n2sqcsl64ahkqdn2pieuhyejmyexes4k/cache
[2023/05/13 13:37:17.261 708:1172 2] Function:util::CSMPPackage::Initialiaze(),File:common\util\SMPPackage.cpp and Line:98.example.test.lab have selected as a PS
[2023/05/13 13:37:17.261 708:1172 2] Function Name is util::ExecuteClass::LogPath(),file name is common\util\ExecuteCommand.cpp and Line no 885. path is  is =http://*:*example.test.lab/altiris/packageshare/pkggroup_n2sqcsl64ahkqdn2pieuhyejmyexes4k/cache/win10_x64.gho
[2023/05/13 13:37:17.261 708:1172 1] ****** ExecuteClass:: In ExecuteCommandNoUser ******

[2023/05/13 13:37:17.261 708:1172 1] ExecuteClass::Module Name = X:\Program Files\Symantec\Deployment\Ghost\Ghost64.exe
[2023/05/13 13:37:17.261 708:1172 1] ExecuteClass:: Commandline contains the credentials hence hiding it...
[2023/05/13 13:37:17.261 708:1172 2] ExecuteCommand.cpp@1886 calling ExecuteClass::ExecuteCommandNoUser().
[2023/05/13 13:37:17.261 708:1172 2] ExecuteClass::@1919 Application Name is NOT NULL.
[2023/05/13 13:37:17.261 708:1172 2] ExecuteClass::@1932 Command line is NOT NULL.
[2023/05/13 13:37:17.261 708:1172 1] ExecuteCommandNoUser()Successfully created process. nResult =1
[2023/05/13 13:37:17.261 708:1172 1]  Calling ExecuteClass::ProcessAfterCreate()
[2023/05/13 13:41:03.182 708:1172 2] ExecuteCommand.cpp@2031 ProcessAfterCreate:: dwExitCode=0
[2023/05/13 13:41:03.182 708:1172 2] tcube::ClientImageDeploy::ExecuteCommand:1186 Result of excution of X:\Program Files\Symantec\Deployment\Ghost\Ghost64.exe
[2023/05/13 13:41:03.182 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp:1214 ImageDeploy Task, Execute, Process returned 0
[2023/05/13 13:41:03.182 708:1172 1] ****** ExecuteClass:: In ExecuteCommandNoUser ******
[2023/05/13 13:41:03.182 708:1172 1] ExecuteClass::Module Name = X:\Program Files\Symantec\Deployment\Ghost\GhConfig64.exe
[2023/05/13 13:41:03.182 708:1172 1] ExecuteClass::Commandline =  /findactivewindows
[2023/05/13 13:41:03.182 708:1172 2] ExecuteCommand.cpp@1886 calling ExecuteClass::ExecuteCommandNoUser().
[2023/05/13 13:41:03.182 708:1172 2] ExecuteClass::@1919 Application Name is NOT NULL.
[2023/05/13 13:41:03.182 708:1172 2] ExecuteClass::@1932 Command line is NOT NULL.
[2023/05/13 13:41:03.182 708:1172 1] ExecuteCommandNoUser()Successfully created process. nResult =1
[2023/05/13 13:41:03.182 708:1172 1]  Calling ExecuteClass::ProcessAfterCreate()
[2023/05/13 13:41:03.276 708:1172 2] ExecuteCommand.cpp@2031 ProcessAfterCreate:: dwExitCode=0
[2023/05/13 13:41:03.276 708:1172 1] ****** ExecuteClass:: In ExecuteCommandNoUser ******

 

 The following output shows a successful DeployAnywhere execution:

[2023/05/13 13:41:03.432 708:1172 1] ****** ExecuteClass:: In ExecuteCommandNoUser ******
[2023/05/13 13:41:03.432 708:1172 1] ExecuteClass::Module Name = X:\Program Files\Symantec\Deployment\Ghost\DeployAnywhere64.exe
[2023/05/13 13:41:03.432 708:1172 1] ExecuteClass::Commandline =  /target=C:\Windows  /reportNonCriticalDevices  /eval  /rad /exportDevicesIntoFile="X:\Program Files\Symantec\Deployment\Logs"
[2023/05/13 13:41:03.432 708:1172 2] ExecuteCommand.cpp@1886 calling ExecuteClass::ExecuteCommandNoUser().
[2023/05/13 13:41:03.432 708:1172 2] ExecuteClass::@1919 Application Name is NOT NULL.
[2023/05/13 13:41:03.432 708:1172 2] ExecuteClass::@1932 Command line is NOT NULL.
[2023/05/13 13:41:03.447 708:1172 1] ExecuteCommandNoUser()Successfully created process. nResult =1
[2023/05/13 13:41:03.447 708:1172 1]  Calling ExecuteClass::ProcessAfterCreate()
[2023/05/13 13:41:34.445 708:1172 2] ExecuteCommand.cpp@2031 ProcessAfterCreate:: dwExitCode=2

[2023/05/13 13:41:34.445 708:1172 2] tcube::ClientImageDeploy::ExecuteCommand:1186 Result of excution of X:\Program Files\Symantec\Deployment\Ghost\DeployAnywhere64.exe
[2023/05/13 13:41:34.445 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp:1214 ImageDeploy Task, Execute, Process returned 2
[2023/05/13 13:41:34.445 708:1172 2] Function Name is util::CSMPPackage::getNearestPackageInfoXML(),file name is common\util\SMPPackage.cpp and Line no 318.Reuest XML is /Deployment/Agent/GetNearestPackageServerInfo.aspx?xml=packageserver{32211B72-9251-4F3C-92B0-0C5DCDECD0B4}192.168.1.31{20827DDD-C698-49E8-B312-830DF1D935B2}
[2023/05/13 13:41:34.492 708:1172 2] Function Name is util::CSMPPackage::getNearestPackageInfoXML(),file name is common\util\SMPPackage.cpp and Line no 328. Response of getNearestPackageInfoXML = falseexample.test.lab192.168.1.34d43d7a2-4620-4ba1-acae-2857c45fb47atrue\\example.test.lab\NSCap\bin\Deployment\DriversDBhttp://example.test.lab/Altiris/PackageShare/pkggroup_t7neyodofi7svj3ttzhvdbn5gfsqjhxx/DriversDBhttps://example.test.lab/Altiris/PackageShare/pkggroup_t7neyodofi7svj3ttzhvdbn5gfsqjhxx/DriversDB
[2023/05/13 13:41:34.492 708:1172 2] Function Name is util::CSMPPackage::ParsePackageInfoXML(),file name is common\util\SMPPackage.cpp and Line no 343. Return XML is =falseexample.test.lab192.168.1.34d43d7a2-4620-4ba1-acae-2857c45fb47atrue\\example.test.lab\NSCap\bin\Deployment\DriversDBhttp://example.test.lab/Altiris/PackageShare/pkggroup_t7neyodofi7svj3ttzhvdbn5gfsqjhxx/DriversDBhttps://example.test.lab/Altiris/PackageShare/pkggroup_t7neyodofi7svj3ttzhvdbn5gfsqjhxx/DriversDB
[2023/05/13 13:41:34.492 708:1172 2] Function:util::CSMPPackage::Initialiaze(),File:common\util\SMPPackage.cpp and Line:98.example.test.lab have selected as a PS
[2023/05/13 13:41:34.601 708:1172 0] common\util\SMPPackage.cpp@595: GetFile SUCCESS return code =0
[2023/05/13 13:41:34.601 708:1172 1] ****** ExecuteClass:: In ExecuteCommandNoUser ******

[2023/05/13 13:41:34.601 708:1172 1] ExecuteClass::Module Name = X:\Program Files\Symantec\Deployment\Ghost\DriverManager64.exe
[2023/05/13 13:41:34.601 708:1172 1] ExecuteClass::Commandline =  /ddb="C:\Program Files\Symantec\Deployment\DriversDB" /list="X:\program files\Symantec\Deployment\driver_list.txt" /cout="C:\Program Files\Symantec\Deployment\DA_Eval_List.xml" /format=xml
[2023/05/13 13:41:34.601 708:1172 2] ExecuteCommand.cpp@1886 calling ExecuteClass::ExecuteCommandNoUser().
[2023/05/13 13:41:34.601 708:1172 2] ExecuteClass::@1919 Application Name is NOT NULL.
[2023/05/13 13:41:34.601 708:1172 2] ExecuteClass::@1932 Command line is NOT NULL.
[2023/05/13 13:41:34.616 708:1172 1] ExecuteCommandNoUser()Successfully created process. nResult =1
[2023/05/13 13:41:34.616 708:1172 1]  Calling ExecuteClass::ProcessAfterCreate()
[2023/05/13 13:41:34.710 708:1172 2] ExecuteCommand.cpp@2031 ProcessAfterCreate:: dwExitCode=0
[2023/05/13 13:41:34.710 708:1172 2] tcube::ClientImageDeploy::ExecuteCommand:1186 Result of excution of X:\Program Files\Symantec\Deployment\Ghost\DriverManager64.exe
[2023/05/13 13:41:34.710 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp:1214 ImageDeploy Task, Execute, Process returned 0
[2023/05/13 13:41:34.866 708:1172 1] ****** ExecuteClass:: In ExecuteCommandNoUser ******
[2023/05/13 13:41:34.866 708:1172 1] ExecuteClass::Module Name = X:\Program Files\Symantec\Deployment\Ghost\DeployAnywhere64.exe
[2023/05/13 13:41:34.866 708:1172 1] ExecuteClass::Commandline =  /target=C:\ /HandleNonCriticalDrivers=minisetup /ddb="C:\Program Files\Symantec\Deployment\DriversDB" /skipMissingCriticalDrivers /byPassDrvVali=All /loglevel=255
[2023/05/13 13:41:34.866 708:1172 2] ExecuteCommand.cpp@1886 calling ExecuteClass::ExecuteCommandNoUser().
[2023/05/13 13:41:34.866 708:1172 2] ExecuteClass::@1919 Application Name is NOT NULL.
[2023/05/13 13:41:34.866 708:1172 2] ExecuteClass::@1932 Command line is NOT NULL.
[2023/05/13 13:41:34.866 708:1172 1] ExecuteCommandNoUser()Successfully created process. nResult =1
[2023/05/13 13:41:34.866 708:1172 1]  Calling ExecuteClass::ProcessAfterCreate()
[2023/05/13 13:42:13.773 708:1172 2] ExecuteCommand.cpp@2031 ProcessAfterCreate:: dwExitCode=0
[2023/05/13 13:42:13.773 708:1172 2] tcube::ClientImageDeploy::ExecuteCommand:1186 Result of excution of X:\Program Files\Symantec\Deployment\Ghost\DeployAnywhere64.exe
[2023/05/13 13:42:13.773 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp:1214 ImageDeploy Task, Execute, Process returned 0
[2023/05/13 13:42:13.773 708:1172 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp@1235::CopyIniFileToProduction()
[2023/05/13 13:42:13.788 708:1172 2] common\util\ExecuteCommand.cpp:util::ExecuteClass::SetResult():4356. Value of nResult(@ReturnValue) = 0, Value of bResult(@Success) = 1
[2023/05/13 13:42:13.788 708:1172 2] common\util\ExecuteCommand.cpp@4380 Task have completed. Successful return.

 

3) How do we troubleshoot the DSTasks.LOG?

Because the log is dynamic - that is, what is in it really depends on what the agent system is to do, troubleshooting is not very cut and dry. Understanding the process of:

  • Understanding the information above
  • Looking for errors upside-down
  • Testing where possible the step that failed.

 

An Example:

For example, let's say you have a job that is supposed to capture an image but it's failing.  The job has a Prepare for Image Capture, Capture Image, and Reboot to Production.  Simple.  How do you use DSTasks to help troubleshoot this?

  • First, Do not reboot to production, stay in automation to see what is happening and not lose the logs.
  • Second: run rungagent.bat from x: to restart pectagent and run the imaging task

Or, boot to Automation manually (or with a task) and just stop there doing nothing.  Then you assign an imaging task (backup or regular disk image doesn't matter) and run it only.  Immediately after it completes take a look at the DSTasks.LOG to see what happened.

 

Looking for errors "upside-down."

Start at the bottom of the file and gradually scroll upwards and look for errors.  Actually - look for where errors stop and success begins.  Literally, look for the last successful "thing" to happen, and the first failure logged.  Often, later messages are misleading, so look for want what came first.  Here's an example:

From the bottom, here's the first failure I see in a DSTasks.LOG file:

Error Description is "Child Process returned an error". The exit code from process is 3. Value of Windows error code = 183 and message is " Cannot create a file when that file already exists."

This message, however, is generic and means nothing.  So keep looking up. 

[2023/02/12 14:09:13.395 1788:240 2] tcube::ClientImageDeploy::ExecuteCommand:1185 Result of excution of X:\Program Files\Symantec\Deployment\Ghost\DriverManager.exe
[2023/02/12 14:09:13.395 1788:240 2] apps\DeploymentClient\ClientImageDeploy\Tcube_ClientImageDeploy.cpp:1213 ImageDeploy Task, Execute, Process returned 0

Now, look at the very next chunk of code - this is what is failing, but the code execution and failure message are SEVERAL lines apart with an ExitCode=3 ( this is a failure )

[2023/02/12 14:09:16.50 1788:240 1] ExecuteClass::Module Name = X:\Program Files\Symantec\Deployment\Ghost\DeployAnywhere.exe
[2023/02/12 14:09:16.50 1788:240 1] ExecuteClass::Commandline = /target=D:\ /HandleNonCriticalDrivers=minisetup /ddb="D:\Program Files\Symantec\Deployment\DriversDB" /loglevel=255
[2023/02/12 14:09:16.50 1788:240 2] ExecuteCommand.cpp@1885 calling ExecuteClass::ExecuteCommandNoUser().
[2023/02/12 14:09:16.50 1788:240 2] ExecuteClass::@1918 Application Name is NOT NULL.
[2023/02/12 14:09:16.50 1788:240 2] ExecuteClass::@1931 Command line is NOT NULL.
[2023/02/12 14:09:16.50 1788:240 1] ExecuteCommandNoUser()Successfully created process. nResult =1
[2023/02/12 14:09:16.50 1788:240 1] Calling ExecuteClass::ProcessAfterCreate()
[2023/02/12 14:10:14.425 1788:240 2] ExecuteCommand.cpp@2030 ProcessAfterCreate:: dwExitCode=3
 

 

Testing where possible.

From the text above,  DeployAnywhere (DA) failed with an exit code of 3.  Since this exit code does not give alot of information as the the cause,and since the client is still in automation we can try rerunning the command.  Here's the whole command line made up of concatenating the two lines together:

X:\Program Files\Symantec\Deployment\Ghost\DeployAnywhere.exe /target=D:\ /HandleNonCriticalDrivers=minisetup /ddb="D:\Program Files\Symantec\Deployment\DriversDB" /loglevel=255

The good news is that X is the RAM drive, and available.  D is used two times, and is the newly deployed production drive  Run this from a Command Prompt here in WinPE and see what happens.

 

Conclusion / Key Take-Away:

Remember, the goal of any troubleshooting process is to either find the problem, OR to find clues to the problem for a faster resolution.

Finally, capture ALL the logs in that LOGS folder, and have them zipped up and ready to send to support!