рассчитать среднее время выполнения с помощью pthread со странными результатами - PullRequest
0 голосов
/ 10 января 2019

Итак, я написал программу, которая вычисляет среднее время выполнения другой программы (имя получено из аргумента командной строки) с 20 пробными запусками. Я использовал pthread для ускорения работы программы (параллельный запуск нескольких трасс). Однако, хотя однопоточная версия работала отлично, многопоточная версия дает мне действительно странный результат. Вот код:

main.cpp

#include <iostream>
#include <chrono>
#include <pthread.h>
using namespace std;
using namespace std::chrono;

struct Thread_arg{ // struct to hold the arguments
    int a; // index of which element for runtime
    char *b; // name of the program to run
};

double runtime[20]; // store all 20 runtime

pthread_mutex_t mutex1 = PTHREAD_MUTEX_INITIALIZER;

void* run_program(void *input){
    auto *arg = (Thread_arg *) input;

    high_resolution_clock::time_point t1 = high_resolution_clock::now();
    system(arg->b);
    high_resolution_clock::time_point t2 = high_resolution_clock::now();

    auto duration = duration_cast<microseconds>( t2 - t1 ).count();
    runtime[arg->a] = duration;

    pthread_mutex_lock(&mutex1);
    cout << " Runtime: " << duration << "\u00B5s" << endl;
    pthread_mutex_unlock(&mutex1);

    return nullptr;
}

int main(int argc, char** argv){
    if(argc != 2){
        if(argc > 2){
            cout << "Too many arguments, you only need 1" << endl;
        }else if(argc < 2){
            cout << "You need 1 argument" << endl;
        }
        exit(410);
    }

    // format name of the program
    string program = "./";
    program += argv[1];

    int n = (int) program.length();

    char char_array[n+1];

    strcpy(char_array, program.c_str());

    // start testing, get average of 20 test
    pthread_t threads[20]; // create threads

    for(int i = 0; i < 20; i++){
        struct Thread_arg *arg = (struct Thread_arg *)malloc(sizeof(struct Thread_arg)); // arguments in struct
        arg->b = char_array; // load struct
        arg->a = i;
        pthread_create(&threads[i], nullptr, run_program, (void *)arg); // launch thread
    }

    // join threads
    for (auto &thread : threads){
        pthread_join(thread, nullptr);
    }

    // calculate average
    double total_time = 0;
    for (double &i : runtime){
        total_time += i;
    }
    double runtime_ave = total_time/20; 

    cout << "************************************************************" << endl;
    cout <<"||| " << "Average runtime for program " << program << " is: " << runtime_ave << "\u00B5s" << " |||" << endl;
    cout << "************************************************************" << endl;
}

выполнить с g ++ -o runtime main.cpp

test.cpp

#include <unistd.h>
#include <iostream>

int main(){
    usleep(1000000);
    std::cout << "Demo Finished";
    return 0;
}

соответствует g ++ -o test test.cpp

запуск с тестом ./runtime

Правильный результат должен быть:

Demo Finished   Runtime: 1.01159e+06µs
Demo Finished   Runtime: 1.01040e+06µs
Demo Finished   Runtime: 1.01208e+06µs
Demo Finished   Runtime: 1.00862e+06µs
Demo Finished   Runtime: 1.0065e+06µs
Demo Finished   Runtime: 1.00863e+06µs
Demo Finished   Runtime: 1.01288e+06µs
Demo Finished   Runtime: 1.01039e+06µs
Demo Finished   Runtime: 1.01221e+06µs
Demo Finished   Runtime: 1.00687e+06µs
Demo Finished   Runtime: 1.01136e+06µs
Demo Finished   Runtime: 1.00874e+06µs
Demo Finished   Runtime: 1.03106e+06µs
Demo Finished   Runtime: 1.00714e+06µs
Demo Finished   Runtime: 1.00679e+06µs
Demo Finished   Runtime: 1.01873e+06µs
Demo Finished   Runtime: 1.01086e+06µs
Demo Finished   Runtime: 1.01146e+06µs
Demo Finished   Runtime: 1.01179e+06µs
Demo Finished   Runtime: 1.00995e+06µs
************************************************************
||| Average runtime for program ./demo is: 1.0114e+06µs |||
************************************************************

Но вместо этого я получил:

Demo Finished Runtime: 1011435µs
Demo Finished Runtime: 2024995µs
Demo Finished Runtime: 3033430µs
Demo Finished Runtime: 4039988µs
Demo Finished Runtime: 5046514µs
Demo Finished Runtime: 6059725µs
Demo Finished Runtime: 7071353µs
Demo Finished Runtime: 8081074µs
Demo Finished Runtime: 9088289µs
Demo Finished Runtime: 10099950µs
Demo Finished Runtime: 11108043µs
Demo Finished Runtime: 12126147µs
Demo Finished Runtime: 13134197µs
Demo Finished Runtime: 14151540µs
Demo Finished Runtime: 15161500µs
Demo Finished Runtime: 16173660µs
Demo Finished Runtime: 17186823µs
Demo Finished Runtime: 18194055µs
Demo Finished Runtime: 19206132µs
Demo Finished Runtime: 20217351µs
************************************************************
||| Average runtime for program ./test is: 1.06108e+07µs |||
************************************************************

Как видите, время приближается. Есть идеи почему? Я не думаю, что это мьютекс, так как общедоступной переменной является массив, и ни одна из них не получит доступ к той же самой.

Спасибо заранее.

UPDATE: Попробовав его на виртуальной машине с Ubuntu, я получил правильный результат с тем же кодом. Тем не менее, я до сих пор не совсем понимаю, почему результат трассировки на MacOS увеличивается. Я думаю, что это может быть связано с system() или с тем фактом, что в MacOS g ++ на самом деле является clang ++. Я буду делать еще один эксперимент, чтобы изолировать проблему. Однако, если вы знаете, что происходит, очень важно, если вы можете дать мне точный ответ.

Большое спасибо @William Miller и @alk за помощь в разделе комментариев.

1 Ответ

0 голосов
/ 11 января 2019

Я могу воспроизвести его на Mac. Причина в том, что system() блокируется, если он уже запущен в другом потоке. Внутренне блокирует мьютекс.

Все потоки исполняются now(), но тогда только одна программа попадает в exec. Таким образом, эта программа получает время выполнения 1 секунды. Затем запускается второй, но его время включает время, затраченное первым, и т. Д.

Вы можете подтвердить это, добавив:

20     cout << "before system()" << endl;
21     system(arg->b);
22     cout << "after system()" << endl;

Итак, самый простой ответ: потому что системная библиотека, поставляемая с вашим компилятором / системой, имеет мьютекс, чтобы сделать system () поточно-ориентированным.

Вы можете увидеть ожидание этого мьютекса в ожидающих потоках внутри system():

* thread #4
  * frame #0: 0x00007fff6c8eda46 libsystem_kernel.dylib`__psynch_mutexwait + 10
    frame #1: 0x00007fff6cab5b9d libsystem_pthread.dylib`_pthread_mutex_lock_wait + 83
    frame #2: 0x00007fff6cab34c8 libsystem_pthread.dylib`_pthread_mutex_lock_slow + 253
    frame #3: 0x00007fff6c8688d1 libsystem_c.dylib`system + 183
    frame #4: 0x0000000100000e11 runtime`run_program(input=0x00000001003000a0) at main.cpp:21
    frame #5: 0x00007fff6cab5661 libsystem_pthread.dylib`_pthread_body + 340
    frame #6: 0x00007fff6cab550d libsystem_pthread.dylib`_pthread_start + 377
    frame #7: 0x00007fff6cab4bf9 libsystem_pthread.dylib`thread_start + 13

тогда как запущенный ожидает завершения работающей программы:

* thread #2
  * frame #0: 0x00007fff6c8ee242 libsystem_kernel.dylib`__wait4_nocancel + 10
    frame #1: 0x00007fff6c8689de libsystem_c.dylib`system + 452
    frame #2: 0x0000000100000e11 runtime`run_program(input=0x0000000100300080) at main.cpp:21
    frame #3: 0x00007fff6cab5661 libsystem_pthread.dylib`_pthread_body + 340
    frame #4: 0x00007fff6cab550d libsystem_pthread.dylib`_pthread_start + 377
    frame #5: 0x00007fff6cab4bf9 libsystem_pthread.dylib`thread_start + 13
Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...