[SteamCMD] Optionally log update/install progress to file

[Exigency]

For gameserver control panels moving to SteamCMD, it is impossible to monitor server install/update progress as SteamCMD has flakey STDOUT on Windows and *NIX. It would be a great addition to have a ConVar option to enable writing update progress to (an already existing?) SteamCMD logfile.

Just to be clear, I am talking about the highlighted part in the screenshot that would be written to logfiles so gameserver control panels can poll and show update progress to the end-user.

As STDERR is already logged to a file by default, progress logging would make a valuable addition to SteamCMD.

[Exigency]

Related: #352

[stevenh]

Digging around the issue could well be that stdout goes fully buffered when stdout isn't a tty. When this happens the buffer size is apparently 1 page size so likely 4k, which ties in with what I've seen when piping the output to a file for large downloads.

The fix could be as easy as adding the following to the code to enforce line buffering of stdout:

setvbuf(stdout, (char *)NULL, _IOLBF, 0);

This still doesn't explain the jumbled output.

[powerlord]

SteamCMD uses a number of log files. Not sure where it goes on Windows, but on Linux it does to ~/Steam/logs/ (Where ~ is the user's home directory)

I can see 5 logs sitting there right now:

-rwxrwxr-x 1 tf2 tf2 32074 Aug 26 15:18 appinfo_log.txt
-rwxrwxr-x 1 tf2 tf2  3752 Aug 26 15:20 bootstrap_log.txt
-rwxrwxr-x 1 tf2 tf2  4930 Aug 26 15:20 connection_log.txt
-rwxrwxr-x 1 tf2 tf2 43638 Aug 26 15:20 content_log.txt
-rw-rw-r-- 1 tf2 tf2     0 Aug 26 15:18 stderr.txt

Note that stderr.txt may be empty because I use @ShutdownOnFailedCommand 1 in my steamcmd script.

Note that none of these logs contain what you see in stdout, though.

[PhonicUK]

I don't think it's necessary to use a log file, just to not use such a large buffer for standard output so that it's output can be piped in a sane manner.

[alfred-valve]

steamcmd already sets setvbuf() when creating its console window, but I notice that if it didn't need to create a console window (so depending on how it is launched) you may not be setup right. I'll fix that.

[HenryGarle]

@alfred-valve Glad to see a fix might be coming for this! Is it still on the cards? It would certainly make my life much easier.

[Gachl]

Has there been any updates yet? We're currently re-developing our server manager in C# where it seems not possible to get the console output from StandardOutput. That's kinda a big issue to us because we can't check for updates on an app or track the update status.

Process process = new Process();
process.StartInfo = new ProcessStartInfo()
{
    FileName = @"C:\steamcmd\steamcmd.exe",
    Arguments = "+login anonymous +app_info_update 1 +app_info_print 258550 +exit",
    RedirectStandardOutput = true,
    UseShellExecute = false
};
process.Start();
process.WaitForExit();
string statusStructure = process.StandardOutput.ReadToEnd();

The string statusStructure will only contain

Steam Console Client (c) Valve Corporation
-- type 'quit' to exit --
Loading Steam API...OK.

Connecting anonymously to Steam Public...Logged in OK
Waiting for license info...OK

but none of the relevant stuff.

[Tele42]

@dgibbs64 and my dirt simple updater works around this by deleting the local cache before trying to get the remote build version. See https://github.com/dgibbs64/linuxgsm/blob/master/functions/update_check.sh#L121 for linuxgsm's version and https://github.com/SteamLUG/steamlug-gaming-servers/wiki/GS5#update-script for the dirt simple updater.

[Gachl]

That didn't work for me. I've found a workaround of executing the same command a couple of times to force the buffer to flush.

+login anonymous +app_info_update 1 +app_info_print 258550 +app_info_print 258550 +exit

This gives me about one and a quarter of the results of the app_info_print command. It's not helping for tracking running updates though.

[PhonicUK]

The issue is that SteamCMD often isn't writing to standard output - under Windows it's writing data directly to the console buffer without using the standard IO streams. This means that in order to capture it's output programmatically you have to do some voodoo black magic with the Win32 console API.

It also outputs the results of things like +app_info_print in one huge write instead of a line at a time, which requires that you have to force the console to have a massive vertical buffer to capture all the output or you'll just end up with the last screen buffers worth of output.

It's the kind of thing I'd do if I were deliberately trying to prevent someone from reading the output programmatically while still being able to read it when executed by hand on a console. I have managed to work around it but it was a significant amount of work.

[zrisher]

The issue is that SteamCMD often isn't writing to standard output - under Windows it's writing data directly to the console buffer without using the standard IO streams.

Finally an explanation of the the root cause of this issue that makes sense.

Relates to #1929.

This means that in order to capture it's output programmatically you have to do some voodoo black magic with the Win32 console API... I have managed to work around it but it was a significant amount of work.

@PhonicUK If you managed to collect all the output from steamcmd, any chance you'd be willing to release that work as a wrapper executable?

[PhonicUK]

@zrisher Afraid not since its for my companies commercial control panel so we don't want other vendors to have the same advantage. We had to produce a complex console application that can create and manipulate a virtual console buffer (without an actual console window attached) that it then makes the 'misbehaving' application use, and then it scans the virtual console row by row to get the data and write it to standard output so other applications can read it normally. It's really really messy and uber-hacky but it works just barely well enough to get data out.