1 /*-------------------------------------------------------------------------
2 * drawElements Quality Program OpenGL ES 3.0 Module
3 * -------------------------------------------------
5 * Copyright 2014 The Android Open Source Project
7 * Licensed under the Apache License, Version 2.0 (the "License");
8 * you may not use this file except in compliance with the License.
9 * You may obtain a copy of the License at
11 * http://www.apache.org/licenses/LICENSE-2.0
13 * Unless required by applicable law or agreed to in writing, software
14 * distributed under the License is distributed on an "AS IS" BASIS,
15 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
16 * See the License for the specific language governing permissions and
17 * limitations under the License.
21 * \brief Flush and finish tests.
22 *//*--------------------------------------------------------------------*/
24 #include "es3fFlushFinishTests.hpp"
26 #include "gluRenderContext.hpp"
27 #include "gluObjectWrapper.hpp"
28 #include "gluShaderProgram.hpp"
29 #include "gluDrawUtil.hpp"
31 #include "glsCalibration.hpp"
33 #include "tcuTestLog.hpp"
34 #include "tcuRenderTarget.hpp"
35 #include "tcuCPUWarmup.hpp"
38 #include "glwEnums.hpp"
39 #include "glwFunctions.hpp"
41 #include "deRandom.hpp"
42 #include "deStringUtil.hpp"
60 using deqp::gls::theilSenLinearRegression;
61 using deqp::gls::LineParameters;
68 MAX_VIEWPORT_SIZE = 256,
69 MAX_SAMPLE_DURATION_US = 150*1000,
70 MAX_CALIBRATE_DURATION_US = tcu::WATCHDOG_INTERVAL_TIME_LIMIT_SECS/3*1000*1000, // Abort when the watch dog gets nervous
72 MIN_DRAW_CALL_COUNT = 10,
73 MAX_DRAW_CALL_COUNT = 1<<20,
74 MAX_SHADER_ITER_COUNT = 1<<10,
76 NUM_VERIFICATION_SAMPLES = 3,
77 MAX_CALIBRATION_ATTEMPTS = 5
80 DE_STATIC_ASSERT(MAX_SAMPLE_DURATION_US < 1000*WAIT_TIME_MS);
82 const float NO_CORR_COEF_THRESHOLD = 0.1f;
83 const float FLUSH_COEF_THRESHOLD = 0.2f;
84 const float CORRELATED_COEF_THRESHOLD = 0.3f;
85 const float CALIBRATION_VERIFICATION_THRESHOLD = 0.10f; // Rendering time needs to be within 10% of MAX_SAMPLE_DURATION_US
87 static void busyWait (int milliseconds)
89 const deUint64 startTime = deGetMicroseconds();
94 for (int i = 0; i < 10; i++)
97 if (deGetMicroseconds()-startTime >= deUint64(1000*milliseconds))
102 class CalibrationFailedException : public std::runtime_error
105 CalibrationFailedException (const std::string& reason) : std::runtime_error(reason) {}
108 class FlushFinishCase : public TestCase
111 enum ExpectedBehavior
113 EXPECT_COEF_LESS_THAN = 0,
114 EXPECT_COEF_GREATER_THAN,
117 FlushFinishCase (Context& context,
119 const char* description,
120 ExpectedBehavior waitBehavior,
122 ExpectedBehavior readBehavior,
123 float readThreshold);
124 ~FlushFinishCase (void);
128 IterateResult iterate (void);
135 deUint64 readPixelsTime;
138 struct CalibrationParams
140 int numItersInShader;
145 virtual void waitForGL (void) = 0;
148 FlushFinishCase (const FlushFinishCase&);
149 FlushFinishCase& operator= (const FlushFinishCase&);
151 CalibrationParams calibrate (void);
152 void verifyCalibration (const CalibrationParams& params);
154 void analyzeResults (const std::vector<Sample>& samples, const CalibrationParams& calibrationParams);
156 void setupRenderState (void);
157 void setShaderIterCount (int numIters);
158 void render (int numDrawCalls);
159 void readPixels (void);
161 const ExpectedBehavior m_waitBehavior;
162 const float m_waitThreshold;
163 const ExpectedBehavior m_readBehavior;
164 const float m_readThreshold;
166 glu::ShaderProgram* m_program;
170 FlushFinishCase::FlushFinishCase (Context& context, const char* name, const char* description, ExpectedBehavior waitBehavior, float waitThreshold, ExpectedBehavior readBehavior, float readThreshold)
171 : TestCase (context, name, description)
172 , m_waitBehavior (waitBehavior)
173 , m_waitThreshold (waitThreshold)
174 , m_readBehavior (readBehavior)
175 , m_readThreshold (readThreshold)
176 , m_program (DE_NULL)
181 FlushFinishCase::~FlushFinishCase (void)
183 FlushFinishCase::deinit();
186 void FlushFinishCase::init (void)
188 DE_ASSERT(!m_program);
190 m_program = new glu::ShaderProgram(m_context.getRenderContext(),
191 glu::ProgramSources()
192 << glu::VertexSource(
194 "in highp vec4 a_position;\n"
195 "out highp vec4 v_coord;\n"
198 " gl_Position = a_position;\n"
199 " v_coord = a_position;\n"
201 << glu::FragmentSource(
203 "uniform highp int u_numIters;\n"
204 "in highp vec4 v_coord;\n"
205 "out mediump vec4 o_color;\n"
208 " highp vec4 color = v_coord;\n"
209 " for (int i = 0; i < u_numIters; i++)\n"
210 " color = sin(color);\n"
211 " o_color = color;\n"
214 if (!m_program->isOk())
216 m_testCtx.getLog() << *m_program;
219 TCU_FAIL("Compile failed");
222 m_iterCountLoc = m_context.getRenderContext().getFunctions().getUniformLocation(m_program->getProgram(), "u_numIters");
223 TCU_CHECK(m_iterCountLoc >= 0);
226 void FlushFinishCase::deinit (void)
232 tcu::TestLog& operator<< (tcu::TestLog& log, const FlushFinishCase::Sample& sample)
234 log << TestLog::Message << sample.numDrawCalls << " calls:\t" << sample.submitTime << " us submit,\t" << sample.waitTime << " us wait,\t" << sample.readPixelsTime << " us read" << TestLog::EndMessage;
238 void FlushFinishCase::setupRenderState (void)
240 const glw::Functions& gl = m_context.getRenderContext().getFunctions();
241 const int posLoc = gl.getAttribLocation(m_program->getProgram(), "a_position");
242 const int viewportW = de::min<int>(m_context.getRenderTarget().getWidth(), MAX_VIEWPORT_SIZE);
243 const int viewportH = de::min<int>(m_context.getRenderTarget().getHeight(), MAX_VIEWPORT_SIZE);
245 static const float s_positions[] =
253 TCU_CHECK(posLoc >= 0);
255 gl.viewport(0, 0, viewportW, viewportH);
256 gl.useProgram(m_program->getProgram());
257 gl.enableVertexAttribArray(posLoc);
258 gl.vertexAttribPointer(posLoc, 2, GL_FLOAT, GL_FALSE, 0, &s_positions[0]);
260 gl.blendFunc(GL_ONE, GL_ONE);
261 gl.blendEquation(GL_FUNC_ADD);
262 GLU_EXPECT_NO_ERROR(gl.getError(), "Failed to set up render state");
265 void FlushFinishCase::setShaderIterCount (int numIters)
267 const glw::Functions& gl = m_context.getRenderContext().getFunctions();
268 gl.uniform1i(m_iterCountLoc, numIters);
271 void FlushFinishCase::render (int numDrawCalls)
273 const glw::Functions& gl = m_context.getRenderContext().getFunctions();
275 const deUint8 indices[] = { 0, 1, 2, 2, 1, 3 };
277 gl.clear(GL_COLOR_BUFFER_BIT|GL_DEPTH_BUFFER_BIT|GL_STENCIL_BUFFER_BIT);
279 for (int ndx = 0; ndx < numDrawCalls; ndx++)
280 gl.drawElements(GL_TRIANGLES, DE_LENGTH_OF_ARRAY(indices), GL_UNSIGNED_BYTE, &indices[0]);
283 void FlushFinishCase::readPixels (void)
285 const glw::Functions& gl = m_context.getRenderContext().getFunctions();
288 gl.readPixels(0, 0, 1, 1, GL_RGBA, GL_UNSIGNED_BYTE, &tmp);
291 FlushFinishCase::CalibrationParams FlushFinishCase::calibrate (void)
293 tcu::ScopedLogSection section (m_testCtx.getLog(), "CalibrationInfo", "Calibration info");
294 CalibrationParams params;
296 const deUint64 calibrateStartTime = deGetMicroseconds();
298 // Step 1: find iteration count that results in rougly 1/10th of target maximum sample duration.
300 const deUint64 targetDurationUs = MAX_SAMPLE_DURATION_US/100;
301 deUint64 prevDuration = 0;
302 int prevIterCount = 1;
303 int curIterCount = 1;
305 m_testCtx.getLog() << TestLog::Message << "Calibrating shader iteration count, target duration = " << targetDurationUs << " us" << TestLog::EndMessage;
310 deUint64 curDuration;
312 setShaderIterCount(curIterCount);
313 render(1); // \note Submit time is ignored
316 const deUint64 startTime = deGetMicroseconds();
318 endTime = deGetMicroseconds();
319 curDuration = endTime-startTime;
322 m_testCtx.getLog() << TestLog::Message << "Duration with " << curIterCount << " iterations = " << curDuration << " us" << TestLog::EndMessage;
324 if (curDuration > targetDurationUs)
326 if (curIterCount > 1)
328 // Compute final count by using linear estimation.
329 const float a = float(curDuration - prevDuration) / float(curIterCount - prevIterCount);
330 const float b = float(prevDuration) - a*float(prevIterCount);
331 const float est = (float(targetDurationUs) - b) / a;
333 curIterCount = de::clamp(deFloorFloatToInt32(est), 1, int(MAX_SHADER_ITER_COUNT));
335 // else: Settle on 1.
339 else if (curIterCount >= MAX_SHADER_ITER_COUNT)
340 break; // Settle on maximum.
341 else if (endTime - calibrateStartTime > MAX_CALIBRATE_DURATION_US)
343 // Calibration is taking longer than expected. This can be due to eager draw call execution.
344 throw CalibrationFailedException("Calibration failed, target duration not reached within expected time");
348 prevIterCount = curIterCount;
349 prevDuration = curDuration;
350 curIterCount = curIterCount*2;
354 params.numItersInShader = curIterCount;
356 m_testCtx.getLog() << TestLog::Integer("ShaderIterCount", "Shader iteration count", "", QP_KEY_TAG_NONE, params.numItersInShader);
359 // Step 2: Find draw call count that results in desired maximum time.
361 deUint64 prevDuration = 0;
362 int prevDrawCount = 1;
363 int curDrawCount = 1;
365 m_testCtx.getLog() << TestLog::Message << "Calibrating maximum draw call count, target duration = " << int(MAX_SAMPLE_DURATION_US) << " us" << TestLog::EndMessage;
367 setShaderIterCount(params.numItersInShader);
372 deUint64 curDuration;
374 render(curDrawCount); // \note Submit time is ignored
377 const deUint64 startTime = deGetMicroseconds();
379 endTime = deGetMicroseconds();
380 curDuration = endTime-startTime;
383 m_testCtx.getLog() << TestLog::Message << "Duration with " << curDrawCount << " draw calls = " << curDuration << " us" << TestLog::EndMessage;
385 if (curDuration > MAX_SAMPLE_DURATION_US)
387 if (curDrawCount > 1)
389 // Compute final count by using linear estimation.
390 const float a = float(curDuration - prevDuration) / float(curDrawCount - prevDrawCount);
391 const float b = float(prevDuration) - a*float(prevDrawCount);
392 const float est = (float(MAX_SAMPLE_DURATION_US) - b) / a;
394 curDrawCount = de::clamp(deFloorFloatToInt32(est), 1, int(MAX_DRAW_CALL_COUNT));
396 // else: Settle on 1.
400 else if (curDrawCount >= MAX_DRAW_CALL_COUNT)
401 break; // Settle on maximum.
402 else if (endTime - calibrateStartTime > MAX_CALIBRATE_DURATION_US)
404 // Calibration is taking longer than expected. This can be due to eager draw call execution.
405 throw CalibrationFailedException("Calibration failed, target duration not reached within expected time");
409 prevDrawCount = curDrawCount;
410 prevDuration = curDuration;
411 curDrawCount = curDrawCount*2;
415 params.maxDrawCalls = curDrawCount;
417 m_testCtx.getLog() << TestLog::Integer("MaxDrawCalls", "Maximum number of draw calls", "", QP_KEY_TAG_NONE, params.maxDrawCalls);
421 if (params.maxDrawCalls < MIN_DRAW_CALL_COUNT)
422 throw CalibrationFailedException("Calibration failed, maximum draw call count is too low");
427 void FlushFinishCase::verifyCalibration (const CalibrationParams& params)
429 setShaderIterCount(params.numItersInShader);
431 for (int sampleNdx = 0; sampleNdx < NUM_VERIFICATION_SAMPLES; sampleNdx++)
433 deUint64 readStartTime;
435 render(params.maxDrawCalls);
437 readStartTime = deGetMicroseconds();
441 const deUint64 renderDuration = deGetMicroseconds()-readStartTime;
442 const float relativeDelta = float(double(renderDuration) / double(MAX_SAMPLE_DURATION_US)) - 1.0f;
444 if (!de::inBounds(relativeDelta, -CALIBRATION_VERIFICATION_THRESHOLD, CALIBRATION_VERIFICATION_THRESHOLD))
446 std::ostringstream msg;
447 msg << "ERROR: Unstable performance, got " << renderDuration << " us read time, "
448 << de::floatToString(relativeDelta*100.0f, 1) << "% diff to estimated " << (int)MAX_SAMPLE_DURATION_US << " us";
449 throw CalibrationFailedException(msg.str());
455 struct CompareSampleDrawCount
457 bool operator() (const FlushFinishCase::Sample& a, const FlushFinishCase::Sample& b) const { return a.numDrawCalls < b.numDrawCalls; }
460 std::vector<Vec2> getPointsFromSamples (const std::vector<FlushFinishCase::Sample>& samples, const deUint64 FlushFinishCase::Sample::*field)
462 vector<Vec2> points(samples.size());
464 for (size_t ndx = 0; ndx < samples.size(); ndx++)
465 points[ndx] = Vec2(float(samples[ndx].numDrawCalls), float(samples[ndx].*field));
471 T getMaximumValue (const std::vector<FlushFinishCase::Sample>& samples, const T FlushFinishCase::Sample::*field)
473 DE_ASSERT(!samples.empty());
475 T maxVal = samples[0].*field;
477 for (size_t ndx = 1; ndx < samples.size(); ndx++)
478 maxVal = de::max(maxVal, samples[ndx].*field);
483 void FlushFinishCase::analyzeResults (const std::vector<Sample>& samples, const CalibrationParams& calibrationParams)
485 const vector<Vec2> waitTimes = getPointsFromSamples(samples, &Sample::waitTime);
486 const vector<Vec2> readTimes = getPointsFromSamples(samples, &Sample::readPixelsTime);
487 const LineParameters waitLine = theilSenLinearRegression(waitTimes);
488 const LineParameters readLine = theilSenLinearRegression(readTimes);
489 const float normWaitCoef = waitLine.coefficient * float(calibrationParams.maxDrawCalls) / float(MAX_SAMPLE_DURATION_US);
490 const float normReadCoef = readLine.coefficient * float(calibrationParams.maxDrawCalls) / float(MAX_SAMPLE_DURATION_US);
494 tcu::ScopedLogSection section (m_testCtx.getLog(), "Samples", "Samples");
495 vector<Sample> sortedSamples (samples.begin(), samples.end());
497 std::sort(sortedSamples.begin(), sortedSamples.end(), CompareSampleDrawCount());
499 for (vector<Sample>::const_iterator iter = sortedSamples.begin(); iter != sortedSamples.end(); ++iter)
500 m_testCtx.getLog() << *iter;
503 m_testCtx.getLog() << TestLog::Float("WaitCoefficient", "Wait coefficient", "", QP_KEY_TAG_NONE, waitLine.coefficient)
504 << TestLog::Float("ReadCoefficient", "Read coefficient", "", QP_KEY_TAG_NONE, readLine.coefficient)
505 << TestLog::Float("NormalizedWaitCoefficient", "Normalized wait coefficient", "", QP_KEY_TAG_NONE, normWaitCoef)
506 << TestLog::Float("NormalizedReadCoefficient", "Normalized read coefficient", "", QP_KEY_TAG_NONE, normReadCoef);
509 const bool waitCorrelated = normWaitCoef > CORRELATED_COEF_THRESHOLD;
510 const bool readCorrelated = normReadCoef > CORRELATED_COEF_THRESHOLD;
511 const bool waitNotCorr = normWaitCoef < NO_CORR_COEF_THRESHOLD;
512 const bool readNotCorr = normReadCoef < NO_CORR_COEF_THRESHOLD;
514 if (waitCorrelated || waitNotCorr)
515 m_testCtx.getLog() << TestLog::Message << "Wait time is" << (waitCorrelated ? "" : " NOT") << " correlated to rendering workload size." << TestLog::EndMessage;
517 m_testCtx.getLog() << TestLog::Message << "Warning: Wait time correlation to rendering workload size is unclear." << TestLog::EndMessage;
519 if (readCorrelated || readNotCorr)
520 m_testCtx.getLog() << TestLog::Message << "Read time is" << (readCorrelated ? "" : " NOT") << " correlated to rendering workload size." << TestLog::EndMessage;
522 m_testCtx.getLog() << TestLog::Message << "Warning: Read time correlation to rendering workload size is unclear." << TestLog::EndMessage;
525 for (int ndx = 0; ndx < 2; ndx++)
527 const float coef = ndx == 0 ? normWaitCoef : normReadCoef;
528 const char* name = ndx == 0 ? "wait" : "read";
529 const ExpectedBehavior behavior = ndx == 0 ? m_waitBehavior : m_readBehavior;
530 const float threshold = ndx == 0 ? m_waitThreshold : m_readThreshold;
531 const bool isOk = behavior == EXPECT_COEF_GREATER_THAN ? coef > threshold :
532 behavior == EXPECT_COEF_LESS_THAN ? coef < threshold : false;
533 const char* cmpName = behavior == EXPECT_COEF_GREATER_THAN ? "greater than" :
534 behavior == EXPECT_COEF_LESS_THAN ? "less than" : DE_NULL;
538 m_testCtx.getLog() << TestLog::Message << "ERROR: Expected " << name << " coefficient to be " << cmpName << " " << threshold << TestLog::EndMessage;
543 m_testCtx.setTestResult(allOk ? QP_TEST_RESULT_PASS : QP_TEST_RESULT_COMPATIBILITY_WARNING,
544 allOk ? "Pass" : "Suspicious performance behavior");
547 FlushFinishCase::IterateResult FlushFinishCase::iterate (void)
549 vector<Sample> samples (NUM_SAMPLES);
550 CalibrationParams params;
556 // Do one full render cycle.
558 setShaderIterCount(1);
564 for (int calibrationRoundNdx = 0; /* until done */; calibrationRoundNdx++)
568 m_testCtx.touchWatchdog();
569 params = calibrate();
570 verifyCalibration(params);
573 catch (const CalibrationFailedException& e)
575 m_testCtx.getLog() << e;
577 if (calibrationRoundNdx < MAX_CALIBRATION_ATTEMPTS)
579 m_testCtx.getLog() << TestLog::Message
580 << "Retrying calibration (" << (calibrationRoundNdx+1) << " / " << (int)MAX_CALIBRATION_ATTEMPTS << ")"
581 << TestLog::EndMessage;
585 m_testCtx.setTestResult(QP_TEST_RESULT_COMPATIBILITY_WARNING, e.what());
593 de::Random rnd (123);
595 setShaderIterCount(params.numItersInShader);
597 for (size_t ndx = 0; ndx < samples.size(); ndx++)
599 const int drawCallCount = rnd.getInt(1, params.maxDrawCalls);
600 const deUint64 submitStartTime = deGetMicroseconds();
601 deUint64 waitStartTime;
602 deUint64 readStartTime;
603 deUint64 readFinishTime;
605 render(drawCallCount);
607 waitStartTime = deGetMicroseconds();
610 readStartTime = deGetMicroseconds();
612 readFinishTime = deGetMicroseconds();
614 samples[ndx].numDrawCalls = drawCallCount;
615 samples[ndx].submitTime = waitStartTime-submitStartTime;
616 samples[ndx].waitTime = readStartTime-waitStartTime;
617 samples[ndx].readPixelsTime = readFinishTime-readStartTime;
619 m_testCtx.touchWatchdog();
623 // Analyze - sets test case result.
624 analyzeResults(samples, params);
629 class WaitOnlyCase : public FlushFinishCase
632 WaitOnlyCase (Context& context)
633 : FlushFinishCase(context, "wait", "Wait only", EXPECT_COEF_LESS_THAN, NO_CORR_COEF_THRESHOLD, EXPECT_COEF_GREATER_THAN, -1000.0f /* practically nothing is expected */)
639 m_testCtx.getLog() << TestLog::Message << int(WAIT_TIME_MS) << " ms busy wait" << TestLog::EndMessage;
640 FlushFinishCase::init();
644 void waitForGL (void)
646 busyWait(WAIT_TIME_MS);
650 class FlushOnlyCase : public FlushFinishCase
653 FlushOnlyCase (Context& context)
654 : FlushFinishCase(context, "flush", "Flush only", EXPECT_COEF_LESS_THAN, FLUSH_COEF_THRESHOLD, EXPECT_COEF_GREATER_THAN, CORRELATED_COEF_THRESHOLD)
660 m_testCtx.getLog() << TestLog::Message << "Single call to glFlush()" << TestLog::EndMessage;
661 FlushFinishCase::init();
665 void waitForGL (void)
667 m_context.getRenderContext().getFunctions().flush();
671 class FlushWaitCase : public FlushFinishCase
674 FlushWaitCase (Context& context)
675 : FlushFinishCase(context, "flush_wait", "Wait after flushing", EXPECT_COEF_LESS_THAN, FLUSH_COEF_THRESHOLD, EXPECT_COEF_LESS_THAN, NO_CORR_COEF_THRESHOLD)
681 m_testCtx.getLog() << TestLog::Message << "glFlush() followed by " << int(WAIT_TIME_MS) << " ms busy wait" << TestLog::EndMessage;
682 FlushFinishCase::init();
686 void waitForGL (void)
688 m_context.getRenderContext().getFunctions().flush();
689 busyWait(WAIT_TIME_MS);
693 class FinishOnlyCase : public FlushFinishCase
696 FinishOnlyCase (Context& context)
697 : FlushFinishCase(context, "finish", "Finish only", EXPECT_COEF_GREATER_THAN, CORRELATED_COEF_THRESHOLD, EXPECT_COEF_LESS_THAN, NO_CORR_COEF_THRESHOLD)
703 m_testCtx.getLog() << TestLog::Message << "Single call to glFinish()" << TestLog::EndMessage;
704 FlushFinishCase::init();
708 void waitForGL (void)
710 m_context.getRenderContext().getFunctions().finish();
714 class FinishWaitCase : public FlushFinishCase
717 FinishWaitCase (Context& context)
718 : FlushFinishCase(context, "finish_wait", "Finish and wait", EXPECT_COEF_GREATER_THAN, CORRELATED_COEF_THRESHOLD, EXPECT_COEF_LESS_THAN, NO_CORR_COEF_THRESHOLD)
724 m_testCtx.getLog() << TestLog::Message << "glFinish() followed by " << int(WAIT_TIME_MS) << " ms busy wait" << TestLog::EndMessage;
725 FlushFinishCase::init();
729 void waitForGL (void)
731 m_context.getRenderContext().getFunctions().finish();
732 busyWait(WAIT_TIME_MS);
738 FlushFinishTests::FlushFinishTests (Context& context)
739 : TestCaseGroup(context, "flush_finish", "Flush and Finish tests")
743 FlushFinishTests::~FlushFinishTests (void)
747 void FlushFinishTests::init (void)
749 addChild(new WaitOnlyCase (m_context));
750 addChild(new FlushOnlyCase (m_context));
751 addChild(new FlushWaitCase (m_context));
752 addChild(new FinishOnlyCase (m_context));
753 addChild(new FinishWaitCase (m_context));