std::thread does not start immediately as expected (c++11)

Question

I have the following code in my main.cpp

std::thread t1(&AgentsSourcesManager::Run, &sim.GetAgentSrcManager());
doSomething(); // in the main Thread
t1.join();

I was expecting t1 to start immediately and start along the main thread. However, this is not the case. I measure the execution time of my program, repeat this 100 times and make some plots.

See the peak in the following picture.

Now if I wait a bit after the creation of t1

std::this_thread::sleep_for(std::chrono::milliseconds(100));

I get better results. See the following picture.

(Still with a peak there, but well ..)

Obviously my questions are:

• Why a peak?
• Why I don't have a straight line?

EDIT

Ok, from the comments I understand by now, that there might be some scheduler magic going on.

Here is a working example

#include <thread>
#include <chrono>
#include <iostream>
#include <pthread.h>
#include <functional>
int main() {
     float x = 0;     float y = 0;
     std::chrono::time_point<std::chrono::system_clock> start, stop;

    start= std::chrono::system_clock::now();
    auto Thread = std::thread([](){std::cout<<"Excuting  thread"<<std::endl;});
    stop = std::chrono::system_clock::now();

    for(int i = 0 ; i<10000 ; i++)
         y += x*x*x*x*x;

    std::this_thread::sleep_for(std::chrono::milliseconds(100));
    Thread.join();

     std::chrono::duration<double> elapsed_time = stop - start;
     std::cout << "Taken time: " << std::to_string(elapsed_time.count()) << "  "<< std::endl;
    return 0;
}

Compiling:

g++-7 -lpthread  threads.cpp -o out2.out

For Analysis I use this code

import subprocess
import matplotlib.pyplot as plt
import numpy as np

RUNS = 1000
factor = 1000
times = []
for i in range(RUNS):
    p = subprocess.run(["./out2.out"], stdout=subprocess.PIPE)
    line = p.stdout
    times.append(float(line.split()[-1]))
    print(i, RUNS)


times = np.array(times)  * factor
plt.plot(times, "-")
plt.ylabel("time * %d" % factor)
plt.xlabel("#runs")
plt.title("mean %.3f (+- %.3f), min = %.3f, max = %.3f" %
          (np.mean(times), np.std(times), np.min(times), np.max(times)))

plt.savefig("log2.png")

Result

I think I should better ask: How can I reduce this latency and tell my OS, that this thread is really important to me and should have a higher priority?

Answer 1

You are not measuring what you think you are measuring here:

start= std::chrono::system_clock::now();
auto Thread = std::thread([](){std::cout<<"Excuting  thread"<<std::endl;});
stop = std::chrono::system_clock::now();

The stop timestamp only gives you an upper bound on how long it takes main to spawn that thread and it actually tells you nothing about when that thread will start doing any actual work (for that you would need to take a timestamp inside the thread).

Also, system_clock is not the best clock for such measurements on most platforms, you should use steady_clock by default and resort to high_resolution_clock if that one doesn't give you enough precision (but note that you will have to deal with the non-monotonic nature of that clock by yourself then, which can easily mess up the gained precision for you).

As was mentioned already in the comments, spawning a new thread (and thus also constructing a new std::thread) is a very complex and time-consuming operation. If you need high responsiveness, what you want to do is spawn a couple of threads during startup of your program and then have them wait on a std::condition_variable that will get signalled as soon as work for them becomes available. That way you can be sure that on an otherwise idle system a thread will start processing the work that was assigned to him very quickly (immediately is not possible on most systems due to how the operating system schedules threads, but the delay should be well under a millisecond).