Util_LatencyTest.cpp
Go to the documentation of this file.
00001 /************************************************************************************
00002 
00003 Filename    :   Util_LatencyTest.cpp
00004 Content     :   Wraps the lower level LatencyTester interface and adds functionality.
00005 Created     :   February 14, 2013
00006 Authors     :   Lee Cooper
00007 
00008 Copyright   :   Copyright 2013 Oculus VR, Inc. All Rights reserved.
00009 
00010 Use of this software is subject to the terms of the Oculus license
00011 agreement provided at the time of installation or download, or which
00012 otherwise accompanies this software in either electronic or hard copy form.
00013 
00014 *************************************************************************************/
00015 
00016 #include "Util_LatencyTest.h"
00017 
00018 #include "../Kernel/OVR_Log.h"
00019 #include "../Kernel/OVR_Timer.h"
00020 
00021 namespace OVR { namespace Util {
00022 
00023 static const UInt32     TIME_TO_WAIT_FOR_SETTLE_PRE_CALIBRATION = 16*10;
00024 static const UInt32     TIME_TO_WAIT_FOR_SETTLE_POST_CALIBRATION = 16*10;
00025 static const UInt32     TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT = 16*5;
00026 static const UInt32     TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT_RANDOMNESS = 16*5;
00027 static const UInt32     DEFAULT_NUMBER_OF_SAMPLES = 10;                 // For both color 1->2 and color 2->1 transitions.
00028 static const UInt32     INITIAL_SAMPLES_TO_IGNORE = 4;
00029 static const UInt32     TIMEOUT_WAITING_FOR_TEST_STARTED = 1000;
00030 static const UInt32     TIMEOUT_WAITING_FOR_COLOR_DETECTED = 4000;
00031 static const Color      CALIBRATE_BLACK(0, 0, 0);
00032 static const Color      CALIBRATE_WHITE(255, 255, 255);
00033 static const Color      COLOR1(0, 0, 0);
00034 static const Color      COLOR2(255, 255, 255);
00035 static const Color      SENSOR_DETECT_THRESHOLD(128, 255, 255);
00036 static const float      BIG_FLOAT = 1000000.0f;
00037 static const float      SMALL_FLOAT = -1000000.0f;
00038 
00039 //-------------------------------------------------------------------------------------
00040 // ***** LatencyTest
00041 
00042 LatencyTest::LatencyTest(LatencyTestDevice* device)
00043  :  Handler(getThis())
00044 {
00045     if (device != NULL)
00046     {
00047         SetDevice(device);
00048     }
00049 
00050     reset();
00051 
00052     srand(Timer::GetTicksMs());
00053 }
00054 
00055 LatencyTest::~LatencyTest()
00056 {
00057      clearMeasurementResults();
00058 }
00059 
00060 bool LatencyTest::SetDevice(LatencyTestDevice* device)
00061 {
00062 
00063     if (device != Device)
00064     {
00065         if (device != NULL)
00066         {
00067             if (device->GetMessageHandler() != NULL)
00068             {
00069                 OVR_DEBUG_LOG(
00070                     ("LatencyTest::AttachToDevice failed - device %p already has handler", device));
00071                 return false;
00072             }
00073         }
00074 
00075         if (Device != NULL)
00076         {
00077             Device->SetMessageHandler(0);
00078         }
00079         Device = device;
00080 
00081         if (Device != NULL)
00082         {
00083             Device->SetMessageHandler(&Handler);
00084 
00085             // Set trigger threshold.
00086             LatencyTestConfiguration configuration(SENSOR_DETECT_THRESHOLD, false);     // No samples streaming.
00087             Device->SetConfiguration(configuration, true);
00088 
00089             // Set display to intial (3 dashes).
00090             LatencyTestDisplay ltd(2, 0x40400040);
00091             Device->SetDisplay(ltd);
00092         }
00093     }
00094 
00095     return true;
00096 }
00097 
00098 UInt32 LatencyTest::getRandomComponent(UInt32 range)
00099 {
00100     UInt32 val = rand() % range;
00101     return val;
00102 }
00103 
00104 void LatencyTest::BeginTest()
00105 {
00106      if (State == State_WaitingForButton)
00107     {
00108         // Set color to black and wait a while.
00109         RenderColor = CALIBRATE_BLACK;
00110 
00111         State = State_WaitingForSettlePreCalibrationColorBlack;
00112         OVR_DEBUG_LOG(("State_WaitingForButton -> State_WaitingForSettlePreCalibrationColorBlack."));
00113 
00114         setTimer(TIME_TO_WAIT_FOR_SETTLE_PRE_CALIBRATION);
00115     }
00116 }
00117 
00118 void LatencyTest::handleMessage(const Message& msg, LatencyTestMessageType latencyTestMessage)
00119 {
00120     // For debugging.
00121 /*  if (msg.Type == Message_LatencyTestSamples)
00122     {
00123         MessageLatencyTestSamples* pSamples = (MessageLatencyTestSamples*) &msg;
00124 
00125         if (pSamples->Samples.GetSize() > 0)
00126         {
00127             // Just show the first one for now.
00128             Color c = pSamples->Samples[0];
00129             OVR_DEBUG_LOG(("%d %d %d", c.R, c.G, c.B));
00130         }
00131         return;
00132     }
00133 */
00134 
00135     if (latencyTestMessage == LatencyTest_Timer)
00136     {
00137         if (!Device)
00138         {
00139             reset();
00140             return;
00141         }
00142         
00143         if (State == State_WaitingForSettlePreCalibrationColorBlack)
00144         {
00145             // Send calibrate message to device and wait a while.
00146             Device->SetCalibrate(CALIBRATE_BLACK);
00147 
00148             State = State_WaitingForSettlePostCalibrationColorBlack;
00149             OVR_DEBUG_LOG(("State_WaitingForSettlePreCalibrationColorBlack -> State_WaitingForSettlePostCalibrationColorBlack."));
00150 
00151             setTimer(TIME_TO_WAIT_FOR_SETTLE_POST_CALIBRATION);
00152         }
00153         else if (State == State_WaitingForSettlePostCalibrationColorBlack)
00154         {
00155             // Change color to white and wait a while.
00156             RenderColor = CALIBRATE_WHITE;
00157 
00158             State = State_WaitingForSettlePreCalibrationColorWhite;
00159             OVR_DEBUG_LOG(("State_WaitingForSettlePostCalibrationColorBlack -> State_WaitingForSettlePreCalibrationColorWhite."));
00160 
00161             setTimer(TIME_TO_WAIT_FOR_SETTLE_PRE_CALIBRATION);
00162         }
00163         else if (State == State_WaitingForSettlePreCalibrationColorWhite)
00164         {
00165             // Send calibrate message to device and wait a while.
00166             Device->SetCalibrate(CALIBRATE_WHITE);
00167 
00168             State = State_WaitingForSettlePostCalibrationColorWhite;
00169             OVR_DEBUG_LOG(("State_WaitingForSettlePreCalibrationColorWhite -> State_WaitingForSettlePostCalibrationColorWhite."));
00170 
00171             setTimer(TIME_TO_WAIT_FOR_SETTLE_POST_CALIBRATION);
00172         }
00173         else if (State == State_WaitingForSettlePostCalibrationColorWhite)
00174         {
00175             // Calibration is done. Switch to color 1 and wait for it to settle.
00176             RenderColor = COLOR1;
00177 
00178             State = State_WaitingForSettlePostMeasurement;
00179             OVR_DEBUG_LOG(("State_WaitingForSettlePostCalibrationColorWhite -> State_WaitingForSettlePostMeasurement."));
00180 
00181             UInt32 waitTime = TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT + getRandomComponent(TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT_RANDOMNESS);
00182             setTimer(waitTime);
00183         }
00184         else if (State == State_WaitingForSettlePostMeasurement)
00185         {
00186             // Prepare for next measurement.
00187 
00188             // Create a new result object.
00189             MeasurementResult* pResult = new MeasurementResult();
00190             Results.PushBack(pResult);
00191 
00192             State = State_WaitingToTakeMeasurement;
00193             OVR_DEBUG_LOG(("State_WaitingForSettlePostMeasurement -> State_WaitingToTakeMeasurement."));
00194         }
00195         else if (State == State_WaitingForTestStarted)
00196         {
00197             // We timed out waiting for 'TestStarted'. Abandon this measurement and setup for the next.
00198             getActiveResult()->TimedOutWaitingForTestStarted = true;
00199 
00200             State = State_WaitingForSettlePostMeasurement;
00201             OVR_DEBUG_LOG(("** Timed out waiting for 'TestStarted'."));
00202             OVR_DEBUG_LOG(("State_WaitingForTestStarted -> State_WaitingForSettlePostMeasurement."));
00203 
00204             UInt32 waitTime = TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT + getRandomComponent(TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT_RANDOMNESS);
00205             setTimer(waitTime);
00206         }
00207         else if (State == State_WaitingForColorDetected)
00208         {
00209             // We timed out waiting for 'ColorDetected'. Abandon this measurement and setup for the next.
00210             getActiveResult()->TimedOutWaitingForColorDetected = true;
00211 
00212             State = State_WaitingForSettlePostMeasurement;
00213             OVR_DEBUG_LOG(("** Timed out waiting for 'ColorDetected'."));
00214             OVR_DEBUG_LOG(("State_WaitingForColorDetected -> State_WaitingForSettlePostMeasurement."));
00215 
00216             UInt32 waitTime = TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT + getRandomComponent(TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT_RANDOMNESS);
00217             setTimer(waitTime);
00218         }
00219     }
00220     else if (latencyTestMessage == LatencyTest_ProcessInputs)
00221     {
00222         if (State == State_WaitingToTakeMeasurement)
00223         {
00224             if (!Device)
00225             {
00226                 reset();
00227                 return;
00228             }
00229             
00230             // Send 'StartTest' feature report with opposite target color.
00231             if (RenderColor == COLOR1)
00232             {
00233                 RenderColor = COLOR2;
00234             }
00235             else
00236             {
00237                 RenderColor = COLOR1;
00238             }
00239 
00240             getActiveResult()->TargetColor = RenderColor;
00241             
00242             // Record time so we can determine usb roundtrip time.
00243             getActiveResult()->StartTestTicksMicroS = Timer::GetTicks();
00244 
00245             Device->SetStartTest(RenderColor);
00246 
00247             State = State_WaitingForTestStarted;
00248             OVR_DEBUG_LOG(("State_WaitingToTakeMeasurement -> State_WaitingForTestStarted."));
00249 
00250             setTimer(TIMEOUT_WAITING_FOR_TEST_STARTED);
00251 
00252             LatencyTestDisplay ltd(2, 0x40090040);
00253             Device->SetDisplay(ltd);
00254         }
00255     }
00256     else if (msg.Type == Message_LatencyTestButton)
00257     {
00258         BeginTest();
00259     }
00260     else if (msg.Type == Message_LatencyTestStarted)
00261     {
00262         if (State == State_WaitingForTestStarted)
00263         {
00264             clearTimer();
00265 
00266             // Record time so we can determine usb roundtrip time.
00267             getActiveResult()->TestStartedTicksMicroS = Timer::GetTicks();
00268             
00269             State = State_WaitingForColorDetected;
00270             OVR_DEBUG_LOG(("State_WaitingForTestStarted -> State_WaitingForColorDetected."));
00271 
00272             setTimer(TIMEOUT_WAITING_FOR_COLOR_DETECTED);
00273         }
00274     }
00275     else if (msg.Type == Message_LatencyTestColorDetected)
00276     {
00277         if (State == State_WaitingForColorDetected)
00278         {
00279             // Record time to detect color.
00280             MessageLatencyTestColorDetected* pDetected = (MessageLatencyTestColorDetected*) &msg;
00281             UInt16 elapsedTime = pDetected->Elapsed;
00282             OVR_DEBUG_LOG(("Time to 'ColorDetected' = %d", elapsedTime));
00283             
00284             getActiveResult()->DeviceMeasuredElapsedMilliS = elapsedTime;
00285 
00286             if (areResultsComplete())
00287             {
00288                 // We're done.
00289                 processResults();
00290                 reset();
00291             }
00292             else
00293             {
00294                 // Run another measurement.
00295                 State = State_WaitingForSettlePostMeasurement;
00296                 OVR_DEBUG_LOG(("State_WaitingForColorDetected -> State_WaitingForSettlePostMeasurement."));
00297 
00298                 UInt32 waitTime = TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT + getRandomComponent(TIME_TO_WAIT_FOR_SETTLE_POST_MEASUREMENT_RANDOMNESS);
00299                 setTimer(waitTime);
00300 
00301                 LatencyTestDisplay ltd(2, 0x40400040);
00302                 Device->SetDisplay(ltd);
00303             }
00304         }
00305     }
00306     else if (msg.Type == Message_DeviceRemoved)
00307     {
00308         reset();
00309     }
00310 }
00311 
00312 LatencyTest::MeasurementResult* LatencyTest::getActiveResult()
00313 {
00314     OVR_ASSERT(!Results.IsEmpty());    
00315     return Results.GetLast();
00316 }
00317 
00318 void LatencyTest::setTimer(UInt32 timeMilliS)
00319 {
00320     ActiveTimerMilliS = timeMilliS;
00321 }
00322 
00323 void LatencyTest::clearTimer()
00324 {
00325     ActiveTimerMilliS = 0;
00326 }
00327 
00328 void LatencyTest::reset()
00329 {
00330     clearMeasurementResults();
00331     State = State_WaitingForButton;
00332 
00333     HaveOldTime = false;
00334     ActiveTimerMilliS = 0;
00335 }
00336 
00337 void LatencyTest::clearMeasurementResults()
00338 {
00339     while(!Results.IsEmpty())
00340     {
00341         MeasurementResult* pElem = Results.GetFirst();
00342         pElem->RemoveNode();
00343         delete pElem;
00344     }
00345 }
00346 
00347 LatencyTest::LatencyTestHandler::~LatencyTestHandler()
00348 {
00349     RemoveHandlerFromDevices();
00350 }
00351 
00352 void LatencyTest::LatencyTestHandler::OnMessage(const Message& msg)
00353 {
00354     pLatencyTestUtil->handleMessage(msg);
00355 }
00356 
00357 void LatencyTest::ProcessInputs()
00358 {
00359     updateForTimeouts();
00360     handleMessage(Message(), LatencyTest_ProcessInputs);
00361 }
00362 
00363 bool LatencyTest::DisplayScreenColor(Color& colorToDisplay)
00364 {
00365     updateForTimeouts();
00366 
00367     if (State == State_WaitingForButton)
00368     {
00369         return false;
00370     }
00371 
00372     colorToDisplay = RenderColor;
00373     return true;
00374 }
00375 
00376 const char*     LatencyTest::GetResultsString()
00377 {
00378         if (!ResultsString.IsEmpty() && ReturnedResultString != ResultsString.ToCStr())
00379         {
00380                 ReturnedResultString = ResultsString;
00381                 return ReturnedResultString.ToCStr();
00382         }
00383     
00384         return NULL;
00385 }
00386 
00387 bool LatencyTest::areResultsComplete()
00388 {
00389     UInt32 initialMeasurements = 0;
00390 
00391     UInt32 measurements1to2 = 0;
00392     UInt32 measurements2to1 = 0;
00393 
00394     MeasurementResult* pCurr = Results.GetFirst();
00395     while(true)
00396     {
00397         // Process.
00398         if (!pCurr->TimedOutWaitingForTestStarted &&
00399             !pCurr->TimedOutWaitingForColorDetected)
00400         {
00401             initialMeasurements++;
00402 
00403             if (initialMeasurements > INITIAL_SAMPLES_TO_IGNORE)
00404             {
00405                 if (pCurr->TargetColor == COLOR2)
00406                 {
00407                     measurements1to2++;
00408                 }
00409                 else
00410                 {
00411                     measurements2to1++;
00412                 }
00413             }
00414         }
00415 
00416         if (Results.IsLast(pCurr))
00417         {
00418             break;
00419         }
00420         pCurr = Results.GetNext(pCurr);
00421     }
00422 
00423     if (measurements1to2 >= DEFAULT_NUMBER_OF_SAMPLES &&
00424         measurements2to1 >= DEFAULT_NUMBER_OF_SAMPLES)
00425     {
00426         return true;
00427     }
00428 
00429     return false;
00430 }
00431 
00432 void LatencyTest::processResults()
00433 {
00434 
00435     UInt32 minTime1To2 = UINT_MAX;
00436     UInt32 maxTime1To2 = 0;
00437     float averageTime1To2 = 0.0f;
00438     UInt32 minTime2To1 = UINT_MAX;
00439     UInt32 maxTime2To1 = 0;
00440     float averageTime2To1 = 0.0f;
00441 
00442     float minUSBTripMilliS = BIG_FLOAT;
00443     float maxUSBTripMilliS = SMALL_FLOAT;
00444     float averageUSBTripMilliS = 0.0f;
00445     UInt32 countUSBTripTime = 0;
00446 
00447     UInt32 measurementsCount = 0;
00448     UInt32 measurements1to2 = 0;
00449     UInt32 measurements2to1 = 0;
00450 
00451     MeasurementResult* pCurr = Results.GetFirst();
00452     UInt32 count = 0;
00453     while(true)
00454     {
00455         count++;
00456 
00457         if (!pCurr->TimedOutWaitingForTestStarted &&
00458             !pCurr->TimedOutWaitingForColorDetected)
00459         {
00460             measurementsCount++;
00461 
00462             if (measurementsCount > INITIAL_SAMPLES_TO_IGNORE)
00463             {
00464                 if (pCurr->TargetColor == COLOR2)
00465                 {
00466                     measurements1to2++;
00467 
00468                     if (measurements1to2 <= DEFAULT_NUMBER_OF_SAMPLES)
00469                     {
00470                         UInt32 elapsed = pCurr->DeviceMeasuredElapsedMilliS;
00471 
00472                         minTime1To2 = Alg::Min(elapsed, minTime1To2);
00473                         maxTime1To2 = Alg::Max(elapsed, maxTime1To2);
00474 
00475                         averageTime1To2 += (float) elapsed;
00476                     }
00477                 }
00478                 else
00479                 {
00480                     measurements2to1++;
00481 
00482                     if (measurements2to1 <= DEFAULT_NUMBER_OF_SAMPLES)
00483                     {
00484                         UInt32 elapsed = pCurr->DeviceMeasuredElapsedMilliS;
00485 
00486                         minTime2To1 = Alg::Min(elapsed, minTime2To1);
00487                         maxTime2To1 = Alg::Max(elapsed, maxTime2To1);
00488 
00489                         averageTime2To1 += (float) elapsed;
00490                     }
00491                 }
00492 
00493                 float usbRountripElapsedMilliS = 0.001f * (float) (pCurr->TestStartedTicksMicroS - pCurr->StartTestTicksMicroS);
00494                 minUSBTripMilliS = Alg::Min(usbRountripElapsedMilliS, minUSBTripMilliS);
00495                 maxUSBTripMilliS = Alg::Max(usbRountripElapsedMilliS, maxUSBTripMilliS);
00496                 averageUSBTripMilliS += usbRountripElapsedMilliS;
00497                 countUSBTripTime++;
00498             }
00499         }
00500 
00501         if (measurements1to2 >= DEFAULT_NUMBER_OF_SAMPLES &&
00502             measurements2to1 >= DEFAULT_NUMBER_OF_SAMPLES)
00503         {
00504             break;
00505         }
00506 
00507         if (Results.IsLast(pCurr))
00508         {
00509             break;
00510         }
00511         pCurr = Results.GetNext(pCurr);
00512     }
00513 
00514     averageTime1To2 /= (float) DEFAULT_NUMBER_OF_SAMPLES;      
00515     averageTime2To1 /= (float) DEFAULT_NUMBER_OF_SAMPLES;
00516 
00517     averageUSBTripMilliS /= countUSBTripTime;
00518     
00519     float finalResult = 0.5f * (averageTime1To2 + averageTime2To1);
00520     finalResult += averageUSBTripMilliS;
00521 
00522     ResultsString.Clear();
00523     ResultsString.AppendFormat("RESULT=%.1f (add half Tracker period) [b->w %d|%.1f|%d] [w->b %d|%.1f|%d] [usb rndtrp %.1f|%.1f|%.1f] [cnt %d] [tmouts %d]",  
00524                 finalResult, 
00525                 minTime1To2, averageTime1To2, maxTime1To2, 
00526                 minTime2To1, averageTime2To1, maxTime2To1,
00527                 minUSBTripMilliS, averageUSBTripMilliS, maxUSBTripMilliS,
00528                 DEFAULT_NUMBER_OF_SAMPLES*2, count - measurementsCount);
00529     
00530     // Display result on latency tester display.
00531     LatencyTestDisplay ltd(1, (int)finalResult);
00532     Device->SetDisplay(ltd);
00533 }
00534 
00535 void LatencyTest::updateForTimeouts()
00536 {
00537     if (!HaveOldTime)
00538     {
00539         HaveOldTime = true;
00540         OldTime = Timer::GetTicksMs();
00541         return;
00542     }
00543 
00544     UInt32 newTime = Timer::GetTicksMs();
00545     UInt32 elapsedMilliS = newTime - OldTime;
00546     if (newTime < OldTime)
00547     {
00548         elapsedMilliS = OldTime - newTime;
00549         elapsedMilliS = UINT_MAX - elapsedMilliS;
00550     }
00551     OldTime = newTime;
00552 
00553     elapsedMilliS = Alg::Min(elapsedMilliS, (UInt32) 100);   // Clamp at 100mS in case we're not being called very often.
00554 
00555 
00556     if (ActiveTimerMilliS == 0)
00557     {
00558         return;
00559     }
00560 
00561     if (elapsedMilliS >= ActiveTimerMilliS)
00562     {
00563         ActiveTimerMilliS = 0;
00564         handleMessage(Message(), LatencyTest_Timer);
00565         return;
00566     }
00567 
00568     ActiveTimerMilliS -= elapsedMilliS;
00569 }
00570 
00571 }} // namespace OVR::Util


oculus_sdk
Author(s):
autogenerated on Fri Aug 28 2015 11:53:11