Why Does a BigFix Client Sometimes Take A Long Time to do Its Thing?

Hi all …

Attached below is a BigFix client log. This client version is an old 9.x version - “Client version 9.0.835.0 built for Solaris 8 Sparc”. There’s nothing unusual about it - except that this client took over an hour to decide to run a blank action and that it doesn’t send heartbeats to the BigFix server (or a parent relay) every 15 minutes. This client has not been configured “specially” in any way (best I could tell), there is nothing unusual in its computer properties, CPU utilization is very low and there are no disk or memory issues. What might cause the BigFix client to be so “laid back” and not send heartbeats at all? It received the UDP message to “wake up & do something” pretty quickly. The annotated log is below (my comments start with ===>).

Current Date: February 10, 2016
   Client version 9.0.835.0 built for Solaris 8 Sparc
   Current Balance Settings: Use CPU: True Entitlement: 0 WorkIdle: 10 SleepIdle: 480
   ICU data directory: '/var/opt/BESClient'
   ICU deployment character set: ISO_8859-1:1987
   ICU local character set: ISO_8859-1:1987
   ICU transcoding between deployment and local character sets: DISABLED
At 10:10:32 -0600 -
   Starting client version 9.0.835.0
   FIPS mode disabled by default.
   Cryptographic module initialized successfully.
   Using crypto library libBEScrypto_1_0_0_4 - OpenSSL 0.9.8x-fips 10 May 2012
   Restricted mode
At 10:10:33 -0600 -
   Initializing Site: BES Support
   Initializing Site: IBM License Reporting
   Initializing Site: mailboxsite
   Initializing Site: opsite2
   Initializing Site: opsite3
   Initializing Site: opsite4
At 10:10:34 -0600 -
   Beginning Relay Select
At 10:10:35 -0600 -
   RegisterOnce: Attempting secure registration with 'https://mybigfix.server.com:52311/cgi-bin/bfenterprise/clientregister.exe?RequestType=RegisterMe60&ClientVersion=9.0.835.0&Body=13971696&SequenceNumber=54&MinRelayVersion=7.1.1.0&CanHandleMVPings=1&Root=http://mybigfix.server.com%3a52311&AdapterInfo=00-03-ba-e1-ba-ab_10.8.0.0%2f16_10.8.2.25_0'
At 10:10:36 -0600 -
   Unrestricted mode
   Configuring listener without wake-on-lan
   Registered with url 'https://mybigfix.server.com:52311/cgi-bin/bfenterprise/clientregister.exe?RequestType=RegisterMe60&ClientVersion=9.0.835.0&Body=13971696&SequenceNumber=54&MinRelayVersion=7.1.1.0&CanHandleMVPings=1&Root=http://mybigfix.server.com%3a52311&AdapterInfo=00-03-ba-e1-ba-ab_10.8.0.0%2f16_10.8.2.25_0'
   Registration Server version 9.2.6.94 , Relay version 9.2.6.94
   Relay does not require authentication.
   Client has an AuthenticationCertificate
   Relay selected: mybigfix.server.com. at: 10.26.51.100:52311 on: IPV4
At 10:10:37 -0600 -
   PollForCommands: Requesting commands
   PollForCommands: commands to process: 0
At 10:10:40 -0600 -
   Entering service loop
At 10:10:41 -0600 -
   Successful Synchronization with site 'actionsite' (version 270) - 'http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/actionsite'
   Site 'mailboxsite' is not yet available on selected relay.  Awaiting notification of availability.
   Successful Synchronization with site 'mailboxsite' (version 0) - 'http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/mailboxsite13971696'
At 10:10:42 -0600 -
   SetupListener success: IPV4
At 10:10:42 -0600 - actionsite (http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/actionsite)
   Relevant - Change '__RelaySelect_Automatic' Setting (fixlet:7898)
At 10:10:42 -0600 -
   ActionLogMessage: (action:7898) Action signature verified for Execution
   ActionLogMessage: (action:7898) starting action
At 10:10:42 -0600 - actionsite (http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/actionsite)
   Command succeeded setting "__RelaySelect_Automatic"="1" on "Wed, 10 Feb 2016 15:41:28 +0000" for client (action:7898)
At 10:10:42 -0600 -
   ActionLogMessage: (action:7898) ending action
At 10:10:42 -0600 - actionsite (http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/actionsite)
   Not Relevant - Change '__RelaySelect_Automatic' Setting (fixlet:7898)
At 10:10:43 -0600 -
   Encryption: optional encryption with no certificate; reports in cleartext
   Report posted successfully
At 10:10:44 -0600 -
   Beginning Relay Select
At 10:10:46 -0600 -
   RegisterOnce: Attempting secure registration with 'https://relay.company.com:52311/cgi-bin/bfenterprise/clientregister.exe?RequestType=RegisterMe60&ClientVersion=9.0.835.0&Body=13971696&SequenceNumber=55&MinRelayVersion=7.1.1.0&CanHandleMVPings=1&MinHops=1&MaxHops=1&Root=http://mybigfix.server.com%3a52311&AdapterInfo=00-03-ba-e1-ba-ab_10.8.0.0%2f16_10.8.2.25_0'
   Unrestricted mode
At 10:10:47 -0600 -
   Configuring listener without wake-on-lan
   Registered with url 'https://relay.company.com:52311/cgi-bin/bfenterprise/clientregister.exe?RequestType=RegisterMe60&ClientVersion=9.0.835.0&Body=13971696&SequenceNumber=55&MinRelayVersion=7.1.1.0&CanHandleMVPings=1&MinHops=1&MaxHops=1&Root=http://mybigfix.server.com%3a52311&AdapterInfo=00-03-ba-e1-ba-ab_10.8.0.0%2f16_10.8.2.25_0'
   Registration Server version 9.2.6.94 , Relay version 9.2.6.94
   Relay does not require authentication.
   Client has an AuthenticationCertificate
   Relay selected: relay.company.com. at: 10.26.50.221:52311 on: IPV4
At 10:10:48 -0600 -
   ShutdownListener
   SetupListener success: IPV4

===> Client receives signal to run a blank action at 10:14 ...
    At 10:14:16 -0600 -
       GatherHashMV command received.
    At 10:14:31 -0600 - mailboxsite (http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/mailboxsite13971696)
       Downloaded 'http://relay.company.com:52311/mailbox/files/07/de/07def518d0f4912b44b8bd82049586331d2be7d7' as 'Action 7901.fxf'
    At 10:14:40 -0600 - mailboxsite (http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/mailboxsite13971696)
       Gather::SyncSiteByFile adding files - count: 1
    At 10:15:14 -0600 -
       Successful Synchronization with site 'mailboxsite' (version 1) - 'http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/mailboxsite13971696'

===> Waits 2 minutes before processing actionsite
    At 10:17:37 -0600 -
       Processing action site.

===> About 1 hour 24 minutes later, determines that the blank task is relevant
    At 11:38:59 -0600 - mailboxsite (http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/mailboxsite13971696)
       Relevant - Blank task (fixlet:7901)

===> runs it 3 minutes later
    At 11:41:27 -0600 -
       ActionLogMessage: (action:7901) Action signature verified for Execution
       ActionLogMessage: (action:7901) starting action
       ActionLogMessage: (action:7901) ending action
    At 11:41:27 -0600 - mailboxsite (http://mybigfix.server.com:52311/cgi-bin/bfgather.exe/mailboxsite13971696)
       Not Relevant - Blank task (fixlet:7901)

==> and sends back a report
    At 11:41:29 -0600 -
       Report posted successfully

Notice not a single heartbeat during this interval. I’m stumped! What did I miss?

–Mark

See if you can find out what the client is doing in these times:

  1. Activate client debug logging:
    http://www-01.ibm.com/support/docview.wss?uid=swg21505873#clientdebuglogging

  2. Activate client usage profiler:
    http://www-01.ibm.com/support/docview.wss?uid=swg21505873#clientusageprofiler

  3. Import and activate the following analysis for the endpoint to evaluate:
    http://www-01.ibm.com/support/docview.wss?uid=swg21669200

One of the best pieces of information returned by 2 and 3 are the content objects that take the most time to evaluate.

Note: Run these traces for a good 24 hours before attempting to analyze them.

If the problem is specific content this will help you determine which content is not being nice.

The other problem could be CPU allowance. Check the following settings to see if they are set to something different than the defaults: http://www-01.ibm.com/support/docview.wss?uid=swg21505852

2 Likes

I like what this analysis returns. I’m nervous about activating it globally. Could I just use the relevance from each property and run it in a QnA session in the fixlet debugger on the device(s) in question?

You could put the analysis in a custom site that only a few computers subscribe to. Then you could activate it locally or globally, but limit the potential impact of it.

Is there a reason in particular that you are worried about activating it globally?

That might work, but it will probably need to be run from the client context.

This seems like an evaluation loop issue.

What is the average evaluation loop on this client?

Related:

My concern is mostly about the amount of data that returns and the impact to fill DB.

Also, I created a dashboard to run in the BESClientUI to retrieve these results. Therefore I would not have to pull the data back. But, I like the idea of creating a custom site where this analysis/property would live

1 Like