RC10 Broken Items on upgrade

adukes40 · Sep 13, 2016, 8:11 PM

@Tom-Elliott

I can find the command again yea

Tom Elliott · Sep 13, 2016, 8:11 PM

@Tom-Elliott I need you to clear shash for om snapin table

Tom Elliott · Sep 13, 2016, 8:12 PM

Update snapins set sHash=‘’

adukes40 · Sep 13, 2016, 2:15 PM

@Tom-Elliott

mysql> update snapins set sHash=‘’;
Query OK, 0 rows affected (0.01 sec)
Rows matched: 746 Changed: 0 Warnings: 0

I have to go for now, keep the message coming and I will respond once I get a minutes, I have to take my son to soccer practice.

Tom Elliott · Sep 13, 2016, 8:16 PM

@adukes40 any better on GUI?

Tom Elliott · Sep 13, 2016, 8:21 PM

@Tom-Elliott hell try update snapins set sHash='abc';
Please

adukes40 · Sep 14, 2016, 1:40 PM

@Tom-Elliott As discussed last night, around 6pm bandwidth ded down and the GUI ran fine. This morning it is back to what it was doing yesterday. As requested here is the tail -f of the access.log

root@MSDCATS09:/var/log/apache2# tail -f access.log
::1 - - [14/Sep/2016:08:05:39 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”
10.102.12.182 - - [14/Sep/2016:08:05:39 -0400] “-” 408 0 “-” “-”
::1 - - [14/Sep/2016:08:05:40 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”
::1 - - [14/Sep/2016:08:05:41 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”
::1 - - [14/Sep/2016:08:05:42 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”
::1 - - [14/Sep/2016:08:05:43 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”
::1 - - [14/Sep/2016:08:05:44 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”
::1 - - [14/Sep/2016:08:05:45 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”
::1 - - [14/Sep/2016:08:05:46 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”
::1 - - [14/Sep/2016:08:05:47 -0400] “OPTIONS * HTTP/1.0” 200 125 “-” “Apache/2. 4.7 (Ubuntu) OpenSSL/1.0.1f (internal dummy connection)”

Also here is a screenshot of what I see on the bandwidth monitor:

You can see the 6PM, and then this morning when I disabled the NIC, other than that something is being pushed from this server, but no clue what.

Wayne Workman · Sep 14, 2016, 9:18 AM

@adukes40 Please install apachetop.
Ubuntu/Debian:
sudo apt-get install apachetop -y
Fedora/RHEL/CentOS:
sudo yum install apachetop -y

Then run it:
apachetop

Stop running it with ctrl+c

It’ll give you counters for page requests, and file requests. Let it run for a few minutes and then take a screenshot of it, and post here please.

Also, you can install iftop as well, to monitor bandwidth being sent to individual IP addresses. Install as normal, i.e. yum install iftop or apt-get install iftop and then run with:
iftop -n

Stop running it with ctrl+c

I’d like a screenshot of that too.

Tom Elliott · Sep 14, 2016, 3:21 PM

@adukes40 can you disable ipv6?

adukes40 · Sep 14, 2016, 3:27 PM

@Wayne-Workman

I know this only shows 40 seconds, but i let atop run for 3 minutes, and nothing changed. when I hit ctrl C. its just dumps me back to the terminal

And here is the bandwidth usage. As you can see I re-enabled the NIC at 11:15… instantly starts heading to maxed out.

Wayne Workman · Sep 14, 2016, 3:36 PM

@adukes40 For one of those IP addresses, can you remote into one of them and get the c:\fog.log and post the last couple pages of it here?

Tom Elliott · Sep 14, 2016, 3:37 PM

@adukes40 please disable ipv6 for Apache, though I can’t tell you how right this moment. A simple test might be to just stop Apache, edit the config.class.php file of fog and replace the 127.0.0.1 with localhost. This should prevent Apache trying to connect to the db using ipv6 altogether.

adukes40 · Sep 14, 2016, 4:02 PM

@Wayne-Workman

Here is 5 minutes worth: Starting at 11:14 right around the time the NIC was reenabled:

------------------------------------------------------------------------------
---------------------------------ClientUpdater--------------------------------
------------------------------------------------------------------------------
 9/14/2016 11:14 AM Client-Info Client Version: 0.11.4
 9/14/2016 11:14 AM Client-Info Client OS:      Windows
 9/14/2016 11:14 AM Client-Info Server Version: 1.3.0-RC-10
 9/14/2016 11:14 AM Middleware::Response ERROR: Unable to get subsection
 9/14/2016 11:14 AM Middleware::Response ERROR: Object reference not set to an instance of an object.

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

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

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

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

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

------------------------------------------------------------------------------
----------------------------------UserTracker---------------------------------
------------------------------------------------------------------------------
 9/14/2016 11:14 AM Client-Info Client Version: 0.11.4
 9/14/2016 11:14 AM Client-Info Client OS:      Windows
 9/14/2016 11:14 AM Client-Info Server Version: 1.3.0-RC-10
 9/14/2016 11:14 AM Middleware::Response ERROR: Unable to get subsection
 9/14/2016 11:14 AM Middleware::Response ERROR: Object reference not set to an instance of an object.
 9/14/2016 11:14 AM Middleware::Communication URL: http://10.103.72.49/fog/management/index.php?sub=requestClientInfo&configure&newService&json
 9/14/2016 11:14 AM Middleware::Communication ERROR: Could not contact FOG server
 9/14/2016 11:14 AM Middleware::Communication ERROR: Unable to connect to the remote server
 9/14/2016 11:14 AM Middleware::Response Success
 9/14/2016 11:14 AM Service Sleeping for 60 seconds
 9/14/2016 11:15 AM Middleware::Communication URL: http://10.103.72.49/fog/management/index.php?sub=requestClientInfo&mac=78:2B:CB:A8:58:E8||00:00:00:00:00:00:00:E0&newService&json
 9/14/2016 11:15 AM Middleware::Authentication Waiting for authentication timeout to pass
 9/14/2016 11:15 AM Middleware::Communication Download: http://10.103.72.49/fog/management/other/ssl/srvpublic.crt
 9/14/2016 11:15 AM Data::RSA FOG Server CA cert found
 9/14/2016 11:15 AM Middleware::Authentication Cert OK
 9/14/2016 11:15 AM Middleware::Communication POST URL: http://10.103.72.49/fog/management/index.php?sub=requestClientInfo&authorize&newService
 9/14/2016 11:16 AM Middleware::Response Success
 9/14/2016 11:16 AM Middleware::Authentication Authenticated
 9/14/2016 11:16 AM Middleware::Communication URL: http://10.103.72.49/fog/management/index.php?sub=requestClientInfo&mac=78:2B:CB:A8:58:E8||00:00:00:00:00:00:00:E0&newService&json
 9/14/2016 11:16 AM Middleware::Communication ERROR: Could not contact FOG server
 9/14/2016 11:16 AM Middleware::Communication ERROR: Unable to connect to the remote server
 9/14/2016 11:16 AM Middleware::Response Success
 9/14/2016 11:16 AM Middleware::Communication URL: http://10.103.72.49/fog/service/getversion.php?clientver&newService&json
 9/14/2016 11:16 AM Middleware::Communication URL: http://10.103.72.49/fog/service/getversion.php?newService&json

 9/14/2016 11:17 AM Service Creating user agent cache
 9/14/2016 11:17 AM Middleware::Response ERROR: Unable to get subsection
 9/14/2016 11:17 AM Middleware::Response ERROR: Object reference not set to an instance of an object.
 9/14/2016 11:17 AM Middleware::Response ERROR: Unable to get subsection
 9/14/2016 11:17 AM Middleware::Response ERROR: Object reference not set to an instance of an object.
 9/14/2016 11:17 AM Middleware::Response ERROR: Unable to get subsection
 9/14/2016 11:17 AM Middleware::Response ERROR: Object reference not set to an instance of an object.

------------------------------------------------------------------------------
---------------------------------ClientUpdater--------------------------------
------------------------------------------------------------------------------
 9/14/2016 11:17 AM Client-Info Client Version: 0.11.4
 9/14/2016 11:17 AM Client-Info Client OS:      Windows
 9/14/2016 11:17 AM Client-Info Server Version: 1.3.0-RC-10
 9/14/2016 11:17 AM Middleware::Response Success
 9/14/2016 11:17 AM Middleware::Communication Download: http://10.103.72.49/fog/client/SmartInstaller.exe
 9/14/2016 11:17 AM Data::RSA FOG Project cert found
 9/14/2016 11:17 AM Data::RSA ERROR: Certificate validation failed
 9/14/2016 11:17 AM Data::RSA ERROR: Trust chain did not complete to the known authority anchor. Errors: A required certificate is not within its validity period when verifying against the current system clock or the timestamp in the signed file. (NotTimeValid)
 9/14/2016 11:17 AM ClientUpdater ERROR: Update file is not authentic
------------------------------------------------------------------------------


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

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

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

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

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

------------------------------------------------------------------------------
----------------------------------UserTracker---------------------------------
------------------------------------------------------------------------------
 9/14/2016 11:17 AM Client-Info Client Version: 0.11.4
 9/14/2016 11:17 AM Client-Info Client OS:      Windows
 9/14/2016 11:17 AM Client-Info Server Version: 1.3.0-RC-10
 9/14/2016 11:17 AM Middleware::Response ERROR: Unable to get subsection
 9/14/2016 11:17 AM Middleware::Response ERROR: Object reference not set to an instance of an object.
 9/14/2016 11:17 AM Middleware::Communication URL: http://10.103.72.49/fog/management/index.php?sub=requestClientInfo&configure&newService&json
 9/14/2016 11:17 AM Middleware::Response Success
 9/14/2016 11:17 AM Service Sleeping for 80 seconds
 9/14/2016 11:18 AM Middleware::Communication URL: http://10.103.72.49/fog/management/index.php?sub=requestClientInfo&mac=78:2B:CB:A8:58:E8||00:00:00:00:00:00:00:E0&newService&json
 9/14/2016 11:19 AM Middleware::Communication ERROR: Could not contact FOG server
 9/14/2016 11:19 AM Middleware::Communication ERROR: Unable to connect to the remote server
 9/14/2016 11:19 AM Middleware::Response Success
 9/14/2016 11:19 AM Middleware::Communication URL: http://10.103.72.49/fog/service/getversion.php?clientver&newService&json
 9/14/2016 11:19 AM Service ERROR: Unable to get cycle data
 9/14/2016 11:19 AM Service ERROR: Unable to connect to the remote server
 9/14/2016 11:19 AM Middleware::Response Success

Mod edited to use code box.

Wayne Workman · Sep 14, 2016, 4:06 PM

@adukes40 There is the issue:

9/14/2016 11:17 AM Data::RSA FOG Project cert found
9/14/2016 11:17 AM Data::RSA ERROR: Certificate validation failed
9/14/2016 11:17 AM Data::RSA ERROR: Trust chain did not complete to the known authority anchor. Errors: A required certificate is not within its validity period when verifying against the current system clock or the timestamp in the signed file. (NotTimeValid)
9/14/2016 11:17 AM ClientUpdater ERROR: Update
 file is not authentic

I notice the timestamps in the log is off. This could do it. Here, it’s 11:05. In your log it says 11:19 which is incorrect, no matter what timezone you’re in. This can cause the issue.

Remote into that computer again, correct it’s time, and see if the client updates. Watch the log, too.

adukes40 · Sep 14, 2016, 4:25 PM

@Wayne-Workman

Well what I provided was between 11:14 and 11:19, the time is right because I brought the log over at 11:47, and the latest time in the log was 11:47. But the times I gave you was while the nic was enabled. Give me a few minutes and I will show you what it does right now. I just cant keep the nic turned on for long because its floods it.

Wayne Workman · Sep 14, 2016, 4:26 PM

@adukes40 Still, the logs literally say it’s a time issue:

A required certificate is not within its validity period when verifying against the current system clock or the timestamp in the signed file.

adukes40 · Sep 14, 2016, 4:31 PM

@Wayne-Workman Well the workstation says 12:30 and the latest timestamp in the log says 12:30… of course I am typing this at 12:30. Could the server time have been knocked out of sync? All of our workstations are set with GPO to pull time from NTP from our state network.

Wayne Workman · Sep 14, 2016, 5:00 PM

@adukes40 The local fog server’s time has no impact on this particular thing, I think. When @Joe-Schmitt builds the client, he signs it afterwards, and I assume his system has the right timezone and time/date set because we’ve been using client 0.11.5 for some time now, the update to it went fine. It’s been out for a while now. If there was an issue with it’s signature, everyone would have brought this up when it was released. Try to re-run the installer please. It’ll re-download the client, maybe that will fix it.

Also - your bandwidth problem is because all your hosts are re-downloading the new fog client from the server over and over, because signature checking of the signed file is failing. You could also try to delete the web directory and then re-run the installer to ensure you have the latest files correctly. Delete it with rm -rf /var/www/fog;rm -rf /var/www/html/fog and then re-run the installer.

Tom Elliott · Sep 14, 2016, 5:40 PM

@Wayne-Workman it would fail to sign if his date time where broken. This cert was generated by me on a system that had been synced in time by pool.ntp.org. if there were a problem with his time he wouldn’t have been able to sign it at all. The time issue that’s being seen would be from the clients time being off.

This same message can appear from the servers own certs too though, as the time the SSL certs were made on the server could’ve been off. I do try to sync the time with an ntp source first but that doesn’t necessarily mean it will work. This is unlikely the issue though. I don’t know what is, but let’s try to narrow down what is causing the bandwidth usage first. We’ve stopped replication services so we now know it isn’t a replication issue causing the problem. We have essentially forced all snapins to fail rather immediately so as to limit it as a potential issue point. All I’m seeing in the logs is a bunch of ::1 requests which is ipv6 localhost TCP calls. If switching to pure socket connections doesn’t fix this I need to remote in at some point to see exactly what’s going on. For now I recommend not rerunning the installer as it will more or less cause us to have to start from scratch.

Wayne Workman · Sep 14, 2016, 5:42 PM

@Tom-Elliott said in RC10 Broken Items on upgrade:

don’t know what is, but let’s try to narrow down what is causing the bandwidth usage first.

It’s the hosts downloading the client over and over. It says so in the log he posted. The file fails signature authentication, so it just tries again the next iteration.

RC10 Broken Items on upgrade

146

12.1k

17.3k

155.3k