Helgrindのサンプルを試す
はじめに
マルチスレッドでプログラムを動かすことが多くある。性能向上のために。Helgrindは、マルチスレッドでのバグを発見するために使用するツールである。今回は、このツールを動かす。簡単なサンプルを使用して。
今回使用したサンプルはこちら。
なお、valgrindのバージョンは3.8.1である。
サンプルソース
下のサンプルソースは、本家からコピーしたもの。
通常、複数のスレッドが同一リソースを使用する場合、排他ロックするべきだが、していない。
したがって、不具合を生む可能性がある。
andre@andre-VirtualBox:~/work/helgrind$ cat main.c
#include <pthread.h>
int var = 0;
void* child_fn ( void* arg ) {
var++; /* Unprotected relative to parent */ /* this is line 6 */ ★リソースvarが競合している。
return NULL;
}
int main ( void ) {
pthread_t child;
pthread_create(&child, NULL, child_fn, NULL);
var++; /* Unprotected relative to child */ /* this is line 13 */ ★リソースvarが競合している。
pthread_join(child, NULL);
return 0;
}
Helgrindを動かす。
Helgrindを動かした結果を下記に示す。
andre@andre-VirtualBox:~/work/helgrind$ valgrind --tool=helgrind ./test_main > no_history.txt 2>&1 andre@andre-VirtualBox:~/work/helgrind$ cat no_history.txt ==11250== Helgrind, a thread error detector ==11250== Copyright (C) 2007-2012, and GNU GPL'd, by OpenWorks LLP et al. ==11250== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info ==11250== Command: ./test_main ==11250== ==11250== ---Thread-Announcement------------------------------------------ ==11250== ==11250== Thread #1 is the program's root thread ★#1 はmainスレッド ==11250== ==11250== ---Thread-Announcement------------------------------------------ ==11250== ==11250== Thread #2 was created ==11250== at 0x41340B8: clone (clone.S:111) ★#2 はchild_fnスレッド（生成されたスレッドである） ==11250== ==11250== ---------------------------------------------------------------- ==11250== ==11250== Possible data race during read of size 4 at 0x804A020 by thread #1 ★#1 は4バイトの競合リソースを読み込んだ。 ==11250== Locks held: none ★ ロック状態：ロックなし ==11250== at 0x8048419: main (main.c:13) ==11250== ==11250== This conflicts with a previous write of size 4 by thread #2 ★#2 は4バイトの競合リソースを読み込んだ。 ==11250== Locks held: none ★ ロック状態：ロックなし ==11250== at 0x80484E0: child_fn (main.c:6) ==11250== by 0x404CD30: start_thread (pthread_create.c:304) ==11250== by 0x41340CD: clone (clone.S:130) ==11250== ==11250== ---------------------------------------------------------------- ==11250== ==11250== Possible data race during write of size 4 at 0x804A020 by thread #1 ★#1 は4バイトの競合リソースに書き込んだ。 ==11250== Locks held: none ★ ロック状態：ロックなし ==11250== at 0x8048419: main (main.c:13) ★ 13行目が競合している ==11250== ==11250== This conflicts with a previous write of size 4 by thread #2 ★#2 は4バイトの競合リソースに書き込んだ。 ==11250== Locks held: none ★ ロック状態：ロックなし ==11250== at 0x80484E0: child_fn (main.c:6) ★ 6行目が競合している ==11250== by 0x404CD30: start_thread (pthread_create.c:304) ==11250== by 0x41340CD: clone (clone.S:130) ==11250== ==11250== ==11250== For counts of detected and suppressed errors, rerun with: -v ==11250== Use --history-level=approx or =none to gain increased speed, at ==11250== the cost of reduced accuracy of conflicting-access information ==11250== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
その他のオプションを試す。
上記Helgrind実行結果の最後4行にあるオプションを試す。
==11250== For counts of detected and suppressed errors, rerun with: ★-v★ ==11250== Use ★--history-level=approx or =none★ to gain increased speed, at ==11250== the cost of reduced accuracy of conflicting-access information ==11250== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
--history-level=approx を試す。
approx は、approximateの略語みたいだ。下記の実行結果を見ると、もう少し詳細な動き(リソースを触った順番)がわかるようだ。
approximate:おおよその，ほぼ正確な
andre@andre-VirtualBox:~/work/helgrind$ valgrind --tool=helgrind --history-level=approx ./test_main >history_approx.txt 2>&1 andre@andre-VirtualBox:~/work/helgrind$ cat history_approx.txt ==11283== Helgrind, a thread error detector ==11283== Copyright (C) 2007-2012, and GNU GPL'd, by OpenWorks LLP et al. ==11283== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info ==11283== Command: ./test_main ==11283== ==11283== ---Thread-Announcement------------------------------------------ ==11283== ==11283== Thread #1 is the program's root thread ★#1 はmainスレッド ==11283== ==11283== ---Thread-Announcement------------------------------------------ ==11283== ==11283== Thread #2 was created ==11283== at 0x41340B8: clone (clone.S:111) ★#2 はchild_fnスレッド ==11283== ==11283== ---------------------------------------------------------------- ==11283== ==11283== Possible data race during read of size 4 at 0x804A020 by thread #1 ==11283== Locks held: none ==11283== at 0x8048419: main (main.c:13) ==11283== This conflicts with a previous access by thread #2, after ★リソースを触った順番(#2 -> #1)が書かれているようだ。 ==11283== (the start of the thread) ==11283== but before ==11283== at 0x4130779: madvise (syscall-template.S:82) ==11283== by 0x41340CD: clone (clone.S:130) ==11283== ==11283== ---------------------------------------------------------------- ==11283== ==11283== Possible data race during write of size 4 at 0x804A020 by thread #1 ==11283== Locks held: none ==11283== at 0x8048419: main (main.c:13) ==11283== This conflicts with a previous access by thread #2, after ★リソースを触った順番(#2 -> #1)が書かれているようだ。 ==11283== (the start of the thread) ==11283== but before ==11283== at 0x4130779: madvise (syscall-template.S:82) ==11283== by 0x41340CD: clone (clone.S:130) ==11283== ==11283== ==11283== For counts of detected and suppressed errors, rerun with: -v ==11283== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
--history-level=none
よくわからない。
andre@andre-VirtualBox:~/work/helgrind$ valgrind --tool=helgrind --history-level=none ./test_main >history_none.txt 2>&1 andre@andre-VirtualBox:~/work/helgrind$ cat history_none.txt ==11299== Helgrind, a thread error detector ==11299== Copyright (C) 2007-2012, and GNU GPL'd, by OpenWorks LLP et al. ==11299== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info ==11299== Command: ./test_main ==11299== ==11299== ---Thread-Announcement------------------------------------------ ==11299== ==11299== Thread #1 is the program's root thread ==11299== ==11299== ---------------------------------------------------------------- ==11299== ==11299== Possible data race during read of size 4 at 0x804A020 by thread #1 ==11299== Locks held: none ==11299== at 0x8048419: main (main.c:13) ==11299== ==11299== ---------------------------------------------------------------- ==11299== ==11299== Possible data race during write of size 4 at 0x804A020 by thread #1 ==11299== Locks held: none ==11299== at 0x8048419: main (main.c:13) ==11299== ==11299== ==11299== For counts of detected and suppressed errors, rerun with: -v ==11299== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
-v を試す。
いろいろな情報が盛り込まれたようだ。OSやgcc のバージョンまで表示されている。
andre@andre-VirtualBox:~/work/helgrind$ valgrind --tool=helgrind -v ./test_main >v.txt 2>&1 andre@andre-VirtualBox:~/work/helgrind$ cat v.txt ==11313== Helgrind, a thread error detector ==11313== Copyright (C) 2007-2012, and GNU GPL'd, by OpenWorks LLP et al. ==11313== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info ==11313== Command: ./test_main ==11313== --11313-- Valgrind options: --11313-- --tool=helgrind --11313-- -v --11313-- Contents of /proc/version: --11313-- Linux version 3.0.0-24-generic (buildd@akateko) (gcc version 4.6.1 (Ubuntu/Linaro 4.6.1-9ubuntu3) ) #40-Ubuntu SMP Tue Jul 24 15:36:59 UTC 2012 --11313-- Arch and hwcaps: X86, x86-sse1-sse2 --11313-- Page sizes: currently 4096, max supported 4096 --11313-- Valgrind library directory: /usr/local/lib/valgrind --11313-- Reading syms from /lib/i386-linux-gnu/ld-2.13.so --11313-- Considering /lib/i386-linux-gnu/ld-2.13.so .. --11313-- .. CRC mismatch (computed 1a2ed160 wanted fece6135) --11313-- Considering /usr/lib/debug/lib/i386-linux-gnu/ld-2.13.so .. --11313-- .. CRC is valid --11313-- Reading syms from /home/andre/work/helgrind/test_main --11313-- Reading syms from /usr/local/lib/valgrind/helgrind-x86-linux --11313-- object doesn't have a dynamic symbol table --11313-- Scheduler: using generic scheduler lock implementation. --11313-- Reading suppressions file: /usr/local/lib/valgrind/default.supp ==11313== embedded gdbserver: reading from /tmp/vgdb-pipe-from-vgdb-to-11313-by-andre-on-??? ==11313== embedded gdbserver: writing to /tmp/vgdb-pipe-to-vgdb-from-11313-by-andre-on-??? ==11313== embedded gdbserver: shared mem /tmp/vgdb-pipe-shared-mem-vgdb-11313-by-andre-on-??? ==11313== ==11313== TO CONTROL THIS PROCESS USING vgdb (which you probably ==11313== don't want to do, unless you know exactly what you're doing, ==11313== or are doing some strange experiment): ==11313== /usr/local/lib/valgrind/../../bin/vgdb --pid=11313 ...command... ==11313== ==11313== TO DEBUG THIS PROCESS USING GDB: start GDB like this ==11313== /path/to/gdb ./test_main ==11313== and then give GDB the following command ==11313== target remote | /usr/local/lib/valgrind/../../bin/vgdb --pid=11313 ==11313== --pid is optional if only one valgrind process is running ==11313== --11313-- Reading syms from /usr/local/lib/valgrind/vgpreload_core-x86-linux.so --11313-- Reading syms from /usr/local/lib/valgrind/vgpreload_helgrind-x86-linux.so ==11313== WARNING: new redirection conflicts with existing -- ignoring it --11313-- old: 0x04016b80 (index ) R-> (0000.0) 0x0402d2dd index --11313-- new: 0x04016b80 (index ) R-> (0000.0) 0x0402d2a0 strchr --11313-- REDIR: 0x4016b80 (index) redirected to 0x402d2dd (index) --11313-- REDIR: 0x4016d40 (strlen) redirected to 0x402d3af (strlen) --11313-- Reading syms from /lib/i386-linux-gnu/libpthread-2.13.so --11313-- Considering /lib/i386-linux-gnu/libpthread-2.13.so .. --11313-- .. CRC mismatch (computed 0b26b884 wanted 21b4acb3) --11313-- Considering /usr/lib/debug/lib/i386-linux-gnu/libpthread-2.13.so .. --11313-- .. CRC is valid ==11313== WARNING: new redirection conflicts with existing -- ignoring it --11313-- old: 0x04051660 (pthread_spin_init ) W-> (0000.0) 0x0402c64a pthread_spin_init --11313-- new: 0x04051660 (pthread_spin_init ) W-> (0000.0) 0x0402c65a pthread_spin_unlock ==11313== WARNING: new redirection conflicts with existing -- ignoring it --11313-- old: 0x04052cf0 (sem_wait@@GLIBC_2.1 ) W-> (0000.0) 0x0402ca8a sem_wait@* --11313-- new: 0x04052cf0 (sem_wait@@GLIBC_2.1 ) W-> (0000.0) 0x0402ca7d sem_wait ==11313== WARNING: new redirection conflicts with existing -- ignoring it --11313-- old: 0x04052d90 (sem_wait@GLIBC_2.0 ) W-> (0000.0) 0x0402ca8a sem_wait@* --11313-- new: 0x04052d90 (sem_wait@GLIBC_2.0 ) W-> (0000.0) 0x0402ca7d sem_wait ==11313== WARNING: new redirection conflicts with existing -- ignoring it --11313-- old: 0x04052f50 (sem_post@@GLIBC_2.1 ) W-> (0000.0) 0x0402caa4 sem_post@* --11313-- new: 0x04052f50 (sem_post@@GLIBC_2.1 ) W-> (0000.0) 0x0402ca97 sem_post ==11313== WARNING: new redirection conflicts with existing -- ignoring it --11313-- old: 0x04052fd4 (sem_post@GLIBC_2.0 ) W-> (0000.0) 0x0402caa4 sem_post@* --11313-- new: 0x04052fd4 (sem_post@GLIBC_2.0 ) W-> (0000.0) 0x0402ca97 sem_post --11313-- Reading syms from /lib/i386-linux-gnu/libc-2.13.so --11313-- Considering /lib/i386-linux-gnu/libc-2.13.so .. --11313-- .. CRC mismatch (computed 365f96ac wanted ff3422fe) --11313-- Considering /usr/lib/debug/lib/i386-linux-gnu/libc-2.13.so .. --11313-- .. CRC is valid ==11313== WARNING: new redirection conflicts with existing -- ignoring it --11313-- old: 0x040d7b40 (index ) R-> (0000.0) 0x0402d263 index --11313-- new: 0x040d7b40 (index ) R-> (0000.0) 0x0402d226 strchr --11313-- REDIR: 0x40d7b40 (index) redirected to 0x402d263 (index) --11313-- REDIR: 0x404cfd0 (pthread_create@@GLIBC_2.1) redirected to 0x402bb75 (pthread_create@*) --11313-- REDIR: 0x40d5420 (calloc) redirected to 0x40281f7 (calloc) --11313-- REDIR: 0x40d48e0 (free) redirected to 0x4028e78 (free) ==11313== ---Thread-Announcement------------------------------------------ ==11313== ==11313== Thread #1 is the program's root thread ==11313== ==11313== ---Thread-Announcement------------------------------------------ ==11313== ==11313== Thread #2 was created ==11313== at 0x41340B8: clone (clone.S:111) ==11313== ==11313== ---------------------------------------------------------------- ==11313== ==11313== Possible data race during read of size 4 at 0x804A020 by thread #1 ==11313== Locks held: none ==11313== at 0x8048419: main (main.c:13) ==11313== ==11313== This conflicts with a previous write of size 4 by thread #2 ==11313== Locks held: none ==11313== at 0x80484E0: child_fn (main.c:6) ==11313== by 0x404CD30: start_thread (pthread_create.c:304) ==11313== by 0x41340CD: clone (clone.S:130) ==11313== ==11313== ---------------------------------------------------------------- ==11313== ==11313== Possible data race during write of size 4 at 0x804A020 by thread #1 ==11313== Locks held: none ==11313== at 0x8048419: main (main.c:13) ==11313== ==11313== This conflicts with a previous write of size 4 by thread #2 ==11313== Locks held: none ==11313== at 0x80484E0: child_fn (main.c:6) ==11313== by 0x404CD30: start_thread (pthread_create.c:304) ==11313== by 0x41340CD: clone (clone.S:130) ==11313== --11313-- REDIR: 0x404dd70 (pthread_join) redirected to 0x402bb95 (pthread_join) --11313-- REDIR: 0x404ed70 (pthread_mutex_lock) redirected to 0x402bdd4 (pthread_mutex_lock) --11313-- REDIR: 0x404fdf0 (pthread_mutex_unlock) redirected to 0x402c1ae (pthread_mutex_unlock) ==11313== ==11313== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0) ==11313== ==11313== 1 errors in context 1 of 2: ==11313== ---------------------------------------------------------------- ==11313== ==11313== Possible data race during write of size 4 at 0x804A020 by thread #1 ==11313== Locks held: none ==11313== at 0x8048419: main (main.c:13) ==11313== ==11313== This conflicts with a previous write of size 4 by thread #2 ==11313== Locks held: none ==11313== at 0x80484E0: child_fn (main.c:6) ==11313== by 0x404CD30: start_thread (pthread_create.c:304) ==11313== by 0x41340CD: clone (clone.S:130) ==11313== ==11313== ==11313== 1 errors in context 2 of 2: ==11313== ---------------------------------------------------------------- ==11313== ==11313== Possible data race during read of size 4 at 0x804A020 by thread #1 ==11313== Locks held: none ==11313== at 0x8048419: main (main.c:13) ==11313== ==11313== This conflicts with a previous write of size 4 by thread #2 ==11313== Locks held: none ==11313== at 0x80484E0: child_fn (main.c:6) ==11313== by 0x404CD30: start_thread (pthread_create.c:304) ==11313== by 0x41340CD: clone (clone.S:130) ==11313== ==11313== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
