Using the Steam Remote Play logs

[GeeEl]

I was looking through the streaming logs and (after initially being quite intimidated by the lack of line breaks) was thinking of asking if the metrics meant what I thought they meant.
It turns out that asking about that is 80% (edit: 47%) of the way to making a beginner's guide - so here's a draft which may be useful.

Please comment if I have anything wrong, or if you have suggestions on information to add.

What to check out before digging into the logs

If you're after some quick information on performance or potential fixes have a look at the following pages (in fact look at them anyway, because they're very useful):

• The Steam Remote Play support page.
  
• A nice write up on how to read the in-game streaming graph by Davew_uk
  I believe that slouken's ^^ translates to "Please read above, this is good information".

Diagnosing Streaming issues with the logs

As mentioned in the pages above there's an easily accessible streaming performance display available while playing (by pressing GUIDE+Y or F6).

In addition there are logs stored on the host machine which give an overview of performance at the end of a streaming session.

These logs relate to the "Display" latency shown in the on-screen streaming statistics and network latency (in streaming_log.txt) along with some information on game latency (in the *Trace.txt files).

Looking at the steaming logs lets you:

• see session overview stats
  
• drill down to see how each step the game video takes towards rendering on the remote machine is performing.
  
• compare performance of different settings (by comparing the overviews of different sessions)
  
• possibly identify specific performance bottlenecks during the beta

Finding your streaming logs

If you're streaming from a Windows host you can find your general Remote Play logs in the folders below (without the x86 bit if your machine is running a 32bit windows).

 Directory of C:\Program Files (x86)\Steam\logs

12/02/2014  06:54 AM     1,700,905,420 StreamAudioTrace.txt
09/02/2014  09:34 AM           167,143 streaming_log.previous.txt
12/02/2014  06:59 AM            67,312 streaming_log.txt
12/02/2014  06:54 AM       867,258,814 StreamVideoTrace.txt

If using a Linux host (which I haven't yet) it should be trivial to find the streaming logs folder with a trusty find command:

find ~ -name "streaming_log.txt"

For SteamOS hosts the logs are found under

/home/steam/.local/share/Steam/logs
/home/steam/.local/share/Steam/streaming

For MacOS:

♥♥♥♥matic2000 eredeti hozzászólása:

OS 10.6.8 Mac users should find their logs in

 [user name]/Library/Application Support/Steam/logs

The two *Trace.txt files hold massive detail about audio and video at the frame by frame level. They are kept until cleared manually but only collect data while the streaming graph is displayed. A much more concise versions of them can be taken with the screenshot capture.

If you end up capturing a screenshot and detailed video/audio stats for part of a session they end up as zips in:

 Directory of C:\Program Files (x86)\Steam\streaming

12/02/2014  06:41 AM         1,469,755 Dark_Souls-_Prepare_to_Die_Edition_(211420)_02-12-14_06-41-08.zip
12/02/2014  06:53 AM         4,337,432 Tomb_Raider_(203160)_02-12-14_06-53-41.zip

Looking inside one of the zips we can see they have a cut down chunk of the *Trace.txt files and a nice screenshot.

12/02/2014  06:41 AM         3,138,700 Screenshot.png
12/02/2014  06:41 AM           790,068 StreamAudioTrace.txt
12/02/2014  06:41 AM           218,953 StreamVideoTrace.txt

For the moment I'm just looking at the overview stats from the gaming session, which are found in the much lighter streaming_log.txt

Looking at session statistics with streaming_log.txt

For an example I'm going to have a look at DiRT 3, which runs pretty well on my system.

Note: The streaming_log.txt file uses UNIX style line breaks, which Notepad doesn't handle well. If viewing it on a Windows system use Wordpad/write (maybe even Word) to preserve line breaks

[2014-02-20 23:40:05] 
=====================================================================
Game: DiRT 3 (44320)
[2014-02-20 23:40:05] Recording on device: Realtek HDMI Output (ATI HDMI Audio)
[2014-02-20 23:40:05] Audio client mix format:
[2014-02-20 23:40:05] 	format: 65534
[2014-02-20 23:40:05] 	channels: 2
[2014-02-20 23:40:05] 	samples/sec: 48000
[2014-02-20 23:40:05] 	bytes/sec: 384000
[2014-02-20 23:40:05] 	alignment: 8
[2014-02-20 23:40:05] 	bits/sample: 32
[2014-02-20 23:40:05] 	channel mask: 0x3
[2014-02-20 23:40:05] 	data format: {00000003-0000-0010-8000-00AA00389B71}
[2014-02-20 23:40:05] Initializing audio with 2 channels and 48000 samples/sec
[2014-02-20 23:40:10] Detected 4 logical processors, using 2 threads
[2014-02-20 23:40:10] >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Capture method set to Desktop BitBlt RGB
[2014-02-20 23:40:31] >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Capture method set to Game async D3D11 NV12

The header shows some basic details about the capture methods being used.
It should be mostly the same for every streaming session, but what does look interesting is the Capture method:

Capture method set to Desktop BitBlt RGB
Capture method set to Game async D3D11 NV12

In this case D3 (aka annoyingly mixed-case DiRT 3) is using a newer DirectX 11 "asynchronous" capture method, meaning that it can do some extra steps in parallel.

Now we get to the performance information - the session statistics.

[2014-02-20 23:48:31] "SessionStats"
{
	"TimeSubmitted"		"1392904111"
	"ResolutionX"		"1280"
	"ResolutionY"		"720"
	"CaptureName"		"Game async D3D11 NV12"
	"DecoderName"		"VDPAU hardware decoding"
	"BandwidthLimit"		"10000"
	"FramerateLimit"		"50"

In this case, I'm running in 720p (ResolutionY) as my (recently upgraded) host machine has a CPU circa 2009 (an AMD Phenom II x4 945 - newer than I thought).
My SteamOS client is using VDPAU hardware decoding (DecoderName). According to wikipedia this is open source and courtesy of Nvidia - thanks Nvidia!

I've manually limited bandwidth to 10Mbps, and left framerate as Automatic - Remote Play has decided that a cap of 50 frames per second would be best.

The next chunk of SessionStats shows obvious problems that are causing poor performance:

	"SlowSeconds"		"0"
	"SlowGamePercent"		"0"
	"SlowCapturePercent"	"0"
	"SlowConvertPercent"		"0"
	"SlowEncodePercent"		"0"
	"SlowNetworkPercent"	"0"
	"SlowDecodePercent"		"0"

The Slow* chunks are pretty self exlanatory.
SlowGame - caused by the game itself running slow
SlowCapture - caused by copying the displayed frame into memory taking too long
SlowConvert - Erm... TO BE COMPLETED...
SlowEncode - caused by the CPU (or hardware encoder) taking a long time to encode a frame in to x264.
SlowNetwork - caused by network connection problems, or a lot of competing traffic on the network.
SlowDecode - caused by the client machine taking a long time to decode the frames.

Next we get onto the standard format for the performance statistcs, average (Avg) and standard deviation (StdDev) statistics for the streaming performance metrics.

From the Wikipedia Page on Standard deviation[en.wikipedia.org] (give them a donation or help fix a page - they love that):
In statistics and probability theory, the standard deviation ... shows how much variation or dispersion from the average exists. A low standard deviation indicates that the data points tend to be very close to the [average] a high standard deviation indicates that the data points are spread out over a large range of values.

For our purposes if the StdDev is small compared to Avg it means that there's generally consistent performance for this metric. If it's large it means that that metric could be causing spikey delays.

If the stat measures time it'll be in milliseconds.

	"AvgClientBitrate"		"63.820789337158203"
	"StdDevClientBitrate"		"16.055004119873047"
	"AvgServerBitrate"		"8809.0078125"
	"StdDevServerBitrate"		"14545.39453125"

ServerBitrate - the video+audo bitrate that the x264 encoder streaming to the client in Kbit/s.
ClientBitrate - bitrate the client is sending data (input and data confirmation) back to the server in Kbit/s

	"AvgLinkBandwidth"		"61510.49609375"
	"AvgPingMS"		"1.1842796802520752"
	"StdDevPingMS"		"0.25608810782432556"

LinkBandwidth - An estimation of available network bandwidth in Kbit/s
PingMS - Network round-trip time between the host and remote client

	"AvgCaptureMS"		"5.708702564239502"
	"StdDevCaptureMS"		"2.6058037281036377"

CaptureMS - How long it takes to make a copy of the current frame for encoding

	"AvgConvertMS"		"4.9717216491699219"
	"StdDevConvertMS"		"1.6487746238708496"

ConvertMS - TO BE COMPLETED

	"AvgEncodeMS"		"12.187912940979004"
	"StdDevEncodeMS"		"2.8964734077453613"

EncodeMS - Time taken to compress the frame for transmission to the client. This is one of the most expensive steps and is very CPU intensive (until hardware encoding is supported).

	"AvgNetworkMS"		"0.56417733430862427"
	"StdDevNetworkMS"		"0.11537900567054749"

NetworkMS - Time taken transferring the encoded frame to the client over the network. In a good setup this should be negligible.

	"AvgDecodeMS"		"3.3226580619812012"
	"StdDevDecodeMS"		"1.5122100114822388"

DecodeMS - Time taken by the client to decompress the video frame

	"AvgDisplayMS"		"4.4955034255981445"
	"StdDevDisplayMS"		"4.8185925483703613"

DisplayMS - Time taken to display the frame on the TV/Monitor

	"AvgFrameMS"		"43.798892974853516"
	"StdDevFrameMS"		"10.485637664794922"

FrameMS - Total time taken to stream the frame.

	"AvgFPS"		"46.833816528320312"
	"StdDevFPS"		"7.0818371772766113"
}

FPS - Frames per second

Looking at SteamVideoTrace.txt

As mentioned, SteamVideoTrace.txt in the logs folder is a massive file. The better way to go about looking at the frame by frame detail is to capture a screenshot zips (stored in the Steam/streaming directory). The capture of the data and screenshot is triggered in game with pressing F8 (keyboard) or GUIDE+X (controller) and can only be done while the performance graph is displayed.

It gives the same sort of detail as the performance log above, but with detail going down to individual frame by frame timings.

The below chunk is from streaming Tomb Raider (2013)

NETWORK: Ping: 1.19ms, Server: 9603 Kbit/s, Client: 64 Kbit/s, Link: 81516 Kbit/s, Packet loss: 0.00%
Frame: 2582, 24573 bytes, k_EStreamFrameEventStart at 60887.93ms
           k_EStreamFrameEventCaptureBegin at 60908.10ms, delta: 20.17ms
           k_EStreamFrameEventCaptureEnd at 60915.61ms, delta: 7.51ms
           k_EStreamFrameEventConvertBegin at 60915.61ms, delta: 0.00ms
           k_EStreamFrameEventConvertEnd at 60915.61ms, delta: 0.00ms
           k_EStreamFrameEventEncodeBegin at 60915.61ms, delta: 0.00ms
           k_EStreamFrameEventEncodeEnd at 60926.22ms, delta: 10.62ms
           k_EStreamFrameEventSend at 60924.76ms, delta: -1.46ms
           k_EStreamFrameEventRecv at 60925.36ms, delta: 0.60ms
           k_EStreamFrameEventDecodeBegin at 60925.54ms, delta: 0.18ms
           k_EStreamFrameEventDecodeEnd at 60927.81ms, delta: 2.27ms
           k_EStreamFrameEventUploadBegin at 60927.99ms, delta: 0.18ms
           k_EStreamFrameEventUploadEnd at 60928.22ms, delta: 0.23ms
           k_EStreamFrameEventComplete at 60937.84ms, delta: 9.61ms
           total frame time: 49.91ms, result = k_EStreamFrameResultDisplayed

From this we can see exactly what's happening for individual frames.
Delta is math slang for change in value, so we can see that there's a 20.17ms gap between start of the frame and the start of encoding (where I guess the game is rendering the frame before it can be captured).

The StreamAudioTrace.txt has similar details for the sound data.

Some games, in this case Dark Souls (which uses Direct3D 9 and performs poorly for me over streaming), have an additional chunk between frames.

           total frame time: 31.13ms, result = k_EStreamFrameResultDisplayed, latency = 88.71ms (I0.4/G57.2/D31.1)
---------> k_EStreamInputEventStart at 149000.78ms, delta: 0.00ms
           k_EStreamInputEventSend at 149000.78ms, delta: 0.00ms
           k_EStreamInputEventRecv at 149001.05ms, delta: 0.27ms
           k_EStreamInputEventHandled at 149006.61ms, delta: 5.55ms

I think this is covering an additional step required for frame capture under Direct3D 9 (if anyone comments, I'll add the details in here). It also shows the Input (I), Game (G) and Display (D) latency. Given the frame rate I was initially getting in Dark Souls I'd believe that the game sometimes took 57ms to render.

Some Troubleshooting pointers

Host performance
SlowGamePercent, SlowEncodePercent, CaptureMS, EncodeMS : These generally means your host CPU is struggling (or, for SlowGame, the game is just be a badly written, or use a display method Steam can't stream efficiently). I know you may hate the idea, but dropping back to 720p (or even 480p) inside the game is probably the easiest way to improve performance. Reducing resolution decreases what the machine has to render and reduces the data to capture and encode.
Hopefully hardware encoding will be supported soon (although hardware encode is reportedly not as flexible as software, so we'll have to see) and if that works out hopefully Slow Encode will become a thing of the past (on supported GPUs).

Network performance
SlowNetworkPercent, NetworkMS, PingMS: If these are high it's indicative of a poor network connection. This could be a a lot of competing traffic (data or, on wi-fi, interference) or a bad piece of network equipment (including flakey ethernet cables). If using wi-fi try moving closer to the wi-fi router and see if it helps. If on ethernet, try swapping cables/switch if you can (and if in a complex setup plug them into the same switch for a test).
Also check what the ServerBitrate is compared to LinkBandwidth. It may be that the bitrate in the Remote Play settings needs to be manually set to a lower value.

Client performance
You're probably hard pressed to see problems at the client end (unless you're experimenting to see what the bare minimum specs for Streaming are), so unless something's gone seriously awry you probably don't need to worry about the client too much.
DecoderName: If this isn't some sort of hardware decoder your client is using CPU decoding (which isn't bad, but would restrict you to lower resolutions with a slow CPU. If your GPU/CPU has a hardware h264 decoder it may just be that it's not yet supported by the beta.
SlowDecodePercent, DecodeMS: This could mean a CPU bottleneck (if software decoding). In this case, it may be worthwhile experimenting with a lower bitrate (pushing more compression back to the host, and degrading video quality), reducing host resolution, or decreasing framerate. All of these should reduce the data being decoded. Note that decreasing the framerate if you've nailed the bitrate to a set value may actually increase latency (bigger individual frames) so experiment and see what helps.
DisplayMS: Bad video bandwidth/drivers (Any suggestions??)

[Offending...]

Is there a reason that Steam would not generate the log files?

As per this post, I should find a "streaming_log.txt" under ~/.local/share/Steam/logs

There are no streaming log files in this folder, let alone anywhere else on my computer.

I am using a Gigabyte Brix (AMD A8-5545m) as a streaming client. It runs Linux mint 17.2 (ubuntu 14.04 base), with latest proprietary AMD Crimson driver, and I can't figure out why it won't use hardware decoding. The streaming performance is rather poor as the CPU in this computer is not that fast, but the GPU should be fully capable of hardware decoding.

The server end runs both Linux and Windows, and also uses AMD graphics (280X) and hardware encoding is not an issue, performance is the same if I stream from Linux or Windows.

I want to see the logs...but they don't exist. I am on Steam beta program.

[GeeEl]

Are you looking on the host or the client? Some information from the client goes into the host logs, but I don't think logs turn up on the client.
EDIT: Didn't find anything likely on my steamos (debian based) machine. I think the host log is it.

[Offending...]

I am looking on the client. It didn't occur to me to check the host, since I am looking for client (decoder) information. I'll check the host when I'm back at home. Thanks.

[Offending...]

Ok, found the logs on the server computer. I believe this bit is in reference to my inability to run hardware decoding:

[2015-12-09 16:11:07] CLIENT: Video size: 1920x1080, output size: 1920x1080
[2015-12-09 16:11:07] CLIENT: CVAAPIAccel: vaInitialize() failed: unknown libva error
[2015-12-09 16:11:07] CLIENT: VDPAU init failed: GL_NV_vdpau_interop not available on current context
[2015-12-09 16:11:07] >>> Client video decoder set to libavcodec software decoding with 4 threads
[2015-12-09 16:11:07] CLIENT: libavcodec software decoding with 4 threads

Further down is the session stats:

{
"GameNameID" "BioShock Infinite"
"TimeSubmitted" "1449699087"
"ResolutionX" "1920"
"ResolutionY" "1080"
"CaptureDescriptionID" "Game Delayed OpenGL NV12 + libx264 main (4 threads)"
"DecoderDescriptionID" "libavcodec software decoding with 4 threads"
"BandwidthLimit" "15000"
"FramerateLimit" "0"
"SlowGamePercent" "0"
"SlowCapturePercent" "0"
"SlowConvertPercent" "0"
"SlowEncodePercent" "0"
"SlowNetworkPercent" "0"
"SlowDecodePercent" "0"
"SlowDisplayPercent" "0"
"AvgClientBitrate" "5.95400047302246094"
"StdDevClientBitrate" "5.57687187194824219"
"AvgServerBitrate" "8260.0263671875"
"StdDevServerBitrate" "0"
"AvgLinkBandwidth" "75000"
"AvgPingMS" "0.4825592041015625"
"StdDevPingMS" "0.037737872451543808"
"AvgCaptureMS" "1.07294070720672607"
"StdDevCaptureMS" "0.414855241775512695"
"AvgConvertMS" "0.0203776545822620392"
"StdDevConvertMS" "0.314402580261230469"
"AvgEncodeMS" "23.4428138732910156"
"StdDevEncodeMS" "5.9516143798828125"
"AvgNetworkMS" "5.91558456420898438"
"StdDevNetworkMS" "3.23080778121948242"
"AvgDecodeMS" "11.6414451599121094"
"StdDevDecodeMS" "2.84054684638977051"
"AvgDisplayMS" "2.26332187652587891"
"StdDevDisplayMS" "1.2771599292755127"
"AvgFrameMS" "40.2400321960449219"
"StdDevFrameMS" "8.40722942352294922"
"AvgFPS" "32.6540756225585938"
"StdDevFPS" "10.7771787643432617"
"BigPicture" "0"
"KeyboardMouseInput" "0"
"GameControllerInput" "0"
"SteamControllerInput" "0"
}

[Iceweazel]

Yeah, this is a pretty standard issue. Search the "unknown libva error" line and you'll see people in this and many other threads offer solutions based on your linux distro. Seems Steam ships the linux client with strange version of libva. soft links and installs I see all over boards seem to fix this.

dcibel eredeti hozzászólása:

Ok, found the logs on the server computer. I believe this bit is in reference to my inability to run hardware decoding:

[2015-12-09 16:11:07] CLIENT: Video size: 1920x1080, output size: 1920x1080
[2015-12-09 16:11:07] CLIENT: CVAAPIAccel: vaInitialize() failed: unknown libva error
[2015-12-09 16:11:07] CLIENT: VDPAU init failed: GL_NV_vdpau_interop not available on current context]

[thowthoww]

Hello,
I have been wondering if my Windows Steam client is really using the best decoder available.
I am using the latest 15.30 Crimson drivers.

I have a AMD 7850k with no extra GPU, which means it should use UVD 4 but the logs always report the standard "DXVA: H.264 variable-length decoder, no film grain technology".
This obviously is not software encoding but is it UVD ? I mean I hope not because my average time for decoding is around 9ms at 1080p with automatic bandwith on Rocket League. Yet it's slightly faster (~8ms) without hardware encoding, but my CPU is not so fast, I even underclocked it.

Looking at the best results, I really hope I can get this number down because my streaming experience is really not great so far.
I am seriously considering buying a Nvidia GT 720 focused solely on the decoding.

[Wesker]

Nice

[[k-mart] guythnick]

I have an issue where streaming has not been working. It is the error where the client only shows 'streaming client has quit unexpectedly (2)'. Unfortunately there are no streaming logs to be found. I was on the beta, and also opted out to the stable steam client. Neither are showing logs for streaming. Below are the only log files generated.

http://i.imgur.com/mJbrO70.png

[Private/Static/Void]

Can anyone look at these stats and tell me where the bottleneck is , please ?

{
"GameNameID" "Tom Clancy's Splinter Cell Blacklist"
"TimeSubmitted" "1454247342"
"ResolutionX" "1920"
"ResolutionY" "1080"
"CaptureDescriptionID" "Game polled D3D11 NV12 + libx264 main (4 threads)"
"DecoderDescriptionID" "Marvell hardware decoding"
"BandwidthLimit" "30000"
"FramerateLimit" "0"
"SlowGamePercent" "0"
"SlowCapturePercent" "0"
"SlowConvertPercent" "0"
"SlowEncodePercent" "1.4137680530548096"
"SlowNetworkPercent" "0"
"SlowDecodePercent" "0"
"SlowDisplayPercent" "0"
"AvgClientBitrate" "17.000064849853516"
"StdDevClientBitrate" "16.601770401000977"
"AvgServerBitrate" "25366.1171875"
"StdDevServerBitrate" "0"
"AvgLinkBandwidth" "100000.0078125"
"AvgPingMS" "0.1310010552406311"
"StdDevPingMS" "0.17119871079921722"
"AvgCaptureMS" "1.3358078002929687"
"StdDevCaptureMS" "2.0422823429107666"
"AvgConvertMS" "0.011791355907917023"
"StdDevConvertMS" "0.3310931921005249"
"AvgEncodeMS" "25.64385986328125"
"StdDevEncodeMS" "6.7429022789001465"
"AvgNetworkMS" "15.442395210266113"
"StdDevNetworkMS" "5.7079968452453613"
"AvgDecodeMS" "2.1332027912139893"
"StdDevDecodeMS" "0.66553890705108643"
"AvgDisplayMS" "0.016240939497947693"
"StdDevDisplayMS" "0.065722011029720306"
"AvgFrameMS" "64.886558532714844"
"StdDevFrameMS" "19.524898529052734"
"AvgFPS" "33.965591430664062"
"StdDevFPS" "16.278661727905273"
"BigPicture" "1"
"KeyboardMouseInput" "1"
"GameControllerInput" "1"
"SteamControllerInput" "0"
}

[✪ Cyprusgirl]

:)

[K0wYcS]

asd

[LXST CXNTURY]

:)

['RBC]

lool

[76561198197121083]

how to veryfy dota 2 acount

[Bizcochito]

lol