FOG Client log reporting old RC and odd behavior

[fry_p]

Server

• FOG Version: RC-18
• OS: UBUNTU 14.04

Client

• Service Version: 0.11.5
• OS: Windows 7 Pro x64

Description

I should have mentioned this a while back as I have seen it a few times in the past. First thing that happens is some sort of odd behavior of the client.

I have seen two variations of this:

Most common is that the client will think it is communicating with the server, but will not “listen” to anything the server says. For example, I tell a snapin to deploy to a lab. 95% of the lab does so. The other few just sit. Mind you, they all were imaged with the same image at the same time. Re-installing the FOG client resolves this. I can try to provide logs for this, but I can tell you the pattern. Everything looks normal except for one glaring anomaly: The client is reporting the server as an older RC than the current one that is running. For example, the oddly behaving client reports RC-14 when we were on RC-17.

The other newer issue is that the client may be rebooting PC’s randomly. It has been difficult to track down what is causing these reboots, but we may have caught one “in the act” on Friday. Please see the excerpt of the client log below:

------------------------------------------------------------------------------
--------------------------------HostnameChanger-------------------------------
------------------------------------------------------------------------------
 10/28/2016 2:06 PM Client-Info Client Version: 0.11.5
 10/28/2016 2:06 PM Client-Info Client OS:      Windows
 10/28/2016 2:06 PM Client-Info Server Version: 1.3.0-RC-14
 10/28/2016 2:06 PM Middleware::Response Success
 10/28/2016 2:06 PM HostnameChanger Checking Hostname
 10/28/2016 2:06 PM HostnameChanger Hostname is correct
 10/28/2016 2:06 PM HostnameChanger Attempting to join domain
 10/28/2016 2:06 PM HostnameChanger Success, code =  0
 10/28/2016 2:06 PM Power Creating shutdown request
 10/28/2016 2:06 PM Power Parameters: /r /c "Host joined to Active Directory, restart required" /t 0
 10/28/2016 2:06 PM Bus {
  "self": true,
  "channel": "Power",
  "data": "{\r\n  \"action\": \"shuttingdown\"\r\n}"
}
 10/28/2016 2:06 PM Bus Emmiting message on channel: Power
------------------------------------------------------------------------------

 10/28/2016 2:07 PM Main Overriding exception handling
 10/28/2016 2:07 PM Main Bootstrapping Zazzles
 10/28/2016 2:07 PM Controller Initialize
 10/28/2016 2:07 PM Zazzles Creating main thread
 10/28/2016 2:07 PM Zazzles Service construction complete
 10/28/2016 2:07 PM Controller Start

 10/28/2016 2:07 PM Service Starting service
 10/28/2016 2:07 PM Bus Became bus server
 10/28/2016 2:07 PM Bus {
  "self": true,
  "channel": "Status",
  "data": "{\r\n  \"action\": \"load\"\r\n}"
}
 10/28/2016 2:07 PM Bus Emmiting message on channel: Status
 10/28/2016 2:07 PM Service Invoking early JIT compilation on needed binaries

Mind you, this is not reporting the proper RC version. I find it very strange that it would randomly need to re-join the domain being that no changes were made in AD at the time of this occurrence. Please see below for Windows logs on the client at that exact moment

So to wrap things up, I am now getting random reboots such as this all around my district. FOG seems to think that these PC’s need to be joined, but evidence points to this being a false positive due to it being on the domain a minute earlier and no actions being taken by us to disjoin these PC’s from the domain. I just updated to RC-18 on Saturday, so if this was already addressed, I apologize. As always, if you need logs, I can provide them. The current work-around is disabling task-reboot and hostname changer globally.

Thanks!
Paul

[Wayne Workman]

@Senior-Developers

[fry_p]

Another known problem PC is reporting RC-13 as the server version and seems to have not checked in since 10/13/16.

------------------------------------------------------------------------------
---------------------------------ClientUpdater--------------------------------
------------------------------------------------------------------------------
 10/13/2016 9:26 AM Client-Info Client Version: 0.11.5
 10/13/2016 9:26 AM Client-Info Client OS:      Windows
 10/13/2016 9:26 AM Client-Info Server Version: 1.3.0-RC-13
 10/13/2016 9:26 AM Middleware::Response Success
------------------------------------------------------------------------------


------------------------------------------------------------------------------
----------------------------------TaskReboot----------------------------------
------------------------------------------------------------------------------
 10/13/2016 9:26 AM Client-Info Client Version: 0.11.5
 10/13/2016 9:26 AM Client-Info Client OS:      Windows
 10/13/2016 9:26 AM Client-Info Server Version: 1.3.0-RC-13
 10/13/2016 9:26 AM Middleware::Response ERROR: Unable to get subsection
 10/13/2016 9:26 AM Middleware::Response ERROR: Object reference not set to an instance of an object.

------------------------------------------------------------------------------
--------------------------------HostnameChanger-------------------------------
------------------------------------------------------------------------------
 10/13/2016 9:26 AM Client-Info Client Version: 0.11.5
 10/13/2016 9:26 AM Client-Info Client OS:      Windows
 10/13/2016 9:26 AM Client-Info Server Version: 1.3.0-RC-13
 10/13/2016 9:26 AM Middleware::Response ERROR: Unable to get subsection
 10/13/2016 9:26 AM Middleware::Response ERROR: Object reference not set to an instance of an object.

------------------------------------------------------------------------------
---------------------------------SnapinClient---------------------------------
------------------------------------------------------------------------------
 10/13/2016 9:26 AM Client-Info Client Version: 0.11.5
 10/13/2016 9:26 AM Client-Info Client OS:      Windows
 10/13/2016 9:26 AM Client-Info Server Version: 1.3.0-RC-13
 10/13/2016 9:26 AM Middleware::Response ERROR: Unable to get subsection
 10/13/2016 9:26 AM Middleware::Response ERROR: Object reference not set to an instance of an object.

------------------------------------------------------------------------------
--------------------------------PrinterManager--------------------------------
------------------------------------------------------------------------------
 10/13/2016 9:26 AM Client-Info Client Version: 0.11.5
 10/13/2016 9:26 AM Client-Info Client OS:      Windows
 10/13/2016 9:26 AM Client-Info Server Version: 1.3.0-RC-13
 10/13/2016 9:26 AM Middleware::Response ERROR: Unable to get subsection
 10/13/2016 9:26 AM Middleware::Response ERROR: Object reference not set to an instance of an object.

------------------------------------------------------------------------------
--------------------------------PowerManagement-------------------------------
------------------------------------------------------------------------------
 10/13/2016 9:26 AM Client-Info Client Version: 0.11.5
 10/13/2016 9:26 AM Client-Info Client OS:      Windows
 10/13/2016 9:26 AM Client-Info Server Version: 1.3.0-RC-13
 10/13/2016 9:26 AM Middleware::Response ERROR: Unable to get subsection
 10/13/2016 9:26 AM Middleware::Response ERROR: Object reference not set to an instance of an object.

------------------------------------------------------------------------------
----------------------------------UserTracker---------------------------------
------------------------------------------------------------------------------
 10/13/2016 9:26 AM Client-Info Client Version: 0.11.5
 10/13/2016 9:26 AM Client-Info Client OS:      Windows
 10/13/2016 9:26 AM Client-Info Server Version: 1.3.0-RC-13
 10/13/2016 9:26 AM Middleware::Response ERROR: Unable to get subsection
 10/13/2016 9:26 AM Middleware::Response ERROR: Object reference not set to an instance of an object.
 10/13/2016 9:26 AM Middleware::Communication URL: http://10.1.106.169/fog/management/index.php?sub=requestClientInfo&configure&newService&json
 10/13/2016 9:26 AM Middleware::Response Success
 10/13/2016 9:26 AM Service ERROR: Invalid promptTime, using default
 10/13/2016 9:26 AM Service Sleeping for 70 seconds

That was the last entry in the client log.

[Joe Schmitt]

@fry_p have you tried resetting encryption data for that host?

[fry_p]

@Joe-Schmitt No luck, still not communicating, last entry still 10/13/16. Do I need to restart the service?

[Joe Schmitt]

@fry_p that’s odd that it’s not logging anything. Can you check if the service is running? If not give it a start and see if it stops itself.

[Wayne Workman]

Also see if the settings.json file inside of c:\ program files x86 \ fog is blank or not…

[fry_p]

@Joe-Schmitt FOG Service is running.

So it seems to start and run on boot ok.

[fry_p]

@Wayne-Workman It is blank. I take it that’s bad…

[Joe Schmitt]

@fry_p Yeah it’s bad. We’re starting to see this bug pop up now. I was hoping it was just a fluke as I am still unsure as what’s causing it.

[fry_p]

@Joe-Schmitt There seems to be no rhyme or reason to which clients this happens to. I am willing to give you any logs you need because this is becoming more and more widespread in the district. Does this explain random reboots?

[Joe Schmitt]

@fry_p for the reboots if the host is truely already on the domain, it may be possible that the server is sending bad data. See my bug report here:

https://github.com/FOGProject/fog-client/issues/76

[Wayne Workman]

@fry_p Is there a bunch of white space inside of settings.json? Mine wasn’t just totally blank but had a bunch of spaces in it.

[Joe Schmitt]

@fry_p I can push out a band-aid in a few hours that’ll prevent any more clients from loosing their settings file. We still need to find out the underlying server issue, but this patch will stop any more damage from being done.

[Wayne Workman]

@Joe-Schmitt How easy would it be to gather every GUID for every version of the new fog client?

[Joe Schmitt]

@Wayne-Workman Why?

[Wayne Workman]

@fry_p This particular computer you pulled the log from in the opening post, is it configured to sleep after a specified time of inactivity? Either through settings you put on the image it uses or via GPO? If so, what is that time length set to?

[Joe Schmitt]

@fry_p could you upload a copy of the blanked setting files along with a hexdump of it?

[fry_p]

@Wayne-Workman @Joe-Schmitt They are configured to never go to sleep or hibernate through group policy. Give me a moment for the settings file.

[fry_p]

@Joe-Schmitt

It says I don’t have enough privileges to upload to the forums.