One time lag spike

[tom-huntington]

I'm using D3D11on12 for interop with direct2d.

There is a one time 120 millisecond render where as the render work usually takes 1.5 milliseconds.

If the render work load is smaller it takes longer to happen. Seems something akin to when std::vector has to resize.

Do you know about this? Can you give any guidance?

[vdwtanner]

Interesting, I don't think I've seen that before. Do you have a repro you'd be willing to share?

[tom-huntington]

@vdwtanner This might be a driver issue. I'm using a 3090. If you replace the D3D1211on12::RenderUI function with the following and set the breakpoint, hopeful you can reproduce. The spike always happens on the 16th draw call that actually does work.

static unsigned all_render_count = 0;
static unsigned actual_11on12_render_count = 0;
struct RaiiTimer
{
    std::chrono::steady_clock::time_point start;
    RaiiTimer()
        : start(std::chrono::high_resolution_clock::now())
    {
    }
    ~RaiiTimer()
    {
        auto stop = std::chrono::high_resolution_clock::now();
        auto duration = std::chrono::duration_cast<std::chrono::microseconds>(stop - start).count();
        std::stringstream oss;
        oss << "11on12 microseconds: " << duration << " all renders: " << all_render_count << " actual 11on12 work: " << actual_11on12_render_count << std::endl;
        OutputDebugStringA(oss.str().c_str());
        if (duration > 70'000)
            auto break_point = 0;
    }
};

void D3D1211on12::RenderUI()
{
    auto timer = RaiiTimer{};
    
    D2D1_SIZE_F rtSize = m_d2dRenderTargets[m_frameIndex]->GetSize();
    D2D1_RECT_F textRect = D2D1::RectF(0, 0, rtSize.width, rtSize.height);
    static const WCHAR text[] = L"11On12";

    // Acquire our wrapped render target resource for the current back buffer.
    m_d3d11On12Device->AcquireWrappedResources(m_wrappedBackBuffers[m_frameIndex].GetAddressOf(), 1);

    m_d2dDeviceContext->SetTarget(m_d2dRenderTargets[m_frameIndex].Get());
    m_d2dDeviceContext->BeginDraw();
    m_d2dDeviceContext->SetTransform(D2D1::Matrix3x2F::Identity());
    if (all_render_count++ % 2 == 0)
    {
        actual_11on12_render_count += 1;
        m_d2dDeviceContext->DrawText(
            text,
            _countof(text) - 1,
            m_textFormat.Get(),
            &textRect,
            m_textBrush.Get()
        );
    }
    ThrowIfFailed(m_d2dDeviceContext->EndDraw());
    m_d3d11On12Device->ReleaseWrappedResources(m_wrappedBackBuffers[m_frameIndex].GetAddressOf(), 1);
    m_d3d11DeviceContext->Flush();
}

11on12 microseconds: 17064 all renders: 1 actual 11on12 work: 1
11on12 microseconds: 337 all renders: 2 actual 11on12 work: 1
11on12 microseconds: 1401 all renders: 3 actual 11on12 work: 2
11on12 microseconds: 258 all renders: 4 actual 11on12 work: 2
11on12 microseconds: 1287 all renders: 5 actual 11on12 work: 3
11on12 microseconds: 296 all renders: 6 actual 11on12 work: 3
11on12 microseconds: 818 all renders: 7 actual 11on12 work: 4
11on12 microseconds: 620 all renders: 8 actual 11on12 work: 4
11on12 microseconds: 861 all renders: 9 actual 11on12 work: 5
11on12 microseconds: 272 all renders: 10 actual 11on12 work: 5
11on12 microseconds: 1025 all renders: 11 actual 11on12 work: 6
11on12 microseconds: 298 all renders: 12 actual 11on12 work: 6
11on12 microseconds: 902 all renders: 13 actual 11on12 work: 7
11on12 microseconds: 309 all renders: 14 actual 11on12 work: 7
11on12 microseconds: 890 all renders: 15 actual 11on12 work: 8
11on12 microseconds: 287 all renders: 16 actual 11on12 work: 8
11on12 microseconds: 896 all renders: 17 actual 11on12 work: 9
11on12 microseconds: 305 all renders: 18 actual 11on12 work: 9
11on12 microseconds: 1058 all renders: 19 actual 11on12 work: 10
11on12 microseconds: 366 all renders: 20 actual 11on12 work: 10
11on12 microseconds: 800 all renders: 21 actual 11on12 work: 11
11on12 microseconds: 273 all renders: 22 actual 11on12 work: 11
11on12 microseconds: 790 all renders: 23 actual 11on12 work: 12
11on12 microseconds: 278 all renders: 24 actual 11on12 work: 12
11on12 microseconds: 893 all renders: 25 actual 11on12 work: 13
11on12 microseconds: 350 all renders: 26 actual 11on12 work: 13
11on12 microseconds: 781 all renders: 27 actual 11on12 work: 14
11on12 microseconds: 346 all renders: 28 actual 11on12 work: 14
11on12 microseconds: 1652 all renders: 29 actual 11on12 work: 15
11on12 microseconds: 561 all renders: 30 actual 11on12 work: 15
11on12 microseconds: 98266 all renders: 31 actual 11on12 work: 16

This isn't noticeable if it is for your 16 present. But it becomes noticeable if it is for your 160th present. Its easy enough to work around now that I understand it.

[tom-huntington]

I just double checked that this also happens on a release build

11on12 microseconds: 369 all renders: 27 actual 11on12 work: 14
11on12 microseconds: 180 all renders: 28 actual 11on12 work: 14
11on12 microseconds: 614 all renders: 29 actual 11on12 work: 15
11on12 microseconds: 173 all renders: 30 actual 11on12 work: 15
11on12 microseconds: 15810 all renders: 31 actual 11on12 work: 16

[vdwtanner]

Hi @tom-huntington,
Out of curiosity were you running the desktop or UWP version of the sample? Running the desktop version in debug doesn't seem to repro for me on an AMD machine.

[tom-huntington]

@vdwtanner Desktop. From memory I only noticed this after I upgraded to a 3090. So probably a driver issue?

[vdwtanner]

Sure sounds like it. I'll try it again on a different machine tomorrow. Was your other card also from nvidia? Wonder if it's a general issue or more specific to the 3090

[tom-huntington]

@vdwtanner yes 1060