From bb6a2d9a434f55df94554cd3e9ef26dbd2ad7ce0 Mon Sep 17 00:00:00 2001
From: Laszlo Csomor <laszlocsomor@google.com>
Date: Fri, 16 Mar 2018 09:44:32 +0100
Subject: [PATCH] Windows process creation: add demo to measure it

Add a demo project that measures process creation
times with and without waiting for the process to
terminate.

On Bazel's testing Windows VM, I measured:

  CreateProcess times
    95th %%: 3 ms
    99th %%: 4 ms
    99.5th %%: 5 ms
    99.9th %%: 10 ms
    max: 10 ms

  CreateProcess + WaitForSingleObject times
    95th %%: 9 ms
    99th %%: 10 ms
    99.5th %%: 11 ms
    99.9th %%: 15 ms
    max: 15 ms

On my own Windows box I measured:

  CreateProcess times
    95th %%: 59 ms
    99th %%: 92 ms
    99.5th %%: 113 ms
    99.9th %%: 178 ms
    max: 178 ms

  CreateProcess + WaitForSingleObject times
    95th %%: 67 ms
    99th %%: 98 ms
    99.5th %%: 122 ms
    99.9th %%: 183 ms
    max: 183 ms
---
 bazel/process-creation-times-windows/BUILD    |  7 ++
 .../process-creation-times-windows/WORKSPACE  |  0
 .../createproc.cc                             | 82 +++++++++++++++++++
 3 files changed, 89 insertions(+)
 create mode 100644 bazel/process-creation-times-windows/BUILD
 create mode 100644 bazel/process-creation-times-windows/WORKSPACE
 create mode 100644 bazel/process-creation-times-windows/createproc.cc

diff --git a/bazel/process-creation-times-windows/BUILD b/bazel/process-creation-times-windows/BUILD
new file mode 100644
index 0000000..806a3fa
--- /dev/null
+++ b/bazel/process-creation-times-windows/BUILD
@@ -0,0 +1,7 @@
+# Usage:
+#   bazel build -c opt //:bin
+#   bazel-bin\bin.exe
+cc_binary(
+    name = "bin",
+    srcs = ["createproc.cc"],
+)
diff --git a/bazel/process-creation-times-windows/WORKSPACE b/bazel/process-creation-times-windows/WORKSPACE
new file mode 100644
index 0000000..e69de29
diff --git a/bazel/process-creation-times-windows/createproc.cc b/bazel/process-creation-times-windows/createproc.cc
new file mode 100644
index 0000000..c10a0d6
--- /dev/null
+++ b/bazel/process-creation-times-windows/createproc.cc
@@ -0,0 +1,82 @@
+#define _CRT_SECURE_NO_WARNINGS
+#include <Windows.h>
+#include <string.h>
+
+#include <algorithm>
+#include <array>
+#include <iostream>
+
+bool RunProc(char* cmdline, LARGE_INTEGER* create_time, LARGE_INTEGER* full_time) {
+  LARGE_INTEGER start;
+  QueryPerformanceCounter(&start);
+  PROCESS_INFORMATION processInfo;
+  STARTUPINFOA startupInfo = {0};
+  BOOL ok = CreateProcessA(NULL, cmdline, NULL, NULL, FALSE, 0, NULL, NULL,
+                           &startupInfo, &processInfo);
+  if (!ok) {
+    DWORD err = GetLastError();
+    std::cerr << "ERROR: CreateProcessA error: " << err << std::endl;
+    return false;
+  }
+  QueryPerformanceCounter(create_time);
+  WaitForSingleObject(processInfo.hProcess, INFINITE);
+  CloseHandle(processInfo.hProcess);
+  CloseHandle(processInfo.hThread);
+  QueryPerformanceCounter(full_time);
+  create_time->QuadPart -= start.QuadPart;
+  full_time->QuadPart -= start.QuadPart;
+  return true;
+}
+
+size_t percentile_index(size_t total, size_t a, size_t b) {
+  return std::min<size_t>(total, (total * a) / b);
+}
+
+int main(int argc, char* argv[]) {
+  if (argc == 1) {
+    static const size_t kSamples = 1000;
+    char cmdline[1000];
+    size_t argv0len = strlen(argv[0]);
+    strcpy(cmdline, argv[0]);
+    cmdline[argv0len] = ' ';
+    cmdline[argv0len + 1] = 'x';
+    cmdline[argv0len + 2] = 0;
+    std::array<LARGE_INTEGER, kSamples> create_time;
+    std::array<LARGE_INTEGER, kSamples> full_time;
+    for (size_t i = 0; i < kSamples; ++i) {
+      if (!RunProc(cmdline, &create_time[i], &full_time[i])) {
+        return 1;
+      }
+      if (i % 10 == 0) {
+        std::cout << "ran " << i << " processes\r";
+      }
+    }
+    std::sort(
+      create_time.begin(), create_time.end(),
+      [](LARGE_INTEGER a, LARGE_INTEGER b) { return a.QuadPart < b.QuadPart; });
+    std::sort(
+      full_time.begin(), full_time.end(),
+      [](LARGE_INTEGER a, LARGE_INTEGER b) { return a.QuadPart < b.QuadPart; });
+    LARGE_INTEGER freq;
+    QueryPerformanceFrequency(&freq);
+    for (size_t i = 0; i < kSamples; ++i) {
+      create_time[i].QuadPart = (create_time[i].QuadPart * 1000) / freq.QuadPart;
+      full_time[i].QuadPart = (full_time[i].QuadPart * 1000) / freq.QuadPart;
+    }
+    std::cout << std::endl;
+    std::cout << "CreateProcess times" << std::endl;
+    std::cout << "  95th %%: " << create_time[percentile_index(kSamples, 95, 100)].QuadPart << " ms" << std::endl;
+    std::cout << "  99th %%: " << create_time[percentile_index(kSamples, 99, 100)].QuadPart << " ms" << std::endl;
+    std::cout << "  99.5th %%: " << create_time[percentile_index(kSamples, 995, 1000)].QuadPart << " ms" << std::endl;
+    std::cout << "  99.9th %%: " << create_time[percentile_index(kSamples, 999, 1000)].QuadPart << " ms" << std::endl;
+    std::cout << "  max: " << create_time[kSamples - 1].QuadPart << " ms" << std::endl;
+    std::cout << std::endl;
+    std::cout << "CreateProcess + WaitForSingleObject times" << std::endl;
+    std::cout << "  95th %%: " << full_time[percentile_index(kSamples, 95, 100)].QuadPart << " ms" << std::endl;
+    std::cout << "  99th %%: " << full_time[percentile_index(kSamples, 99, 100)].QuadPart << " ms" << std::endl;
+    std::cout << "  99.5th %%: " << full_time[percentile_index(kSamples, 995, 1000)].QuadPart << " ms" << std::endl;
+    std::cout << "  99.9th %%: " << full_time[percentile_index(kSamples, 999, 1000)].QuadPart << " ms" << std::endl;
+    std::cout << "  max: " << full_time[kSamples - 1].QuadPart << " ms" << std::endl;
+  }
+  return 0;
+}