You can subscribe to this list here.
| 2002 |
Jan
|
Feb
|
Mar
|
Apr
|
May
|
Jun
|
Jul
|
Aug
|
Sep
(1) |
Oct
(122) |
Nov
(152) |
Dec
(69) |
|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 2003 |
Jan
(6) |
Feb
(25) |
Mar
(73) |
Apr
(82) |
May
(24) |
Jun
(25) |
Jul
(10) |
Aug
(11) |
Sep
(10) |
Oct
(54) |
Nov
(203) |
Dec
(182) |
| 2004 |
Jan
(307) |
Feb
(305) |
Mar
(430) |
Apr
(312) |
May
(187) |
Jun
(342) |
Jul
(487) |
Aug
(637) |
Sep
(336) |
Oct
(373) |
Nov
(441) |
Dec
(210) |
| 2005 |
Jan
(385) |
Feb
(480) |
Mar
(636) |
Apr
(544) |
May
(679) |
Jun
(625) |
Jul
(810) |
Aug
(838) |
Sep
(634) |
Oct
(521) |
Nov
(965) |
Dec
(543) |
| 2006 |
Jan
(494) |
Feb
(431) |
Mar
(546) |
Apr
(411) |
May
(406) |
Jun
(322) |
Jul
(256) |
Aug
(401) |
Sep
(345) |
Oct
(542) |
Nov
(308) |
Dec
(481) |
| 2007 |
Jan
(427) |
Feb
(326) |
Mar
(367) |
Apr
(255) |
May
(244) |
Jun
(204) |
Jul
(223) |
Aug
(231) |
Sep
(354) |
Oct
(374) |
Nov
(497) |
Dec
(362) |
| 2008 |
Jan
(322) |
Feb
(482) |
Mar
(658) |
Apr
(422) |
May
(476) |
Jun
(396) |
Jul
(455) |
Aug
(267) |
Sep
(280) |
Oct
(253) |
Nov
(232) |
Dec
(304) |
| 2009 |
Jan
(486) |
Feb
(470) |
Mar
(458) |
Apr
(423) |
May
(696) |
Jun
(461) |
Jul
(551) |
Aug
(575) |
Sep
(134) |
Oct
(110) |
Nov
(157) |
Dec
(102) |
| 2010 |
Jan
(226) |
Feb
(86) |
Mar
(147) |
Apr
(117) |
May
(107) |
Jun
(203) |
Jul
(193) |
Aug
(238) |
Sep
(300) |
Oct
(246) |
Nov
(23) |
Dec
(75) |
| 2011 |
Jan
(133) |
Feb
(195) |
Mar
(315) |
Apr
(200) |
May
(267) |
Jun
(293) |
Jul
(353) |
Aug
(237) |
Sep
(278) |
Oct
(611) |
Nov
(274) |
Dec
(260) |
| 2012 |
Jan
(303) |
Feb
(391) |
Mar
(417) |
Apr
(441) |
May
(488) |
Jun
(655) |
Jul
(590) |
Aug
(610) |
Sep
(526) |
Oct
(478) |
Nov
(359) |
Dec
(372) |
| 2013 |
Jan
(467) |
Feb
(226) |
Mar
(391) |
Apr
(281) |
May
(299) |
Jun
(252) |
Jul
(311) |
Aug
(352) |
Sep
(481) |
Oct
(571) |
Nov
(222) |
Dec
(231) |
| 2014 |
Jan
(185) |
Feb
(329) |
Mar
(245) |
Apr
(238) |
May
(281) |
Jun
(399) |
Jul
(382) |
Aug
(500) |
Sep
(579) |
Oct
(435) |
Nov
(487) |
Dec
(256) |
| 2015 |
Jan
(338) |
Feb
(357) |
Mar
(330) |
Apr
(294) |
May
(191) |
Jun
(108) |
Jul
(142) |
Aug
(261) |
Sep
(190) |
Oct
(54) |
Nov
(83) |
Dec
(22) |
| 2016 |
Jan
(49) |
Feb
(89) |
Mar
(33) |
Apr
(50) |
May
(27) |
Jun
(34) |
Jul
(53) |
Aug
(53) |
Sep
(98) |
Oct
(206) |
Nov
(93) |
Dec
(53) |
| 2017 |
Jan
(65) |
Feb
(82) |
Mar
(102) |
Apr
(86) |
May
(187) |
Jun
(67) |
Jul
(23) |
Aug
(93) |
Sep
(65) |
Oct
(45) |
Nov
(35) |
Dec
(17) |
| 2018 |
Jan
(26) |
Feb
(35) |
Mar
(38) |
Apr
(32) |
May
(8) |
Jun
(43) |
Jul
(27) |
Aug
(30) |
Sep
(43) |
Oct
(42) |
Nov
(38) |
Dec
(67) |
| 2019 |
Jan
(32) |
Feb
(37) |
Mar
(53) |
Apr
(64) |
May
(49) |
Jun
(18) |
Jul
(14) |
Aug
(53) |
Sep
(25) |
Oct
(30) |
Nov
(49) |
Dec
(31) |
| 2020 |
Jan
(87) |
Feb
(45) |
Mar
(37) |
Apr
(51) |
May
(99) |
Jun
(36) |
Jul
(11) |
Aug
(14) |
Sep
(20) |
Oct
(24) |
Nov
(40) |
Dec
(23) |
| 2021 |
Jan
(14) |
Feb
(53) |
Mar
(85) |
Apr
(15) |
May
(19) |
Jun
(3) |
Jul
(14) |
Aug
(1) |
Sep
(57) |
Oct
(73) |
Nov
(56) |
Dec
(22) |
| 2022 |
Jan
(3) |
Feb
(22) |
Mar
(6) |
Apr
(55) |
May
(46) |
Jun
(39) |
Jul
(15) |
Aug
(9) |
Sep
(11) |
Oct
(34) |
Nov
(20) |
Dec
(36) |
| 2023 |
Jan
(79) |
Feb
(41) |
Mar
(99) |
Apr
(169) |
May
(48) |
Jun
(16) |
Jul
(16) |
Aug
(57) |
Sep
(19) |
Oct
|
Nov
|
Dec
|
| S | M | T | W | T | F | S |
|---|---|---|---|---|---|---|
|
|
|
1
|
2
|
3
(3) |
4
|
5
(7) |
|
6
|
7
|
8
(6) |
9
|
10
|
11
|
12
|
|
13
(1) |
14
|
15
(1) |
16
|
17
(2) |
18
|
19
(1) |
|
20
(2) |
21
(2) |
22
(2) |
23
|
24
|
25
|
26
|
|
27
|
28
(2) |
29
|
30
(1) |
31
|
|
|
|
From: Philippe W. <phi...@so...> - 2019-10-13 15:44:10
|
https://sourceware.org/git/gitweb.cgi?p=valgrind.git;h=83a535e431b28dfa591136fdf08406d1b167b9cc commit 83a535e431b28dfa591136fdf08406d1b167b9cc Author: Philippe Waroquiers <phi...@sk...> Date: Thu Oct 10 21:42:01 2019 +0200 Enhance callgrind option --collect-system. - The command option --collect-systime has been enhanced to specify the unit used to record the elapsed time spent during system calls. The command option now accepts the values no|yes|msec|usec|nsec, where yes is a synonym of msec. When giving the value nsec, the system cpu time of system calls is also recorded. Note that the nsec option is not supported on Darwin. Diff: --- NEWS | 5 ++ callgrind/clo.c | 26 ++++++++- callgrind/docs/cl-manual.xml | 18 +++++- callgrind/dump.c | 15 +++++ callgrind/global.h | 20 +++++-- callgrind/main.c | 130 ++++++++++++++++++++++++++++++++----------- callgrind/sim.c | 9 ++- coregrind/m_libcproc.c | 14 +++++ include/pub_tool_libcproc.h | 10 ++++ 9 files changed, 201 insertions(+), 46 deletions(-) diff --git a/NEWS b/NEWS index 2fde3c7..a2422e8 100644 --- a/NEWS +++ b/NEWS @@ -32,6 +32,11 @@ support for X86/macOS 10.13 and AMD64/macOS 10.13. * Cachegrind: * Callgrind: + - The command option --collect-systime has been enhanced to specify + the unit used to record the elapsed time spent during system calls. + The command option now accepts the values no|yes|msec|usec|nsec, + where yes is a synonym of msec. When giving the value nsec, the + system cpu time of system calls is also recorded. * Massif: diff --git a/callgrind/clo.c b/callgrind/clo.c index b9ccb32..ce15fc8 100644 --- a/callgrind/clo.c +++ b/callgrind/clo.c @@ -523,7 +523,23 @@ Bool CLG_(process_cmd_line_option)(const HChar* arg) else if VG_INT_CLO( arg, "--dump-every-bb", CLG_(clo).dump_every_bb) {} else if VG_BOOL_CLO(arg, "--collect-alloc", CLG_(clo).collect_alloc) {} - else if VG_BOOL_CLO(arg, "--collect-systime", CLG_(clo).collect_systime) {} + else if VG_XACT_CLO(arg, "--collect-systime=no", + CLG_(clo).collect_systime, systime_no) {} + else if VG_XACT_CLO(arg, "--collect-systime=msec", + CLG_(clo).collect_systime, systime_msec) {} + else if VG_XACT_CLO(arg, "--collect-systime=yes", /* backward compatibility. */ + CLG_(clo).collect_systime, systime_msec) {} + else if VG_XACT_CLO(arg, "--collect-systime=usec", + CLG_(clo).collect_systime, systime_usec) {} + else if VG_XACT_CLO(arg, "--collect-systime=nsec", + CLG_(clo).collect_systime, systime_nsec) { +# if defined(VGO_darwin) + VG_(fmsg_bad_option) + (arg, + "--collect-systime=nsec not supported on darwin\n"); +# endif + } + else if VG_BOOL_CLO(arg, "--collect-bus", CLG_(clo).collect_bus) {} /* for option compatibility with cachegrind */ else if VG_BOOL_CLO(arg, "--cache-sim", CLG_(clo).simulate_cache) {} @@ -580,7 +596,11 @@ void CLG_(print_usage)(void) #if CLG_EXPERIMENTAL " --collect-alloc=no|yes Collect memory allocation info? [no]\n" #endif -" --collect-systime=no|yes Collect system call time info? [no]\n" +" --collect-systime=no|yes|msec|usec|nsec Collect system call time info? [no]\n" +" no Do not collect system call time info.\n" +" msec|yes Collect syscount, syscall elapsed time (milli-seconds).\n" +" usec Collect syscount, syscall elapsed time (micro-seconds).\n" +" nsec Collect syscount, syscall elapsed and syscall cpu time (nano-seconds).\n" "\n cost entity separation options:\n" " --separate-threads=no|yes Separate data per thread [no]\n" @@ -646,7 +666,7 @@ void CLG_(set_clo_defaults)(void) CLG_(clo).collect_atstart = True; CLG_(clo).collect_jumps = False; CLG_(clo).collect_alloc = False; - CLG_(clo).collect_systime = False; + CLG_(clo).collect_systime = systime_no; CLG_(clo).collect_bus = False; CLG_(clo).skip_plt = True; diff --git a/callgrind/docs/cl-manual.xml b/callgrind/docs/cl-manual.xml index c1eb6ea..31fcbaa 100644 --- a/callgrind/docs/cl-manual.xml +++ b/callgrind/docs/cl-manual.xml @@ -800,11 +800,25 @@ Also see <xref linkend="cl-manual.limits"/>.</para> <varlistentry id="opt.collect-systime" xreflabel="--collect-systime"> <term> - <option><![CDATA[--collect-systime=<no|yes> [default: no] ]]></option> + <option><![CDATA[--collect-systime=<no|yes|msec|usec|nsec> [default: no] ]]></option> </term> <listitem> <para>This specifies whether information for system call times - should be collected.</para> + should be collected.</para> + <para>The value <computeroutput>no</computeroutput> indicates to record + no system call information.</para> + <para>The other values indicate to record the number of system calls + done (sysCount event) and the elapsed time (sysTime event) spent + in system calls. + The <computeroutput>--collect-systime</computeroutput> value gives + the unit used for sysTime : milli seconds, micro seconds or nano + seconds. With the value <computeroutput>nsec</computeroutput>, + callgrind also records the cpu time spent during system calls + (sysCpuTime).</para> + <para>The value <computeroutput>yes</computeroutput> is a synonym + of <computeroutput>msec</computeroutput>. + The value <computeroutput>nsec</computeroutput> is not supported + on Darwin.</para> </listitem> </varlistentry> diff --git a/callgrind/dump.c b/callgrind/dump.c index e57abfe..f95bdb5 100644 --- a/callgrind/dump.c +++ b/callgrind/dump.c @@ -1305,6 +1305,21 @@ static VgFile *new_dumpfile(int tid, const HChar* trigger) HChar *evmap = CLG_(eventmapping_as_string)(CLG_(dumpmap)); VG_(fprintf)(fp, "events: %s\n", evmap); VG_(free)(evmap); + switch (CLG_(clo).collect_systime) { + case systime_no: break; + case systime_msec: + VG_(fprintf)(fp, "event: sysTime : sysTime (elapsed ms)\n"); + break; + case systime_usec: + VG_(fprintf)(fp, "event: sysTime : sysTime (elapsed us)\n"); + break; + case systime_nsec: + VG_(fprintf)(fp, "event: sysTime : sysTime (elapsed ns)\n"); + VG_(fprintf)(fp, "event: sysCpuTime : sysCpuTime (system cpu ns)\n"); + break; + default: + tl_assert(0); + } /* summary lines */ sum = CLG_(get_eventset_cost)( CLG_(sets).full ); diff --git a/callgrind/global.h b/callgrind/global.h index 4fd8f22..4a988a4 100644 --- a/callgrind/global.h +++ b/callgrind/global.h @@ -58,11 +58,6 @@ /* Enable experimental features? */ #define CLG_EXPERIMENTAL 0 -/* Syscall Timing in microseconds? - * (define to 0 if you get compile errors) */ -#define CLG_MICROSYSTIME 0 - - /*------------------------------------------------------------*/ /*--- Command line options ---*/ @@ -70,6 +65,19 @@ #define DEFAULT_OUTFORMAT "callgrind.out.%p" +/* If and how to collect syscall time. + systime_no : do not collect systime + systime_msec : collect syscount, systime elapsed, milli second precision. + systime_usec : collect syscount, systime elapsed, micro second precision. + systime_nsec : collect syscount, systime elapsed, systime cpu, nano second + precision. */ +typedef enum { + systime_no, + systime_msec, + systime_usec, + systime_nsec +} Collect_Systime; + typedef struct _CommandLineOptions CommandLineOptions; struct _CommandLineOptions { @@ -100,7 +108,7 @@ struct _CommandLineOptions { Bool collect_jumps; /* Collect (cond.) jumps in functions ? */ Bool collect_alloc; /* Collect size of allocated memory */ - Bool collect_systime; /* Collect time for system calls */ + Collect_Systime collect_systime; /* Collect time for system calls */ Bool collect_bus; /* Collect global bus events */ diff --git a/callgrind/main.c b/callgrind/main.c index 5f88fb0..47369d1 100644 --- a/callgrind/main.c +++ b/callgrind/main.c @@ -1697,60 +1697,115 @@ Bool CLG_(handle_client_request)(ThreadId tid, UWord *args, UWord *ret) } -/* Syscall Timing */ +/* Syscall Timing. syscalltime[tid] is the time at which thread tid last + started a syscall. */ + +/* struct vki_timespec syscalltime[VG_N_THREADS]; + Whatever the syscall we use to measure the syscall time, we convert to + seconds and nanoseconds. */ +struct vki_timespec *syscalltime; +struct vki_timespec *syscallcputime; -/* struct timeval syscalltime[VG_N_THREADS]; */ -#if CLG_MICROSYSTIME -ULong *syscalltime; -#else -UInt *syscalltime; -#endif + +static +void collect_time (struct vki_timespec *systime, struct vki_timespec *syscputime) +{ + switch (CLG_(clo).collect_systime) { + case systime_no: tl_assert (0); + case systime_msec: { + UInt ms_timer = VG_(read_millisecond_timer)(); + systime->tv_sec = ms_timer / 1000; + systime->tv_nsec = (ms_timer % 1000) * 1000000L; + break; + } + case systime_usec: { + struct vki_timeval tv_now; + VG_(gettimeofday)(&tv_now, NULL); + systime->tv_sec = tv_now.tv_sec; + systime->tv_nsec = tv_now.tv_usec * 1000; + break; + } + case systime_nsec: +# if defined(VGO_linux) || defined(VGO_solaris) + VG_(clock_gettime)(systime, VKI_CLOCK_MONOTONIC); + VG_(clock_gettime)(syscputime, VKI_CLOCK_THREAD_CPUTIME_ID); + +# elif defined(VGO_darwin) + tl_assert(0); +# else +# error "Unknown OS" +# endif + break; + } +} static void CLG_(pre_syscalltime)(ThreadId tid, UInt syscallno, UWord* args, UInt nArgs) { - if (CLG_(clo).collect_systime) { -#if CLG_MICROSYSTIME - struct vki_timeval tv_now; - VG_(gettimeofday)(&tv_now, NULL); - syscalltime[tid] = tv_now.tv_sec * 1000000ULL + tv_now.tv_usec; -#else - syscalltime[tid] = VG_(read_millisecond_timer)(); -#endif + collect_time(&syscalltime[tid], + CLG_(clo).collect_systime == systime_nsec ? &syscallcputime[tid] : NULL); +} + +/* Returns "after - before" in the unit as specified by --collect-systime. + after is supposed to be >= before, and tv_nsec must be >= 0 and < One_Second_In_Nsec. */ +static +ULong vki_timespec_diff (struct vki_timespec after, struct vki_timespec before) +{ + vki_time_t diff_sec = after.tv_sec - before.tv_sec; + long diff_nsec = after.tv_nsec - before.tv_nsec; + ULong nsec_factor; // factor to convert the desired unit into nsec. + + if (diff_nsec < 0) { + diff_sec--; + diff_nsec += 1000000000ULL; + } + switch (CLG_(clo).collect_systime) { + case systime_no: tl_assert (0); + case systime_msec: nsec_factor = 1000000ULL; break; + case systime_usec: nsec_factor = 1000ULL; break; + case systime_nsec: nsec_factor = 1ULL; break; + default: tl_assert(0); } + return ((ULong) diff_sec * 1000000000ULL + diff_nsec) / nsec_factor; } static void CLG_(post_syscalltime)(ThreadId tid, UInt syscallno, UWord* args, UInt nArgs, SysRes res) { - if (CLG_(clo).collect_systime && - CLG_(current_state).bbcc) { - Int o; -#if CLG_MICROSYSTIME - struct vki_timeval tv_now; + if (CLG_(current_state).bbcc) { + Int o; + struct vki_timespec ts_now; + struct vki_timespec ts_cpunow; ULong diff; - - VG_(gettimeofday)(&tv_now, NULL); - diff = (tv_now.tv_sec * 1000000ULL + tv_now.tv_usec) - syscalltime[tid]; -#else - UInt diff = VG_(read_millisecond_timer)() - syscalltime[tid]; -#endif - /* offset o is for "SysCount", o+1 for "SysTime" */ + collect_time(&ts_now, + CLG_(clo).collect_systime == systime_nsec ? &ts_cpunow : NULL); + + diff = vki_timespec_diff (ts_now, syscalltime[tid]); + + /* offset o is for "SysCount", o+1 for "SysTime", + o+2 is (optionally) "SysCpuTime". */ o = fullOffset(EG_SYS); CLG_ASSERT(o>=0); CLG_DEBUG(0," Time (Off %d) for Syscall %u: %llu\n", o, syscallno, - (ULong)diff); - - CLG_(current_state).cost[o] ++; - CLG_(current_state).cost[o+1] += diff; + diff); + if (!CLG_(current_state).bbcc->skipped) CLG_(init_cost_lz)(CLG_(sets).full, &(CLG_(current_state).bbcc->skipped)); + CLG_(current_state).cost[o] ++; + CLG_(current_state).cost[o+1] += diff; CLG_(current_state).bbcc->skipped[o] ++; CLG_(current_state).bbcc->skipped[o+1] += diff; + if (CLG_(clo).collect_systime == systime_nsec) { + diff = vki_timespec_diff (ts_cpunow, syscallcputime[tid]); + CLG_DEBUG(0," SysCpuTime (Off %d) for Syscall %u: %llu\n", o+2, syscallno, + diff); + CLG_(current_state).cost[o+2] += diff; + CLG_(current_state).bbcc->skipped[o+2] += diff; + } } } @@ -1973,13 +2028,22 @@ void CLG_(post_clo_init)(void) "sp-at-mem-access\n"); } - if (CLG_(clo).collect_systime) { + if (CLG_(clo).collect_systime != systime_no) { VG_(needs_syscall_wrapper)(CLG_(pre_syscalltime), CLG_(post_syscalltime)); syscalltime = CLG_MALLOC("cl.main.pci.1", VG_N_THREADS * sizeof syscalltime[0]); for (UInt i = 0; i < VG_N_THREADS; ++i) { - syscalltime[i] = 0; + syscalltime[i].tv_sec = 0; + syscalltime[i].tv_nsec = 0; + } + if (CLG_(clo).collect_systime == systime_nsec) { + syscallcputime = CLG_MALLOC("cl.main.pci.2", + VG_N_THREADS * sizeof syscallcputime[0]); + for (UInt i = 0; i < VG_N_THREADS; ++i) { + syscallcputime[i].tv_sec = 0; + syscallcputime[i].tv_nsec = 0; + } } } diff --git a/callgrind/sim.c b/callgrind/sim.c index 521bfb8..104c634 100644 --- a/callgrind/sim.c +++ b/callgrind/sim.c @@ -1625,8 +1625,12 @@ void CLG_(init_eventsets)() if (CLG_(clo).collect_alloc) CLG_(register_event_group2)(EG_ALLOC, "allocCount", "allocSize"); - if (CLG_(clo).collect_systime) - CLG_(register_event_group2)(EG_SYS, "sysCount", "sysTime"); + if (CLG_(clo).collect_systime != systime_no) { + if (CLG_(clo).collect_systime == systime_nsec) + CLG_(register_event_group3)(EG_SYS, "sysCount", "sysTime", "sysCpuTime"); + else + CLG_(register_event_group2)(EG_SYS, "sysCount", "sysTime"); + } // event set used as base for instruction self cost CLG_(sets).base = CLG_(get_event_set2)(EG_USE, EG_IR); @@ -1670,6 +1674,7 @@ void CLG_(init_eventsets)() CLG_(append_event)(CLG_(dumpmap), "allocSize"); CLG_(append_event)(CLG_(dumpmap), "sysCount"); CLG_(append_event)(CLG_(dumpmap), "sysTime"); + CLG_(append_event)(CLG_(dumpmap), "sysCpuTime"); } diff --git a/coregrind/m_libcproc.c b/coregrind/m_libcproc.c index d6577ba..fc5da96 100644 --- a/coregrind/m_libcproc.c +++ b/coregrind/m_libcproc.c @@ -962,6 +962,20 @@ UInt VG_(read_millisecond_timer) ( void ) return (now - base) / 1000; } +# if defined(VGO_linux) || defined(VGO_solaris) +void VG_(clock_gettime) ( struct vki_timespec *ts, vki_clockid_t clk_id ) +{ + SysRes res; + res = VG_(do_syscall2)(__NR_clock_gettime, clk_id, + (UWord)ts); + vg_assert (sr_isError(res) == 0); +} +# elif defined(VGO_darwin) + /* See pub_tool_libcproc.h */ +# else +# error "Unknown OS" +# endif + Int VG_(gettimeofday)(struct vki_timeval *tv, struct vki_timezone *tz) { SysRes res; diff --git a/include/pub_tool_libcproc.h b/include/pub_tool_libcproc.h index f90af82..73d7eca 100644 --- a/include/pub_tool_libcproc.h +++ b/include/pub_tool_libcproc.h @@ -103,6 +103,16 @@ extern UInt VG_(read_millisecond_timer) ( void ); extern Int VG_(gettimeofday)(struct vki_timeval *tv, struct vki_timezone *tz); +# if defined(VGO_linux) || defined(VGO_solaris) +/* Get the clock value as specified by clk_id. Asserts if unsuccesful. */ +extern void VG_(clock_gettime)(struct vki_timespec *ts, vki_clockid_t clk_id); +# elif defined(VGO_darwin) + /* It seems clock_gettime is only available on recent Darwin versions. + For the moment, let's assume it is not available. */ +# else +# error "Unknown OS" +# endif + // Returns the number of milliseconds of user cpu time we have used, // as reported by 'getrusage'. extern UInt VG_(get_user_milliseconds)(void); |