时间测试中解释不了的现象，望各位大侠指点迷津

picachu82

测试目的：想知道 渲染 时的绘制时间消耗在哪段代码中。
测试条件：在场景中显示了一个曲面，创建了曲面的顶点数组和索引数组，将其放入geometry对象相应成员对象中，采用的线程方式是 singleThreaded,程序运行正常，显示正常。
测试位置：在 渲染 过程中分段计算各段渲染操作代码 所消耗时间。
代码段1、在 ViewerBase::frame() 中,在 renderingTraversals()前后设置取时间点，测试时间。
代码段2、在 RenderStage::drawInner(osg::RenderInfo& renderInfo,RenderLeaf*& previous, bool& doCopyTexture)中，
   在如下代码段前后设置取时间点:
if(state.getCheckForGLErrors()!=osg::State::NEVER_CHECK_GL_ERRORS)
{
    GLenum errorNo = glGetError();
    if (errorNo!=GL_NO_ERROR)
    {
      const char* error = (char*)gluErrorString(errorNo);
      if (error)  osg::notify(osg::NOTICE)<<"Warning: detected OpenGL error '"<<error<<"' after RenderBin::draw(,)"<<std::endl;
      else        osg::notify(osg::NOTICE)<<"Warning: detected OpenGL errorNo= 0x"<<std::hex<<errorNo<<" after RenderBin::draw(,)"<<std::dec<<std::endl;
      if (fbo_ext) osg::notify(osg::NOTICE)<<"RenderStage::drawInner(,) FBO status= 0x"<<std::hex<<fbo_ext->glCheckFramebufferStatusEXT(GL_FRAMEBUFFER_EXT)<<std::dec<<std::endl;
     }
}
代码段3、在 void GraphicsWindowWin32::swapBuffersImplementation()中，在::SwapBuffers(_hdc);前后设置取时间点。
各段代码的消耗时间：
代码段1： 0.0156627 秒
代码段2： 0.0143021 秒
代码段3： 0.000071  秒
看起来在整个渲染的过程中，消耗时间最大贡献的是代码段2，但是代码段2只是检查错误的代码，让我觉得很奇怪，既然是错误代码，那对程序的影响也许不大，于是我考虑屏蔽掉其中
    GLenum errorNo = glGetError();
    if (errorNo!=GL_NO_ERROR)
    {
      const char* error = (char*)gluErrorString(errorNo);
      if (error)  osg::notify(osg::NOTICE)<<"Warning: detected OpenGL error '"<<error<<"' after RenderBin::draw(,)"<<std::endl;
      else        osg::notify(osg::NOTICE)<<"Warning: detected OpenGL errorNo= 0x"<<std::hex<<errorNo<<" after RenderBin::draw(,)"<<std::dec<<std::endl;
      if (fbo_ext) osg::notify(osg::NOTICE)<<"RenderStage::drawInner(,) FBO status= 0x"<<std::hex<<fbo_ext->glCheckFramebufferStatusEXT(GL_FRAMEBUFFER_EXT)<<std::dec<<std::endl;
     }
部分，再重新测试时间，得出了如下结果：
各段代码的消耗时间：
代码段1： 0.0157272    秒
代码段2： 2.69988e-007 秒
代码段3： 0.012529     秒
代码段2是不耗时了，耗时的变成了代码段3，我不知道为什么glGetError会对这个时间测试有那么大的影响，如果 SwapBuffers 在2次测试中均贡献大，那我还能想通，但是我现在完全迷糊了，知识有限，无法解释这个现象的原因，请热心的朋友们告诉我，到底耗时到哪里去了？我是否能避开这 10+ ms 的耗时。

FlySky

glGetError需要循环处理，可能耗费的时间相当之多～～～～这个只是针对调试程序而用的！！至于SwapBuffers的效率，那是比较不理想的，，如果你想高效率的话，可以自己手动去获得wglSwapBuffers～～～～～～～

picachu82

可是这两个函数调用osg渲染源码里面必定会走的，我怎么做才能绕过呢？

FlySky

你可以选择重写这些类～～～如果你不是做高精度的渲染，，这些不必考虑～～只需要考虑程序的简化和优化就可以了～～～～～～

array

您是如何取得时间点的？不知道这个取值是否精确？

picachu82

to array:
    用osg的timer类来获取时间的，在一段代码之前之后获取当前timeTick，然后获取代码运行的时间差。
to flysky:
    自己的代码消耗时间已经不到1ms ，但是在这2句代码上却要消耗 20+ms的时间，确实有点难受。

array

如果您是工作于多线程渲染的模式下，您的检测方法恐怕并不科学。因为您实际上不知道前后两次tick()的动作，是不是对于同一个线程的！因此我个人认为这个结果本身的意义不大

picachu82

我用的是 single thread ，这种模式在osg里面也会产生另外的工作线程吗？ 不了解Osg的线程运作机制

array

如果您确定是采用Viewer的SingleThreaded模式，那么不会产生别的线程。

根据您目前提供的信息，我个人无法判断其缘由，并且猜测这一差异源自于Win32的API函数SwapBuffers()。

此外的确如Flysky所说，您考虑这些地方恐怕并没有什么意义；倒不如单独对自己的绘制代码进行tick()判断时间间隔，看看到底消耗了多少时间~~

事实上10ms以下的数据本身就是无法精确量测的（尤其在windows下），尽管Timer类用到了Win32 API中的QueryPerformanceCounter()这个系统级别的频率计数函数，但是它的误差也是ms数量级的，并且我们无法判断它和SwapBuffers()之间有什么相互的影响。

picachu82

谢谢 array 和 flySky 的 耐心解答。