1.1 --- /dev/null	Thu Jan 01 00:00:00 1970 +0000
     1.2 +++ b/LibOVR/Src/CAPI/CAPI_LatencyStatistics.cpp	Wed Jan 14 06:51:16 2015 +0200
     1.3 @@ -0,0 +1,316 @@
     1.4 +/************************************************************************************
     1.5 +
     1.6 +Filename    :   CAPI_LatencyStatistics.cpp
     1.7 +Content     :   Record latency statistics during rendering
     1.8 +Created     :   Sept 23, 2014
     1.9 +Authors     :   Chris Taylor, Kevin Jenkins
    1.10 +
    1.11 +Copyright   :   Copyright 2014 Oculus VR, LLC All Rights reserved.
    1.12 +
    1.13 +Licensed under the Oculus VR Rift SDK License Version 3.2 (the "License"); 
    1.14 +you may not use the Oculus VR Rift SDK except in compliance with the License, 
    1.15 +which is provided at the time of installation or download, or which 
    1.16 +otherwise accompanies this software in either electronic or hard copy form.
    1.17 +
    1.18 +You may obtain a copy of the License at
    1.19 +
    1.20 +http://www.oculusvr.com/licenses/LICENSE-3.2 
    1.21 +
    1.22 +Unless required by applicable law or agreed to in writing, the Oculus VR SDK 
    1.23 +distributed under the License is distributed on an "AS IS" BASIS,
    1.24 +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    1.25 +See the License for the specific language governing permissions and
    1.26 +limitations under the License.
    1.27 +
    1.28 +************************************************************************************/
    1.29 +
    1.30 +#include "CAPI_LatencyStatistics.h"
    1.31 +
    1.32 +#include "../Kernel/OVR_Log.h"
    1.33 +#include "../Kernel/OVR_Threads.h"
    1.34 +#include "../Util/Util_SystemInfo.h"
    1.35 +
    1.36 +namespace OVR { namespace CAPI {
    1.37 +
    1.38 +//-----------------------------------------------------------------------------
    1.39 +// ***** LatencyStatisticsObserver
    1.40 +
    1.41 +LatencyStatisticsCSV::LatencyStatisticsCSV()
    1.42 +{
    1.43 +}
    1.44 +
    1.45 +LatencyStatisticsCSV::~LatencyStatisticsCSV()
    1.46 +{
    1.47 +    Stop();
    1.48 +}
    1.49 +
    1.50 +bool LatencyStatisticsCSV::Start(String fileName, String userData1)
    1.51 +{
    1.52 +    if (_File.IsValid())
    1.53 +    {
    1.54 +        if (fileName == FileName)
    1.55 +        {
    1.56 +            UserData1 = userData1;
    1.57 +            return true;
    1.58 +        }
    1.59 +        else
    1.60 +        {
    1.61 +            Stop();
    1.62 +        }
    1.63 +    }
    1.64 +
    1.65 +    OVR::String basePath = OVR::GetBaseOVRPath(true);
    1.66 +    OVR::String path = basePath;
    1.67 +    path.AppendString("\\");
    1.68 +    path.AppendString(fileName);
    1.69 +    OS = OVR::Util::OSAsString();
    1.70 +    OSVersion = OVR::Util::OSVersionAsString();
    1.71 +#if defined (OVR_OS_WIN64) || defined (OVR_OS_WIN32)
    1.72 +    ProcessInfo = OVR::Util::GetProcessInfo();
    1.73 +    DisplayDriverVersion = OVR::Util::GetDisplayDriverVersion();
    1.74 +    CameraDriverVersion = OVR::Util::GetCameraDriverVersion();
    1.75 +    OVR::Array< OVR::String > gpus;
    1.76 +    OVR::Util::GetGraphicsCardList(gpus);
    1.77 +    StringBuffer sb;
    1.78 +    size_t gpuIdx;
    1.79 +    for (gpuIdx = 0; gpuIdx < gpus.GetSize(); gpuIdx++)
    1.80 +    {
    1.81 +        sb.AppendString(gpus[gpuIdx]);
    1.82 +        if (gpuIdx + 1 < gpus.GetSize())
    1.83 +            sb.AppendString("; ");
    1.84 +    }
    1.85 +    GPUVersion = sb;
    1.86 +#endif
    1.87 +    Guid = OVR::Util::GetGuidString();
    1.88 +
    1.89 +    if (!_File.Open(path, OVR::File::Open_Write, OVR::File::Mode_Write))
    1.90 +    {
    1.91 +        _File.Create(path, OVR::File::Mode_Write);
    1.92 +        WriteHeaderV1();
    1.93 +    }
    1.94 +    else
    1.95 +    {
    1.96 +        _File.Seek(0, FileConstants::Seek_End);
    1.97 +    }
    1.98 +
    1.99 +    if (_File.IsValid())
   1.100 +    {
   1.101 +        UserData1 = userData1;
   1.102 +        FileName = fileName;
   1.103 +        _Observer.SetHandler(LatencyStatisticsSlot::FromMember<LatencyStatisticsCSV, &LatencyStatisticsCSV::OnResults>(this));
   1.104 +
   1.105 +        return true;
   1.106 +    }
   1.107 +
   1.108 +    return false;
   1.109 +}
   1.110 +bool LatencyStatisticsCSV::Stop()
   1.111 +{
   1.112 +    if (_File.IsValid())
   1.113 +    {
   1.114 +        _File.Flush();
   1.115 +        _File.Close();
   1.116 +        _Observer.ReleaseAll();
   1.117 +
   1.118 +        Guid.Clear();
   1.119 +        FileName.Clear();
   1.120 +        return true;
   1.121 +    }
   1.122 +    return false;
   1.123 +}
   1.124 +void LatencyStatisticsCSV::WriteHeaderV1()
   1.125 +{
   1.126 +    if (_File.IsValid())
   1.127 +    {
   1.128 +        // Write header if creating the file
   1.129 +        const char *str = "GUID,OS,OSVersion,Process,DisplayDriver,CameraDriver,GPU,Time,Interval,FPS,EndFrameExecutionTime,LatencyRender,LatencyTimewarp,LatencyPostPresent,LatencyVisionProc,LatencyVisionFrame,UserData1\n";
   1.130 +        _File.Write((const uint8_t *) str, (int)OVR_strlen(str));
   1.131 +    }
   1.132 +}
   1.133 +
   1.134 +void LatencyStatisticsCSV::WriteResultsV1(LatencyStatisticsResults *results)
   1.135 +{
   1.136 +    if (_File.IsValid())
   1.137 +    {
   1.138 +        char str[512];
   1.139 +        OVR_sprintf(str, sizeof(str),
   1.140 +            "%s,%s,%s,%s,%s,%s,%s,%f,%f,%f,%f,%f,%f,%f,%f,%f,%s\n",
   1.141 +            Guid.ToCStr(),
   1.142 +            OS.ToCStr(),
   1.143 +            OSVersion.ToCStr(),
   1.144 +            ProcessInfo.ToCStr(),
   1.145 +            DisplayDriverVersion.ToCStr(),
   1.146 +            CameraDriverVersion.ToCStr(),
   1.147 +            GPUVersion.ToCStr(),
   1.148 +            ovr_GetTimeInSeconds(),
   1.149 +            results->IntervalSeconds,
   1.150 +            results->FPS,
   1.151 +            results->EndFrameExecutionTime,
   1.152 +            results->LatencyRender,
   1.153 +            results->LatencyTimewarp,
   1.154 +            results->LatencyPostPresent,
   1.155 +            results->LatencyVisionProc,
   1.156 +            results->LatencyVisionFrame,
   1.157 +            UserData1.ToCStr());
   1.158 +        str[sizeof(str)-1] = 0;
   1.159 +        _File.Write((const uint8_t *)str, (int)OVR_strlen(str));
   1.160 +    }
   1.161 +}
   1.162 +void LatencyStatisticsCSV::OnResults(LatencyStatisticsResults *results)
   1.163 +{
   1.164 +    WriteResultsV1(results);
   1.165 +}
   1.166 +//-------------------------------------------------------------------------------------
   1.167 +// ***** LatencyStatisticsCalculator
   1.168 +    
   1.169 +LagStatsCalculator::LagStatsCalculator()
   1.170 +{
   1.171 +    resetPerfStats();
   1.172 +}
   1.173 +
   1.174 +void LagStatsCalculator::resetPerfStats(double resetTime)
   1.175 +{
   1.176 +    EndFrameStartTime = 0.;
   1.177 +    EndFrameEndTime = 0.;
   1.178 +
   1.179 +    LastCameraFrameCounter = ~(uint32_t)0;
   1.180 +
   1.181 +    EpochBegin = resetTime; // Set epoch start to now
   1.182 +
   1.183 +    FrameCount = 0;
   1.184 +    //EndFrameSum = 0.;
   1.185 +
   1.186 +    //VisionProcSum = 0.;
   1.187 +    //VisionLagSum = 0.;
   1.188 +    VisionFrames = 0;
   1.189 +
   1.190 +    //for (int i = 0; i < 3; ++i)
   1.191 +    //{
   1.192 +    //    LatencyData[i] = 0.f;
   1.193 +    //    LatencySum[i] = 0.;
   1.194 +    //}
   1.195 +
   1.196 +    latencyStatisticsData.EndFrameExecutionTime = 0;
   1.197 +    latencyStatisticsData.LatencyRender = 0;
   1.198 +    latencyStatisticsData.LatencyTimewarp = 0;
   1.199 +    latencyStatisticsData.LatencyPostPresent = 0;
   1.200 +    latencyStatisticsData.LatencyVisionProc = 0;
   1.201 +    latencyStatisticsData.LatencyVisionFrame = 0;
   1.202 +}
   1.203 +
   1.204 +void LagStatsCalculator::GetLatestResults(LatencyStatisticsResults* results)
   1.205 +{
   1.206 +    *results = Results.GetState();
   1.207 +}
   1.208 +void LagStatsCalculator::AddResultsObserver(ObserverScope<LatencyStatisticsSlot> *calculateResultsObserver)
   1.209 +{
   1.210 +    Lock::Locker locker(&calculateResultsLock);
   1.211 +    calculateResultsObserver->GetPtr()->Observe(calculateResultsSubject);
   1.212 +}
   1.213 +void LagStatsCalculator::InstrumentEndFrameStart(double timestamp)
   1.214 +{
   1.215 +    EndFrameStartTime = timestamp;
   1.216 +}
   1.217 +
   1.218 +void LagStatsCalculator::InstrumentLatencyTimings(FrameTimeManager& ftm)
   1.219 +{
   1.220 +    //latencies[0] = (float)RenderLatencySeconds;
   1.221 +    //latencies[1] = (float)TimewarpLatencySeconds;
   1.222 +    //latencies[2] = (float)FrameDeltas.GetMedianTimeDelta();
   1.223 +
   1.224 +    // Note: This assumes that it is called right before InstrumentEndFrameEnd()
   1.225 +	float latencyRender, latencyTimewarp, latencyPostPresent;
   1.226 +    ftm.GetLatencyTimings(latencyRender, latencyTimewarp, latencyPostPresent);
   1.227 +	latencyStatisticsData.LatencyRender += latencyRender;
   1.228 +	latencyStatisticsData.LatencyTimewarp += latencyTimewarp;
   1.229 +	latencyStatisticsData.LatencyPostPresent += latencyPostPresent;
   1.230 +}
   1.231 +
   1.232 +void LagStatsCalculator::InstrumentEndFrameEnd(double timestamp)
   1.233 +{
   1.234 +    EndFrameEndTime = timestamp;
   1.235 +
   1.236 +    calculateResults();
   1.237 +}
   1.238 +
   1.239 +void LagStatsCalculator::InstrumentEyePose(const ovrTrackingState& state)
   1.240 +{
   1.241 +    // If the camera frame counter has rolled,
   1.242 +    if (LastCameraFrameCounter != state.LastCameraFrameCounter)
   1.243 +    {
   1.244 +        // Accumulate eye pose data
   1.245 +        if (state.StatusFlags != 0)
   1.246 +        {
   1.247 +            latencyStatisticsData.LatencyVisionProc += state.LastVisionProcessingTime;
   1.248 +            latencyStatisticsData.LatencyVisionFrame += state.LastVisionFrameLatency;
   1.249 +        }
   1.250 +        ++VisionFrames;
   1.251 +
   1.252 +        LastCameraFrameCounter = state.LastCameraFrameCounter;
   1.253 +    }
   1.254 +}
   1.255 +
   1.256 +// Note: Currently assumes this is being called from OnEndFrameEnd() above.
   1.257 +void LagStatsCalculator::calculateResults()
   1.258 +{
   1.259 +    // Calculate time in the current epoch so far
   1.260 +    double intervalDuration = EndFrameEndTime - EpochBegin;
   1.261 +
   1.262 +    // If stats should be reset due to inactivity,
   1.263 +    if (intervalDuration >= OVR_LAG_STATS_RESET_LIMIT)
   1.264 +    {
   1.265 +        resetPerfStats(EndFrameEndTime);
   1.266 +        return;
   1.267 +    }
   1.268 +
   1.269 +    // Calculate EndFrame() duration
   1.270 +    double endFrameDuration = EndFrameEndTime - EndFrameStartTime;
   1.271 +
   1.272 +    // Incorporate EndFrame() duration into the running sum
   1.273 +    latencyStatisticsData.EndFrameExecutionTime += endFrameDuration;
   1.274 +
   1.275 +    //for (int i = 0; i < 3; ++i)
   1.276 +    //{
   1.277 +    //    LatencySum[i] += LatencyData[i];
   1.278 +    //}
   1.279 +
   1.280 +    // Increment frame counter
   1.281 +    ++FrameCount;
   1.282 +
   1.283 +    // If enough time has passed,
   1.284 +    if (intervalDuration >= OVR_LAG_STATS_EPOCH)
   1.285 +    {
   1.286 +        LatencyStatisticsResults results;
   1.287 +
   1.288 +        float invFrameCount = 1.0f / (float) FrameCount;
   1.289 +
   1.290 +        // EndFrame() instrumentation
   1.291 +        results.IntervalSeconds = intervalDuration;
   1.292 +        results.FPS = FrameCount / intervalDuration;
   1.293 +        results.EndFrameExecutionTime = latencyStatisticsData.EndFrameExecutionTime * invFrameCount;
   1.294 +
   1.295 +        // Latency data
   1.296 +        results.LatencyRender = latencyStatisticsData.LatencyRender * invFrameCount;
   1.297 +        results.LatencyTimewarp = latencyStatisticsData.LatencyTimewarp * invFrameCount;
   1.298 +        results.LatencyPostPresent = latencyStatisticsData.LatencyPostPresent * invFrameCount;
   1.299 +
   1.300 +        double invVisionFrameCount = 1. / VisionFrames;
   1.301 +
   1.302 +        // Eye pose instrumentation
   1.303 +        results.LatencyVisionProc = latencyStatisticsData.LatencyVisionProc * invVisionFrameCount;
   1.304 +        results.LatencyVisionFrame = latencyStatisticsData.LatencyVisionFrame * invVisionFrameCount;
   1.305 +
   1.306 +        Results.SetState(results);
   1.307 +
   1.308 +        {
   1.309 +            Lock::Locker locker(&calculateResultsLock);
   1.310 +            calculateResultsSubject.GetPtr()->Call(&results);
   1.311 +        }
   1.312 +
   1.313 +        // Reset for next frame
   1.314 +        resetPerfStats();
   1.315 +    }
   1.316 +}
   1.317 +
   1.318 +
   1.319 +}} // namespace OVR::CAPI