Reporting performance

[eero-t]

There aren't much Vulkan programs yet. As these demos cover a lot of Vulkan functionality, it would be nice if they could also be used for testing/comparing performance.

Best would be if demos could:

• Have an option for how long the demo will run before it exits (seconds)
• Have an option for how long demo runs "warmup" before it will start measuring performance (seconds or frames)
• Outputting FPS at given interval to console
• At the end outputting frame count and min/max/avg FPS (or frame time)

This requires refactoring the command line option handling (see the fullscreen issue) and mainloop. Most of the code in mainloop is same for all platforms so it could be common with parts specific to given platforms being e.g. separate methods.

[SaschaWillems]

Sounds feasible and I think I'll combine this with some sort of "validation feature" that allows to also output a screenshot to compare against some reference. Together with this IHVs could create some kind of test suite to compare performance and visual quality.

The FPS output stuff has been discussed in #239 and I'm not too keen on it. I prefer just measuring e.g. how fast the example rendered 1000 frames and output that to the command line once the example finished the benchmarking run.

[eero-t]

The main thing needed from the demos for validation is removing randomness, e.g. in instancing test using fixed seed, or allowing user to specify the random seed from command line.

For validation comparison, there's already vkreplay and its screenshot feature.

I'm fine if FPS isn't shown during test replay, as long as there are statistics at the end and user can control how long it takes.

PS. LunarG has started Monitor layer for run-time FPS showing, but it's still far from usable: LunarG/VulkanTools#129

[eero-t]

In case it helps, here's quick patch for doing above changes for Linux + some improvement to command line parsing (I guess you would want to refactor mainloop so that all everything doesn't need to be repeated for all other supported OSes, and get the timeout values through something else than environment variables):

--- a/base/vulkanexamplebase.cpp
+++ b/base/vulkanexamplebase.cpp
@@ -61,7 +61,7 @@ std::string VulkanExampleBase::getWindowTitle()
        windowTitle = title + " - " + device;
        if (!enableTextOverlay)
        {
-               windowTitle += " - " + std::to_string(frameCounter) + " fps";
+               windowTitle += " - " + std::to_string(lastFPS) + " fps";
        }
        return windowTitle;
 }
@@ -245,6 +245,50 @@ void VulkanExampleBase::renderLoop()
 {
        destWidth = width;
        destHeight = height;
+       // fps timer (one second interval)
+       float fpsTimer = 0.0f;
+       // min/avg/max FPS for the whole test
+       float fpsMin = 99999.0f;
+        float fpsMax = 0.0f;
+       float fpsAvg;
+       // to calculate whole run FPS
+       uint32_t frameCounter = 0;
+       uint32_t frameWarmup = 0;
+       uint32_t frameLast = 0;
+       int warmupSecs = 0;
+       int durationSecs = 0;
+       int removeSecs;
+
+       if (settings.timeout)
+       {
+               char *envstr;
+               warmupSecs = 1;
+               durationSecs = 5;
+               envstr = getenv("TEST_WARMUP_SECS");
+               if (envstr && isdigit(envstr[0]))
+               {
+                       warmupSecs = atoi(envstr);
+               }
+               envstr = getenv("TEST_DURATION_SECS");
+               if (envstr && isdigit(envstr[0]))
+               {
+                       durationSecs = atoi(envstr);
+               }
+               if (warmupSecs < 1 || warmupSecs >= durationSecs)
+               {
+                       fprintf(stderr, "ERROR: warmup (%ds) >= duration (%ds)!\n", warmupSecs, durationSecs);
+                       exit(1);
+               }
+       }
+       printf("Warming up for %d secs...\n", warmupSecs);
+       removeSecs = warmupSecs;
+
+       std::chrono::seconds tDuration(durationSecs);
+       auto tFirst = std::chrono::high_resolution_clock::now();
+       auto tLast = tFirst + tDuration;
+
+       // TODO: move all the OS specific stuff to separate helper functions
+       // so that this function doesn't need OS ifdefs
 #if defined(_WIN32)
        MSG msg;
        while (TRUE)
@@ -286,18 +330,20 @@ void VulkanExampleBase::renderLoop()
                                timer -= 1.0f;
                        }
                }
+               doingOverlayUpdate = false;
                fpsTimer += (float)tDiff;
                if (fpsTimer > 1000.0f)
                {
+                       doingOverlayUpdate = true;
                        if (!enableTextOverlay)
                        {
                                std::string windowTitle = getWindowTitle();
                                SetWindowText(window, windowTitle.c_str());
                        }
-                       lastFPS = static_cast<uint32_t>(1.0f / frameTimer);
+                       lastFPS = frameCounter - frameLast;
                        updateTextOverlay();
                        fpsTimer = 0.0f;
-                       frameCounter = 0;
+                       frameLast = frameCounter;
                }
        }
 #elif defined(__ANDROID__)
@@ -350,13 +396,15 @@ void VulkanExampleBase::renderLoop()
                                        timer -= 1.0f;
                                }
                        }
+                       doingOverlayUpdate = false;
                        fpsTimer += (float)tDiff;
                        if (fpsTimer > 1000.0f)
                        {
-                               lastFPS = frameCounter;
+                               doingOverlayUpdate = true;
+                               lastFPS = frameCounter - frameLast;
                                updateTextOverlay();
                                fpsTimer = 0.0f;
-                               frameCounter = 0;
+                               frameLast = frameCounter;
                        }
                        // Check gamepad state
                        const float deadZone = 0.0015f;
@@ -427,13 +475,15 @@ void VulkanExampleBase::renderLoop()
                                timer -= 1.0f;
                        }
                }
+               doingOverlayUpdate = false;
                fpsTimer += (float)tDiff;
                if (fpsTimer > 1000.0f)
                {
-                       lastFPS = frameCounter;
+                       doingOverlayUpdate = true;
+                       lastFPS = frameCounter - frameLast;
                        updateTextOverlay();
                        fpsTimer = 0.0f;
-                       frameCounter = 0;
+                       frameLast = frameCounter;
                }
        }
 #elif defined(__linux__)
@@ -457,6 +507,23 @@ void VulkanExampleBase::renderLoop()
                auto tEnd = std::chrono::high_resolution_clock::now();
                auto tDiff = std::chrono::duration<double, std::milli>(tEnd - tStart).count();
                frameTimer = tDiff / 1000.0f;
+               auto fpsFrame = 1.0f / frameTimer;
+               if (frameWarmup)
+               {
+                       // count only frames after warmup
+                       if (fpsFrame < fpsMin)
+                       {
+                               fpsMin = fpsFrame;
+                       }
+                       if (fpsFrame > fpsMax)
+                       {
+                               fpsMax = fpsFrame;
+                       }
+               }
+               if (settings.timeout && tEnd >= tLast)
+               {
+                       break;
+               }
                camera.update(frameTimer);
                if (camera.moving())
                {
@@ -471,9 +538,12 @@ void VulkanExampleBase::renderLoop()
                                timer -= 1.0f;
                        }
                }
+               doingOverlayUpdate = false;
+               // TODO: just calculate next time to show text, instead of accumulating diff error
                fpsTimer += (float)tDiff;
                if (fpsTimer > 1000.0f)
                {
+                       doingOverlayUpdate = true;  // for tests that want to do this stuff too
                        if (!enableTextOverlay)
                        {
                                std::string windowTitle = getWindowTitle();
@@ -481,13 +551,34 @@ void VulkanExampleBase::renderLoop()
                                        window, XCB_ATOM_WM_NAME, XCB_ATOM_STRING, 8,
                                        windowTitle.size(), windowTitle.c_str());
                        }
-                       lastFPS = frameCounter;
+                       lastFPS = frameCounter - frameLast;
                        updateTextOverlay();
                        fpsTimer = 0.0f;
-                       frameCounter = 0;
+                       frameLast = frameCounter;
+                       if (--removeSecs > 0)
+                       {
+                               // still warmup
+                       }
+                       else if (!frameWarmup)
+                       {
+                               // warmup frames done
+                               frameWarmup = frameCounter;
+                               printf("%d frames of warmup.\n", frameWarmup);
+                       }
+                       else
+                       {
+                               printf("Frames / sec: %d\n", lastFPS);
+                       }
                }
        }
 #endif
+       tLast = std::chrono::high_resolution_clock::now();
+       auto tSeconds = std::chrono::duration<float>(tLast - tFirst).count();
+       int usedFrames = frameCounter-frameWarmup;
+       fpsAvg = float(usedFrames) / tSeconds;
+       printf("\nDuration: %.1f s\nFrames: %d\nMin FPS: %0.1f\nAvg FPS: %0.1f\nMax FPS: %0.1f\n",
+              tSeconds, usedFrames, fpsMin, fpsAvg, fpsMax);
+
        // Flush device to make sure all resources can be freed 
        vkDeviceWaitIdle(device);
 }
@@ -582,7 +673,7 @@ VulkanExampleBase::VulkanExampleBase(bool enableValidation)
        settings.validation = enableValidation;
 
        // Parse command line arguments
-       for (size_t i = 0; i < args.size(); i++)
+       for (size_t i = 1; i < args.size(); i++)
        {
                if (args[i] == std::string("-validation"))
                {
@@ -592,22 +683,45 @@ VulkanExampleBase::VulkanExampleBase(bool enableValidation)
                {
                        settings.vsync = true;
                }
+               if (args[i] == std::string("-timeout"))
+               {
+                       settings.timeout = true;
+               }
                if (args[i] == std::string("-fullscreen"))
                {
                        settings.fullscreen = true;
                }
-               if ((args[i] == std::string("-w")) || (args[i] == std::string("-width")))
+               if (i+1 < args.size() && ((args[i] == std::string("-w")) || (args[i] == std::string("-width"))))
                {
                        char* endptr;
                        uint32_t w = strtol(args[i + 1], &endptr, 10);
                        if (endptr != args[i + 1]) { width = w; };
                }
-               if ((args[i] == std::string("-h")) || (args[i] == std::string("-height")))
+               if (i+1 < args.size() && ((args[i] == std::string("-h")) || (args[i] == std::string("-height"))))
                {
                        char* endptr;
                        uint32_t h = strtol(args[i + 1], &endptr, 10);
                        if (endptr != args[i + 1]) { height = h; };
                }
+               if ((args[i] == std::string("-help")) || (args[i] == std::string("--help")))
+               {
+                       fprintf(stderr, "\n\
+Usage: %s [options]\n\
+\n\
+Options:\n\
+       -fullscreen  -- run test in fullscreen instead as windowed\n\
+       -timeout     -- exit test after specified duration\n\
+       -validation  -- enable default validation layers\n\
+       -vsync       -- enables Vsync\n\
+       -w <width>   -- window width\n\
+       -h <height>  -- window height\n\
+\n\
+Environment variables affecting -timeout:\n\
+       TEST_WARMUP_SECS    -- first seconds to ignore in statistics\n\
+       TEST_DURATION_SECS  -- seconds to run, includes warmup\n\
+\n\n", basename(args[0]));
+                       exit(1);
+               }
        }
  #if defined(__ANDROID__)
diff --git a/base/vulkanexamplebase.h b/base/vulkanexamplebase.h
index d9e47a6..9c52992 100644
--- a/base/vulkanexamplebase.h
+++ b/base/vulkanexamplebase.h
@@ -49,8 +49,6 @@
 class VulkanExampleBase
 {
 private:       
-       // fps timer (one second interval)
-       float fpsTimer = 0.0f;
        // Get window title with example name, device, et.
        std::string getWindowTitle();
        /** brief Indicates that the view (position, rotation) has changed and */
@@ -64,9 +62,10 @@ private:
 protected:
        // Last frame time, measured using a high performance timer (if available)
        float frameTimer = 1.0f;
-       // Frame counter to display fps
-       uint32_t frameCounter = 0;
+       // to display fps
        uint32_t lastFPS = 0;
+       // true when common code is doing overlay update (so that test can do that too)
+       bool doingOverlayUpdate = false;
        // Vulkan instance, stores all per-application states
        VkInstance instance;
        // Physical device (GPU) that Vulkan will ise
@@ -138,6 +137,8 @@ public:
                bool validation = false;
                /** @brief Set to true if fullscreen mode has been requested via command line */
                bool fullscreen = false;
+               /** @brief Set to true if program is requested to exit after certain timeout via command line */
+               bool timeout = false;
                /** @brief Set to true if v-sync will be forced for the swapchain */
                bool vsync = false;
        } settings;
--- a/base/vulkanswapchain.hpp
+++ b/base/vulkanswapchain.hpp
@@ -319,11 +319,13 @@ public:
                {
                        for (size_t i = 0; i < presentModeCount; i++)
                        {
+#if 0 /* mailbox mode is Vsynched in fullscreen */
                                if (presentModes[i] == VK_PRESENT_MODE_MAILBOX_KHR)
                                {
                                        swapchainPresentMode = VK_PRESENT_MODE_MAILBOX_KHR;
                                        break;
                                }
+#endif
                                if ((swapchainPresentMode != VK_PRESENT_MODE_MAILBOX_KHR) && (presentModes[i] == VK_PRESENT_MODE_IMMEDIATE_KHR))
                                {
                                        swapchainPresentMode = VK_PRESENT_MODE_IMMEDIATE_KHR;
--- a/textoverlay/textoverlay.cpp
+++ b/textoverlay/textoverlay.cpp
@@ -1194,7 +1194,8 @@ public:
                if (!prepared)
                        return;
                draw();
-               if (frameCounter == 0)
+               // Why??? renderLoop() calling this, also calls updateTextOverlay() when doingOverlayUpdate is set.
+               if (doingOverlayUpdate)
                {
                        vkDeviceWaitIdle(device);
                        updateTextOverlay();

[SaschaWillems]

Just merged the benchmark mode into master. Every example can now be run in benchmark mode by running with the argument -b.

This will run 10 iterations with 1,000 frames each and calculate extremes and averages. Details are stored in benchmarkresults.csv by default.

A short summary is also output to the command line:

best : 3073.534 fps (0.325 ms)
worst: 2861.183 fps (0.350 ms)
avg  : 2981.672 fps (0.335 ms)

Benchmark settings can be tweaked at command line level,e.g.:
computenbody -b ./results/computenbody.csv 5
Will run 5 benchmark iterations and store the result to ./results/computenbody.csv.

The repository also includes a python script that runs all examples in benchmark mode storing results to a given sub directory and outputting summaries to the command line:

Benchmarking all examples...
---- (1/54) Running bloom in benchmark mode ----
best : 3087.569 fps (0.324 ms)
worst: 2955.863 fps (0.338 ms)
avg  : 3032.856 fps (0.330 ms)
Results written to ./benchmark/bloom.csv
---- (2/54) Running computecloth in benchmark mode ----
...

[eero-t]

Thanks!

While the new code is large improvement, I don't think it's quite there yet:

• For regular performance testing (e.g. things like CI), there needs to be accurate control over how long tests take. It should be possible to specify how long the test runs (in seconds) instead of 1000x iterations
• While it may be useful to specify minimum number of frames for doing warmup, warmup itself should also be specified in seconds instead of frames (devices turbo periods etc are specified in seconds, not frames)
• Timing data for each frame may also be useful for analyzing perf drops (how much badly performing frames there are and do they have some sequence, e.g. related to power throttling), but I'm not that worried about that, as there are other tools for that
• Many of the tests use random, with a random seed (time()). Use of random means that the benchmark produces random data. There are 12 places in the sources where this needs to be fixed (I have a patch that adds -seed option & fixes those). Additionally, to get data that is comparable between different platforms, you may need to use your own random generator to make sure it produces same sequence of values with the same seed value

The option parsing is also quite buggy (it crashes if args are missing, and misparses them if user gives multiple options), but that's a separate issue. I have a patch to fix that + add help if you're interested.

[SaschaWillems]

Running the benchmark for a given time makes sense, I'll try to add that too. Saving the single frame times is also pretty easy, and yes, the randomized stuff needs to work with a fixed seed.