FOG Client log reporting old RC and odd behavior
-
@Joe-Schmitt not much to see, flagged it as spam when I tried to copy paste it.
-
@fry_p so that’s not good. The entire file is getting zero’d out.
-
So I’ve been thinking about lots of ways to try to detect when this happens.
The best idea I’ve had so far is to have a login script via GPO just copy each computer’s settings.json file to a share on the fog server, and have the fog server run a script every hour via CRON to do a checksum on every file, and then if any match the signature of one of the blank files, to just log it. This would give me a list of computers with the problem.
-
@Joe-Schmitt here is a copy of the file.
The computer this file came from hasn’t been imaged in a long while, but we’ve tried deploying snapins to update things like Chrome several times, and also I sometimes deploy snapins with batch files for various things.
Here’s the log file.
Joe, look at the end of the log.
0_1477940491375_fog.logThe log says that the client stopped working at 9/7/2016 4:50 PM
The teacher that uses this room says she’s only in here on Mondays and Wednesdays, and September 7th was a Wednesday. Maybe it’s coincidence, maybe the bug is somehow/someway related to being used or after being used.
Looking through the system logs, the Meraki service we have installed on all our systems is crashing a lot.
@fry_p do you have Meraki installed?
-
@Wayne-Workman now that is very interesting. The
Log
API uses a different style of file writing than theSettings
API does. So the fact that this is somehow happening to both is very surprising. I suspect some kind of outside interference. -
@fry_p could you upload the log file of a host that has stopped functioning?
If you still can’t upload provide a hex dump in a code block, e.g.
.... ....
If I’m right you should have a large amount of null bytes at the end of the file.
-
@Joe-Schmitt Here’s somethin else kind of interesting.
Right now I’m sitting in front of another computer that never returned for the “roll-call” if you remember when I did that.
Here’s it’s c:\users\tech.fog_user file.
0_1477944159340_.fog_user.logNotice, the log times…
This computer went unused for a month
!?!------------------------------------------------------------------------------ --------------------------------DisplayManager-------------------------------- ------------------------------------------------------------------------------ 9/30/2016 2:59 PM Client-Info Client Version: 0.11.5 9/30/2016 2:59 PM Client-Info Client OS: Windows 9/30/2016 2:59 PM Client-Info Server Version: 1.3.0-RC-10 9/30/2016 2:59 PM Middleware::Response Success 9/30/2016 2:59 PM DisplayManager ERROR: Invalid settings provided ------------------------------------------------------------------------------ 9/30/2016 2:59 PM Service Sleeping for 44 seconds 10/31/2016 2:58 PM UserService Initializing - phase 1 10/31/2016 2:58 PM Bus Registering ParseBus in channel Power 10/31/2016 2:58 PM UserService Initializing - phase 2 10/31/2016 2:58 PM Zazzles Creating main thread 10/31/2016 2:58 PM Zazzles Service construction complete 10/31/2016 2:58 PM Service Starting service 10/31/2016 2:58 PM Bus Became bus client 10/31/2016 2:58 PM Bus Registering OnUpdate in channel Update 10/31/2016 2:58 PM Bus Registering OnPower in channel Power 10/31/2016 2:58 PM Bus Registering OnStatus in channel Status 10/31/2016 2:58 PM Middleware::Response Success 10/31/2016 2:58 PM Service Initializing modules ------------------------------------------------------------------------------ ----------------------------------AutoLogOut---------------------------------- ------------------------------------------------------------------------------ 10/31/2016 2:58 PM Client-Info Client Version: 0.11.5 10/31/2016 2:58 PM Client-Info Client OS: Windows 10/31/2016 2:58 PM Client-Info Server Version: 1.3.0-RC-17 10/31/2016 2:58 PM Middleware::Response Success ------------------------------------------------------------------------------ ------------------------------------------------------------------------------ -----------------------------DefaultPrinterManager---------------------------- ------------------------------------------------------------------------------ 10/31/2016 2:58 PM Client-Info Client Version: 0.11.5 10/31/2016 2:58 PM Client-Info Client OS: Windows 10/31/2016 2:58 PM Client-Info Server Version: 1.3.0-RC-17 10/31/2016 2:58 PM Middleware::Response Success 10/31/2016 2:58 PM DefaultPrinterManager Checking defaults 10/31/2016 2:58 PM Printer Setting Ed Options Lab as default 10/31/2016 2:58 PM PrinterManager PrintUI return code = 0 ------------------------------------------------------------------------------ ------------------------------------------------------------------------------ --------------------------------DisplayManager-------------------------------- ------------------------------------------------------------------------------ 10/31/2016 2:58 PM Client-Info Client Version: 0.11.5 10/31/2016 2:58 PM Client-Info Client OS: Windows 10/31/2016 2:58 PM Client-Info Server Version: 1.3.0-RC-17 10/31/2016 2:58 PM Middleware::Response Success 10/31/2016 2:58 PM DisplayManager ERROR: Invalid settings provided ------------------------------------------------------------------------------ 10/31/2016 2:58 PM Service Sleeping for 90 seconds 10/31/2016 2:58 PM Bus::Client ERROR: No connection could be made because the target machine actively refused it 10/31/2016 2:58 PM Bus::Client ERROR: Connection lost 10/31/2016 2:59 PM Bus::Client ERROR: No connection could be made because the target machine actively refused it 10/31/2016 2:59 PM Bus::Client ERROR: No connection could be made because the target machine actively refused it
Notice also, those errors at the bottom (above this text) are EXACTLY the same ones I found and reported in the other thread. Here is the fog.log file, the client will not write to it.
For the moment, the settings.json file has this - and it’s inaccurate. We are on RC-18, not 17.
{ "HTTPS": "0", "Tray": "1", "Server": "10.2.1.11", "WebRoot": "/fog", "Version": "0.11.5", "Company": "FOG", "RootLog": "1", "ServerVersion": "1.3.0-RC-17", "ALOTime": "", "DefaultPrinter": "Ed Options Lab", "DisplayX": "", "DisplayY": "", "DisplayR": "", "PromptTime": "60", "Sleep": "90" }
@Joe-Schmitt I think I found a computer that is soon to destroy it’s settings.json file?
-
@Wayne-Workman I am genuinely at a loss of ideas right now. @Developers if anyone’s got any theories I’d be happy to hear them. As of right now my best guess is perhaps some kind of interference from another process.
Notice, the log times… from 2:59 -> 2:58 -> 2:59.
The client grabs the time straight from the SYSTEM itself. The only thing I can think of is some other program / script / policy is managing parts of the computer.
-
Just for reference, here’s a snippet of the .fog_user.log file from the other thread here:
https://forums.fogproject.org/topic/8819/fog-client-stops-reporting-working------------------------------------------------------------------------------ --------------------------------DisplayManager-------------------------------- ------------------------------------------------------------------------------ 10/19/2016 3:24 PM Client-Info Client Version: 0.11.5 10/19/2016 3:24 PM Client-Info Client OS: Windows 10/19/2016 3:24 PM Client-Info Server Version: 1.3.0-RC-14 10/19/2016 3:24 PM Middleware::Response Success 10/19/2016 3:24 PM DisplayManager ERROR: Invalid settings provided ------------------------------------------------------------------------------ 10/19/2016 3:24 PM Service Sleeping for 118 seconds 10/20/2016 6:50 AM UserService Initializing - phase 1 10/20/2016 6:50 AM Bus Registering ParseBus in channel Power 10/20/2016 6:50 AM Middleware::Configuration ERROR: Invalid parameters 10/20/2016 6:50 AM UserService Initializing - phase 2 10/20/2016 6:50 AM Zazzles Creating main thread 10/20/2016 6:50 AM Zazzles Service construction complete 10/20/2016 6:50 AM Service Starting service 10/20/2016 6:50 AM Service ERROR: ServerAddress not found! Exiting. 10/24/2016 6:53 AM UserService Initializing - phase 1 10/24/2016 6:53 AM Bus Registering ParseBus in channel Power 10/24/2016 6:53 AM Middleware::Configuration ERROR: Invalid parameters 10/24/2016 6:53 AM UserService Initializing - phase 2 10/24/2016 6:53 AM Zazzles Creating main thread 10/24/2016 6:53 AM Zazzles Service construction complete 10/24/2016 6:53 AM Service Starting service 10/24/2016 6:53 AM Service ERROR: ServerAddress not found! Exiting.
@Joe-Schmitt Notice the log dates and times! It jumps dates! Just like what I posted below!
-
9/30/2016 2:59 PM Service Sleeping for 44 seconds 10/31/2016 2:58 PM UserService Initializing - phase 1
That wasn’t 44 seconds.
10/19/2016 3:24 PM Service Sleeping for 118 seconds 10/20/2016 6:50 AM UserService Initializing - phase 1
And that was no 118 seconds.
-
10/19/2016 3:24 PM Service Sleeping for 118 seconds 10/20/2016 6:50 AM UserService Initializing - phase 1
User logs are prone to that. They don’t log the exiting sequence. So what happened is while it was sleeping the person logged out. And at 6:50AM the person logged back in. The issue here is the client is writing null bytes to files.
-
@Senior-Developers I might have found a clue. One of the earlier systems I pulled the blank settings.json file from, I didn’t notice then but now I notice.
Look at it’s name in fog? Look at my search criteria. I’m searching by room number (first 6 characters of name) and then doing a sub-search for windows desktop mb (my building abbreviation).
How did that computer show up in the search results?? And that computer just so happens to be one of the systems with this bug… The MAC address from the previous log I posted matches it’s mac.
90:B1:1C:98:08:81
-
I have a host ID of zero.
MariaDB [fog]> SELECT `hostID`, `hostName` FROM `hosts` WHERE `hostID` = '0'; +--------+----------+ | hostID | hostName | +--------+----------+ | 0 | | +--------+----------+ 1 row in set (0.00 sec)
Information about that host:
SELECT * FROM `hosts` WHERE `hostID` NOT IN (SELECT `hmhostID` FROM `hostMAC`); +--------+-----------------+--------------------------------------------------+------------+-----------+--------------+---------------------+---------------------+--------------+-----------+--------------+----------+------------+------------+------------------+----------------+------------------+----------------+------------+------------+----------+-------------+------------+--------------+---------------------+--------------+--------------+-------------+-------------+ | hostID | hostName | hostDesc | hostIP | hostImage | hostBuilding | hostCreateDate | hostLastDeploy | hostCreateBy | hostUseAD | hostADDomain | hostADOU | hostADUser | hostADPass | hostADPassLegacy | hostProductKey | hostPrinterLevel | hostKernelArgs | hostKernel | hostDevice | hostInit | hostPending | hostPubKey | hostSecToken | hostSecTime | hostPingCode | hostExitBios | hostExitEfi | hostEnforce | +--------+-----------------+--------------------------------------------------+------------+-----------+--------------+---------------------+---------------------+--------------+-----------+--------------+----------+------------+------------+------------------+----------------+------------------+----------------+------------+------------+----------+-------------+------------+--------------+---------------------+--------------+--------------+-------------+-------------+ | 0 | | | | 0 | 0 | 2016-10-25 18:15:40 | 0000-00-00 00:00:00 | fog | | | | | | | | | | | | | | | | 0000-00-00 00:00:00 | | | | | | 826 | R01100ROBOTWLMB | Created by FOG Reg on January 15, 2016, 11:04 am | 10.2.3.253 | 1 | 0 | 2016-01-15 11:04:52 | 0000-00-00 00:00:00 | fog | | | | | | | | | | | | NULL | | | | 0000-00-00 00:00:00 | 110 | | | 1 | +--------+-----------------+--------------------------------------------------+------------+-----------+--------------+---------------------+---------------------+--------------+-----------+--------------+----------+------------+------------+------------------+----------------+------------------+----------------+------------+------------+----------+-------------+------------+--------------+---------------------+--------------+--------------+-------------+-------------+ 2 rows in set (0.01 sec)
And it has several snapins assigned to it.
MariaDB [fog]> SELECT * from `snapinAssoc` WHERE `saID` = '0' OR `saHostID` = '0' OR `saSnapinID` = '0'; +------+----------+------------+ | saID | saHostID | saSnapinID | +------+----------+------------+ | 7037 | 0 | 38 | | 7031 | 0 | 19 | | 7028 | 0 | 31 | | 7032 | 0 | 20 | | 7035 | 0 | 32 | | 7034 | 0 | 30 | | 7033 | 0 | 23 | | 7036 | 0 | 34 | +------+----------+------------+ 8 rows in set (0.00 sec)
-
Even after deleting all those junk entries in the DB, that one computer that did have the bug still incorrectly shows up in the search results.
-
@Wayne-Workman incorrectly shows up? The search at first searches for multiple Ares. If r01300 is group the host is in, a snapin, an image, description, etc… It will show in the list. Fog isn’t just searching data on one field.
-
@Joe-Schmitt This is the very end of the log in question in hex (no permissions to upload the file and too many lines for the full dump in the code window).
0003B040 20 31 31 3A 34 32 20 41 4D 20 43 6C 69 65 6E 74 11:42 AM Client 0003B050 2D 49 6E 66 6F 20 43 6C 69 65 6E 74 20 56 65 72 -Info Client Ver 0003B060 73 69 6F 6E 3A 20 30 2E 31 31 2E 35 0D 0A 20 39 sion: 0.11.5.. 9 0003B070 2F 31 35 2F 32 30 31 36 20 31 31 3A 34 32 20 41 /15/2016 11:42 A 0003B080 4D 20 43 6C 69 65 6E 74 2D 49 6E 66 6F 20 43 6C M Client-Info Cl 0003B090 69 65 6E 74 20 4F 53 3A 20 20 20 20 20 20 57 69 ient OS: Wi 0003B0A0 6E 64 6F 77 73 0D 0A 20 39 2F 31 35 2F 32 30 31 ndows.. 9/15/201 0003B0B0 36 20 31 31 3A 34 32 20 41 4D 20 43 6C 69 65 6E 6 11:42 AM Clien 0003B0C0 74 2D 49 6E 66 6F 20 53 65 72 76 65 72 20 56 65 t-Info Server Ve 0003B0D0 72 73 69 6F 6E 3A 20 31 2E 33 2E 30 2D 52 43 2D rsion: 1.3.0-RC- 0003B0E0 31 30 0D 0A 20 39 2F 31 35 2F 32 30 31 36 20 31 10.. 9/15/2016 1 0003B0F0 31 3A 34 32 20 41 4D 20 4D 69 64 64 6C 65 77 61 1:42 AM Middlewa 0003B100 72 65 3A 3A 52 65 73 70 6F 6E 73 65 20 53 75 63 re::Response Suc 0003B110 63 65 73 73 0D 0A 20 39 2F 31 35 2F 32 30 31 36 cess.. 9/15/2016 0003B120 20 31 31 3A 34 32 20 41 4D 20 50 6F 77 65 72 4D 11:42 AM PowerM 0003B130 61 6E 61 67 65 6D 65 6E 74 20 43 61 6C 63 75 6C anagement Calcul 0003B140 61 74 69 6E 67 20 74 61 73 6B 73 20 74 6F 20 75 ating tasks to u 0003B150 6E 73 63 68 65 64 75 6C 65 0D 0A 20 39 2F 31 35 nschedule.. 9/15 0003B160 2F 32 30 31 36 20 31 31 3A 34 32 20 41 4D 20 50 /2016 11:42 AM P 0003B170 6F 77 65 72 4D 61 6E 61 67 65 6D 65 6E 74 20 43 owerManagement C 0003B180 61 6C 63 75 6C 61 74 69 6E 67 20 74 61 73 6B 73 alculating tasks 0003B190 20 74 6F 20 73 63 68 65 64 75 6C 65 0D 0A 2D 2D to schedule..-- 0003B1A0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B1B0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B1C0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B1D0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B1E0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 0D 0A 0D 0A ------------.... 0003B1F0 0D 0A 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ..-------------- 0003B200 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B210 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B220 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B230 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B240 0D 0A 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ..-------------- 0003B250 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B260 2D 2D 2D 2D 55 73 65 72 54 72 61 63 6B 65 72 2D ----UserTracker- 0003B270 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B280 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B290 0D 0A 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ..-------------- 0003B2A0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B2B0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B2C0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B2D0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B2E0 0D 0A 20 39 2F 31 35 2F 32 30 31 36 20 31 31 3A .. 9/15/2016 11: 0003B2F0 34 32 20 41 4D 20 43 6C 69 65 6E 74 2D 49 6E 66 42 AM Client-Inf 0003B300 6F 20 43 6C 69 65 6E 74 20 56 65 72 73 69 6F 6E o Client Version 0003B310 3A 20 30 2E 31 31 2E 35 0D 0A 20 39 2F 31 35 2F : 0.11.5.. 9/15/ 0003B320 32 30 31 36 20 31 31 3A 34 32 20 41 4D 20 43 6C 2016 11:42 AM Cl 0003B330 69 65 6E 74 2D 49 6E 66 6F 20 43 6C 69 65 6E 74 ient-Info Client 0003B340 20 4F 53 3A 20 20 20 20 20 20 57 69 6E 64 6F 77 OS: Window 0003B350 73 0D 0A 20 39 2F 31 35 2F 32 30 31 36 20 31 31 s.. 9/15/2016 11 0003B360 3A 34 32 20 41 4D 20 43 6C 69 65 6E 74 2D 49 6E :42 AM Client-In 0003B370 66 6F 20 53 65 72 76 65 72 20 56 65 72 73 69 6F fo Server Versio 0003B380 6E 3A 20 31 2E 33 2E 30 2D 52 43 2D 31 30 0D 0A n: 1.3.0-RC-10.. 0003B390 20 39 2F 31 35 2F 32 30 31 36 20 31 31 3A 34 32 9/15/2016 11:42 0003B3A0 20 41 4D 20 4D 69 64 64 6C 65 77 61 72 65 3A 3A AM Middleware:: 0003B3B0 52 65 73 70 6F 6E 73 65 20 53 75 63 63 65 73 73 Response Success 0003B3C0 0D 0A 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ..-------------- 0003B3D0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B3E0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B3F0 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B400 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D 2D ---------------- 0003B410 0D 0A 0D 0A 20 39 2F 31 35 2F 32 30 31 36 20 31 .... 9/15/2016 1 0003B420 31 3A 34 32 20 41 4D 20 4D 69 64 64 6C 65 77 61 1:42 AM Middlewa 0003B430 72 65 3A 3A 43 6F 6D 6D 75 6E 69 63 61 74 69 6F re::Communicatio 0003B440 6E 20 55 52 4C 3A 20 68 74 74 70 3A 2F 2F 31 30 n URL: http://10 0003B450 2E 31 2E 31 30 36 2E 31 36 39 2F 66 6F 67 2F 6D .1.106.169/fog/m 0003B460 61 6E 61 67 65 6D 65 6E 74 2F 69 6E 64 65 78 2E anagement/index. 0003B470 70 68 70 3F 73 75 62 3D 72 65 71 75 65 73 74 43 php?sub=requestC 0003B480 6C 69 65 6E 74 49 6E 66 6F 26 63 6F 6E 66 69 67 lientInfo&config 0003B490 75 72 65 26 6E 65 77 53 65 72 76 69 63 65 26 6A ure&newService&j 0003B4A0 73 6F 6E 0D 0A 20 39 2F 31 35 2F 32 30 31 36 20 son.. 9/15/2016 0003B4B0 31 31 3A 34 32 20 41 4D 20 4D 69 64 64 6C 65 77 11:42 AM Middlew 0003B4C0 61 72 65 3A 3A 52 65 73 70 6F 6E 73 65 20 53 75 are::Response Su 0003B4D0 63 63 65 73 73 0D 0A 20 39 2F 31 35 2F 32 30 31 ccess.. 9/15/201 0003B4E0 36 20 31 31 3A 34 32 20 41 4D 20 53 65 72 76 69 6 11:42 AM Servi 0003B4F0 63 65 20 45 52 52 4F 52 3A 20 49 6E 76 61 6C 69 ce ERROR: Invali 0003B500 64 20 70 72 6F 6D 70 74 54 69 6D 65 2C 20 75 73 d promptTime, us 0003B510 69 6E 67 20 64 65 66 61 75 6C 74 0D 0A 20 39 2F ing default.. 9/ 0003B520 31 35 2F 32 30 31 36 20 31 31 3A 34 32 20 41 4D 15/2016 11:42 AM 0003B530 20 53 65 72 76 69 63 65 20 53 6C 65 65 70 69 6E Service Sleepin 0003B540 67 20 66 6F 72 20 31 32 38 20 73 65 63 6F 6E 64 g for 128 second 0003B550 73 0D 0A s..
-
@Tom-Elliott I know how the search works, it’s very robust and useful. However I’ve looked through this host’s groups, inventory, snapins, printers. I can’t find any string with “r01300” in it in any of those areas for that host. I don’t know why it’s matching - and I think it odd that it also happened to suffer from the OP’s bug.
-
@Wayne-Workman My description of elements searches was even further limited that how much is searched. If the string r01300 shows up in any of the inventory and what not. It’s difficult to express what and/or where, but I can try a session tonight with you if you’re up to it to see if we can figure out exactly where this is all occurring.
-
Just wanted to post an update here, Joe has been helping me with figuring out what the problem is, he built a special copy of the fog client for me to use, and I’ve been using this along with some other scripting techniques to try to “cause” the issue to happen, and when it does this special fog client has mechanisms in it to immediately gather data that we need to figure out what’s happening.
So… it’s just a waiting game right now.
-
@Wayne-Workman I have the utmost confidence in the team. I patiently await the results.