BigFix action is taking time for more 45minutes to complete

sai_sreep · April 20, 2020, 6:08pm

This is health check action which is is executed against 2019 machine, usually this action need to be completed between 5-15 minutes times (observed), but on the 2019 vm it is taking 45minutes. attached is the log from 2019 for the action.

At 08:33:48 +0000 - mailboxsite (http://*****:52311/cgi-bin/bfgather.exe/mailboxsite7707355)
   Downloaded 'http://*****:52311/mailbox/files/5e/97/5e970a13926ec676e52118a7a8c96638780bb79b' as 'Action 915244.fxf'
   Gather::SyncSiteByFile adding files - count: 1
At 08:33:48 +0000 - 
   Successful Synchronization with site 'mailboxsite' (version 23) - 'http://*****:52311/cgi-bin/bfgather.exe/mailboxsite7707355'
   Processing action site.
At 08:33:48 +0000 - mailboxsite (http://*****:52311/cgi-bin/bfgather.exe/mailboxsite7707355)
   Relevant - SRAB3ABN78531-158241-A1395843 - _Run Windows2019-ITSS_CSD2 (fixlet:915244)
At 08:33:49 +0000 - 
   ActionLogMessage: (action:915244) Action signature verified for Downloads
At 08:33:50 +0000 - 
   ItemizedDownloadsAvailable: true (action id 915244)
   ActionLogMessage: (action:915244) Non-Distributed - DownloadsAvailable
   ActionLogMessage: (action:915244) Submitting download request
   ActionLogMessage: (action:915244) Download url: 'GTSProtocol://download.bigfix.com/download/gtscontent/iemhc/410/20191206-9/Windows/Windows.2019.ITSS_CSD2/policy.xml'
   ActionLogMessage: (action:915244) Download url: 'GTSProtocol://download.bigfix.com/download/gtscontent/iemhc/410/20191206-9/Windows/Windows.2019.ITSS_CSD2/Collectors.zip'
   ActionLogMessage: (action:915244) Download url: 'GTSProtocol://download.bigfix.com/download/gtscontent/iemhc/410/20191206-9/tools/unzip.exe'
   ActionLogMessage: (action:915244) Download url: 'GTSProtocol://download.bigfix.com/download/gtscontent/iemhc/410/20191206-9/tools/cuz.jar'
At 08:33:51 +0000 - 
   ActionLogMessage: (action:915244) Non-Distributed - DownloadsAvailable
   ActionLogMessage: (action:915244) Action signature verified for Execution
   ActionLogMessage: (action:915244) starting action
At 08:33:51 +0000 - actionsite (http://*****:52311/cgi-bin/bfgather.exe/actionsite)
   Command succeeded parameter "basepath" = "GTSProtocol://download.bigfix.com/download/gtscontent/iemhc" (action:915244)
   Command succeeded parameter "downloaded_jre_win64" = "80530" (action:915244)
   Command succeeded parameter "input_jre_win64" = "80530" (action:915244)
   Command succeeded parameter "jre_download_win64" = "nodownload" (action:915244)
   Command succeeded parameter "updateTools" = "False" (action:915244)
   Command succeeded parameter "error" = "100" (action:915244)
   Command succeeded parameter "build_id" = "20191206-9" (action:915244)
   Command succeeded parameter "version" = "4.1.0" (action:915244)
   Command succeeded folder create "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__UIDEXT" (action:915244)
   Command succeeded folder create "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC" (action:915244)
   Command succeeded parameter "dump" = "-Xdump:none" (action:915244)
   Command succeeded parameter "customJVM" = "" (action:915244)
   Command succeeded folder delete No 'C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/Temp' exists to delete, no failure reported (action:915244)
   Command succeeded folder create "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2_backup" (action:915244)
   Command succeeded move "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2/policy_parameters.txt" "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2_backup/policy_parameters.txt" (action:915244)
   Command succeeded move "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2/vault" "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2_backup/vault" (action:915244)
At 08:33:52 +0000 - actionsite (http://*****:52311/cgi-bin/bfgather.exe/actionsite)
   Command succeeded folder delete "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2" (action:915244)
   Command succeeded folder create "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2" (action:915244)
   Command succeeded move "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2_backup/vault" "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2/vault" (action:915244)
   Command succeeded move "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2_backup/policy_parameters.txt" "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2/policy_parameters.txt"  (action:915244)
   Command started - wait "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\jre\bin\java.exe" -jar "C:\Program Files (x86)\BigFix Enterprise\BES Client\__BESData\CustomSite_A158-2dC-2dGv4-2e0-2dW2K19\__Download\cuz.jar" "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\__IEMHC\A158-C-Gv4.0-W2K19\Windows2019-ITSS_CSD2" "C:\Program Files (x86)\BigFix Enterprise\BES Client\__BESData\CustomSite_A158-2dC-2dGv4-2e0-2dW2K19\__Download\Collectors.zip" 	 (action:915244)
At 08:34:02 +0000 - 
   DownloadCRCPing command received
At 08:34:03 +0000 - 
   DownloadCRCPing command received
At 08:34:28 +0000 - actionsite (http://*****:52311/cgi-bin/bfgather.exe/actionsite)
   Command succeeded (Exit Code=0) wait "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\jre\bin\java.exe" -jar "C:\Program Files (x86)\BigFix Enterprise\BES Client\__BESData\CustomSite_A158-2dC-2dGv4-2e0-2dW2K19\__Download\cuz.jar" "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\__IEMHC\A158-C-Gv4.0-W2K19\Windows2019-ITSS_CSD2" "C:\Program Files (x86)\BigFix Enterprise\BES Client\__BESData\CustomSite_A158-2dC-2dGv4-2e0-2dW2K19\__Download\Collectors.zip" 	 (action:915244)
   Command succeeded delete No 'C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2/policy.xml' exists to delete, no failure reported (action:915244)
   Command succeeded copy "C:\Program Files (x86)\BigFix Enterprise\BES Client\__BESData\CustomSite_A158-2dC-2dGv4-2e0-2dW2K19/__Download/policy.xml" "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2/policy.xml" (action:915244)
   Command succeeded appendfile {now as string} (action:915244)
   Command succeeded (file created) appendfile Wed, 08 Apr 2020 08:34:28 +0000 (action:915244)
   Command succeeded appendfile Wed, 08 Apr 2020 08:34:28 +0000 (action:915244)
   Command succeeded appendfile Windows-2019-ITSS_CSD2-1.3 (action:915244)
   Command succeeded appendfile 4.1.0 (action:915244)
   Command succeeded appendfile 20191206-9 (action:915244)
   Command succeeded delete No 'C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2/version.txt' exists to delete, no failure reported (action:915244)
   Command succeeded move __appendfile "C:\Program Files (x86)\BigFix Enterprise\BES Client/__GTS/__IEMHC/A158-C-Gv4.0-W2K19/Windows2019-ITSS_CSD2/version.txt" (action:915244)
   Command succeeded parameter "reportoutput" = "" (action:915244)
   Command succeeded parameter "limitOutput" = "10000" (action:915244)
   Command succeeded parameter "truncateOutput" = "500" (action:915244)
   Command succeeded parameter "debug" = "" (action:915244)
   Command succeeded parameter "localpolparm" = "" (action:915244)
   Command succeeded (file created) appendfile C: (action:915244)
   Command succeeded appendfile C: (action:915244)
   Command succeeded appendfile cd "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\__IEMHC\A158-C-Gv4.0-W2K19\Windows2019-ITSS_CSD2"  (action:915244)
   Command succeeded appendfile "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\jre\bin\java.exe" -jar  -Xdump:none "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\HCLauncher_410\HCLauncher.jar" -policy "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\__IEMHC\A158-C-Gv4.0-W2K19\Windows2019-ITSS_CSD2\policy.xml"    -pparams "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\__IEMHC\A158-C-Gv4.0-W2K19\Windows2019-ITSS_CSD2\policy_parameters.txt" -sv   -truncate 500 -limit 10000 > "C:\Program Files (x86)\BigFix Enterprise\BES Client\__GTS\__IEMHC\A158-C-Gv4.0-W2K19\Windows2019-ITSS_CSD2\GCMBigfix_HealthCheck.log"  2>&1 (action:915244)
   Command succeeded delete launch.bat (action:915244)
   Command succeeded move __appendfile launch.bat (action:915244)
At 08:34:29 +0000 - actionsite (http://*****:52311/cgi-bin/bfgather.exe/actionsite)
   Command started - wait launch.bat (action:915244)
At 08:34:45 +0000 - 
   Report posted successfully
At 08:35:58 +0000 - 
   Report posted successfully
At 08:41:23 +0000 - 
   Report posted successfully
At 08:44:52 +0000 - 
   GatherHashMV command received. Already have site 'mailboxsite' (version 23)
At 08:45:47 +0000 - 
   Report posted successfully
At 08:48:14 +0000 - 
   PollForCommands: Requesting commands
   PollForCommands: commands to process: 0
At 08:48:31 +0000 - 
   Report posted successfully
At 08:50:54 +0000 - 
   Report posted successfully
At 08:56:05 +0000 - 
   Report posted successfully
At 08:56:34 +0000 - 
   Beginning Relay Select
At 08:56:35 +0000 - 
   RegisterOnce: Attempting secure registration ...
At 08:56:36 +0000 - 
   Unrestricted mode
   Configuring listener without wake-on-lan
   Registered with url ...
   Registration Server version 9.5.14.73 , Relay version 9.5.14.73
   Relay does not require authentication.
   Client has an AuthenticationCertificate
   Relay selected: ...
At 08:56:38 +0000 - 
   [ThreadTime:08:56:36] ShutdownListener
   [ThreadTime:08:56:36] SetupListener success: IPV4/6
At 09:00:42 +0000 - 
   Report posted successfully
At 09:00:44 +0000 - actionsite (http://*****:52311/cgi-bin/bfgather.exe/actionsite)
   Relevant - Run Capacity Scan and Upload Results (9.2.17.0) (fixlet:894729)
At 09:01:49 +0000 - 
   Report posted successfully
At 09:03:07 +0000 - 
   Report posted successfully
At 09:03:15 +0000 - 
   PollForCommands: Requesting commands
   PollForCommands: commands to process: 0
At 09:06:37 +0000 - 
   Report posted successfully
At 09:11:07 +0000 - 
   Report posted successfully
At 09:15:38 +0000 - 
   Report posted successfully
At 09:18:08 +0000 - 
   Report posted successfully
At 09:18:16 +0000 - 
   PollForCommands: Requesting commands
   PollForCommands: commands to process: 0
At 09:20:26 +0000 - 
   GatherHashMV command received.
At 09:20:28 +0000 - mailboxsite (http://*****:52311/cgi-bin/bfgather.exe/mailboxsite7707355)
   Downloaded 'http://*****:52311/mailbox/files/e3/56/e3563557aef9c42b1140ed1ecf395903544f7ef5' as 'Action 915245.fxf'
   Gather::SyncSiteByFile adding files - count: 1
At 09:20:29 +0000 - 
   Successful Synchronization with site 'mailboxsite' (version 24) - 'http://*****:52311/cgi-bin/bfgather.exe/mailboxsite7707355'
   Processing action site.
At 09:20:29 +0000 - mailboxsite (http://*****:52311/cgi-bin/bfgather.exe/mailboxsite7707355)
   Relevant - SRAB3ABN78531-158241-A1395843 - _Run Windows-SSH-ITSSCSD (fixlet:915245)
At 09:20:41 +0000 - 
   Report posted successfully
At 09:21:57 +0000 - 
   Report posted successfully
At 09:26:30 +0000 - 
   Report posted successfully
At 09:27:31 +0000 - 
   Successful Synchronization with site 'BES Support' (version 1433) - 'http://sync.bigfix.com/cgi-bin/bfgather/bessupport'
   Successful Synchronization with site 'CustomSite_A158' (version 931390,7989) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_A158'
At 09:27:32 +0000 - 
   Successful Synchronization with site 'CustomSite_A158-2dUIDEXT' (version 706833,1024) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_A158-2dUIDEXT'
   Successful Synchronization with site 'CustomSite_CMS-2dUTILS' (version 424869,971) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_CMS-2dUTILS'
At 09:27:33 +0000 - 
   Successful Synchronization with site 'CustomSite_CMSD-2dBAU' (version 357507,224) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_CMSD-2dBAU'
   Successful Synchronization with site 'CustomSite_GTS_CM_Support_-28Deprecated-29_3-2e8' (version 782706,1701) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_GTS_CM_Support_-28Deprecated-29_3-2e8'
At 09:27:34 +0000 - 
   Successful Synchronization with site 'CustomSite_GTS_CM_Support_custom' (version 637506,1014) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_GTS_CM_Support_custom'
At 09:27:35 +0000 - 
   Successful Synchronization with site 'CustomSite_Windows_Infrastructure' (version 233679,211) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_Windows_Infrastructure'
   Successful Synchronization with site 'Enterprise Security' (version 3517) - 'http://sync.bigfix.com/cgi-bin/bfgather/bessecurity'
At 09:28:35 +0000 - 
   Successful Synchronization with site 'BES Inventory and License' (version 188) - 'http://sync.bigfix.com/cgi-bin/bfgather/besinventory'
   Successful Synchronization with site 'GTS CM Support' (version 14) - 'http://sync.bigfix.com/cgi-bin/bfgather/gtscmsupport'
At 09:28:36 +0000 - 
   Successful Synchronization with site 'GTS CM Support (Deprecated)' (version 9) - 'http://sync.bigfix.com/cgi-bin/bfgather/gtscmsupportdeprecated'
   Successful Synchronization with site 'GTS CM Windows' (version 32) - 'http://sync.bigfix.com/cgi-bin/bfgather/gtscmwin'
   Successful Synchronization with site 'GTS Support' (version 154) - 'http://sync.bigfix.com/cgi-bin/bfgather/gtssupport'
   Successful Synchronization with site 'GTS Tools' (version 82) - 'http://sync.bigfix.com/cgi-bin/bfgather/gtstools'
At 09:28:37 +0000 - 
   Successful Synchronization with site 'GTS Tools System Support' (version 49) - 'http://sync.bigfix.com/cgi-bin/bfgather/gtstoolssystemsupport'
   Successful Synchronization with site 'IBM Endpoint Manager for Software Use Analysis' (version 132) - 'http://sync.bigfix.com/cgi-bin/bfgather/ibmforsua'
   Successful Synchronization with site 'Patching Support' (version 893) - 'http://sync.bigfix.com/cgi-bin/bfgather/patchingsupport'
   Successful Synchronization with site 'SCM Reporting' (version 128) - 'http://sync.bigfix.com/cgi-bin/bfgather/scmreporting'
At 09:31:07 +0000 - 
   Report posted successfully
At 09:31:09 +0000 - actionsite (http://*****:52311/cgi-bin/bfgather.exe/actionsite)
   Relevant - ***DO NOT STOP***Initiate SubSystemsScan_PHASE37 (fixlet:906327)
At 09:32:15 +0000 - 
   Report posted successfully
At 09:32:37 +0000 - 
   Successful Synchronization with site 'CustomSite_A158-2dC-2dGv3-2e7-2dSSH-2dWIN' (version 640526,1014) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_A158-2dC-2dGv3-2e7-2dSSH-2dWIN'
At 09:32:37 +0000 - CustomSite_A158-2dC-2dGv4-2e0-2dSSH-2dWIN (http://*****:52311/cgi-bin/bfgather.exe/CustomSite_A158-2dC-2dGv4-2e0-2dSSH-2dWIN)
   Gather::SyncSiteByFile deleting files - count: 3
At 09:32:37 +0000 - 
   Successful Synchronization with site 'CustomSite_A158-2dC-2dGv4-2e0-2dSSH-2dWIN' (version 928184,7987) - 'http://*****:52311/cgi-bin/bfgather.exe/CustomSite_A158-2dC-2dGv4-2e0-2dSSH-2dWIN'
At 09:33:17 +0000 - 
   PollForCommands: Requesting commands
   PollForCommands: commands to process: 0
At 09:33:31 +0000 - 
   Report posted successfully
At 09:35:50 +0000 - 
   Report posted successfully
At 09:40:32 +0000 - 
   Report posted successfully
At 09:44:53 +0000 - 
   GatherHashMV command received. Already have site 'mailboxsite' (version 24)
At 09:46:15 +0000 - 
   Report posted successfully
At 09:47:32 +0000 - 
   Report posted successfully
At 09:48:18 +0000 - 
   PollForCommands: Requesting commands
   PollForCommands: commands to process: 0
At 09:51:21 +0000 - 
   Report posted successfully
At 09:55:59 +0000 - 
   Report posted successfully
At 09:57:24 +0000 - 
   DownloadCRCPing command received
   DownloadCRCPing command received
At 09:57:25 +0000 - 
   DownloadCRCPing command received
   DownloadCRCPing command received
   DownloadCRCPing command received
   DownloadCRCPing command received
At 09:58:44 +0000 - actionsite (http://*****:52311/cgi-bin/bfgather.exe/actionsite)
   Command succeeded (Exit Code=0) wait launch.bat (action:915244)
At 09:58:45 +0000 - actionsite (http://*****:52311/cgi-bin/bfgather.exe/actionsite)
   Command succeeded folder delete "C:\Program Files (x86)\BigFix Enterprise\BES Client\__BESData\CustomSite_A158-2dC-2dGv4-2e0-2dW2K19/__Download" (action:915244)

Aram · April 20, 2020, 6:54pm

This is really a function of what the action is executing (in this case launch.bat), and the conditions and performance of the endpoint itself rather than of BigFix.

How long does it take to run launch.bat on the endpoint in question if executed manually via the command-line for instance?

sai_sreep · April 20, 2020, 7:18pm

@Aram
I have two scenarios here.
There are two windows 2019 machines from the same domain were

one machine has not taken much time to run launch.bat and completed in 5-15 minutes.
second machine from same domain has issue…above log is from this machine and to execute manually on the endpoint is a tricky as this is in production.

Aram · April 20, 2020, 7:26pm

Understood. But my point is that local conditions of the endpoint (including the virtual machine infrastructure, and the VM itself) are the likely factors here rather than the BigFix Client. As you can see from the log, the Client executed the batch file, and it was the batch file itself that took so long to run. That process (and it’s associated duration) is external to BigFix.

AlanM · April 22, 2020, 3:03am

Another thing to consider is in the case where you are having issues is the program trying to display something? If it does it will hang as you are operating without a UI as a service.