zenithsiz/ftmemsim-valgrind
1
0
Fork 0
mirror of https://github.com/Zenithsiz/ftmemsim-valgrind.git synced 2026-02-03 10:05:29 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

Add a simple progress-reporting facility.

Browse Source 
Fixes BZ#384633.
Patch by: Julian Seward <jseward@acm.org>
This commit is contained in:
Ivo Raisr 2018-01-19 16:12:34 +00:00
parent ea1c229392
commit bd077baa71
11 changed files with 171 additions and 2 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
NEWS
View File

@ -72,6 +72,7 @@ where XXXXXX is the bug number as listed below.
384096 Mention AddrCheck at Memcheck's command line option --undef-value-errors=no
384526 reduce number of spill instructions generated by VEX register allocator v3
384584 Callee saved registers listed first for AMD64, X86, and PPC architectures
384633 Add a simple progress-reporting facility
384987 VEX register allocator: allocate caller-save registers for short lived vregs
385182 PPC64 is missing support for the DSCR
385207 PPC64, generate_store_FPRF() generates too many Iops

34
coregrind/m_libcproc.c
View File

@ -958,6 +958,40 @@ Int VG_(gettimeofday)(struct vki_timeval *tv, struct vki_timezone *tz)
return -1;
}
UInt VG_(get_user_milliseconds)(void)
{
UInt res = 0;
# if defined(VGO_linux)
{
struct vki_rusage ru;
VG_(memset)(&ru, 0, sizeof(ru));
SysRes sr = VG_(do_syscall2)(__NR_getrusage, VKI_RUSAGE_SELF, (UWord)&ru);
if (!sr_isError(sr)) {
res = ru.ru_utime.tv_sec * 1000 + ru.ru_utime.tv_usec / 1000;
}
}
# elif defined(VGO_solaris)
{
struct vki_rusage ru;
VG_(memset)(&ru, 0, sizeof(ru));
SysRes sr = VG_(do_syscall2)(__NR_rusagesys, VKI__RUSAGESYS_GETRUSAGE,
(UWord) &ru);
if (!sr_isError(sr)) {
res = ru.ru_utime.tv_sec * 1000 + ru.ru_utime.tv_usec / 1000;
}
}
# elif defined(VGO_darwin)
res = 0;
# else
# error "Unknown OS"
# endif
return res;
}
/* ---------------------------------------------------------------------
atfork()

4
coregrind/m_main.c
View File

@ -258,6 +258,8 @@ static void usage_NORETURN ( Bool debug_help )
" heap blocks allocated for Valgrind internal use (in bytes) [4]\n"
" --wait-for-gdb=yes|no pause on startup to wait for gdb attach\n"
" --sym-offsets=yes|no show syms in form 'name+offset'? [no]\n"
" --progress-interval=<number> report progress every <number>\n"
" CPU seconds [0, meaning disabled]\n"
" --command-line-only=no|yes only use command line options [no]\n"
"\n"
" Vex options for all Valgrind tools:\n"
@ -671,6 +673,8 @@ void main_process_cmd_line_options( void )
else if VG_BOOL_CLO(arg, "--trace-syscalls", VG_(clo_trace_syscalls)) {}
else if VG_BOOL_CLO(arg, "--wait-for-gdb", VG_(clo_wait_for_gdb)) {}
else if VG_BOOL_CLO(arg, "--sym-offsets", VG_(clo_sym_offsets)) {}
else if VG_BINT_CLO(arg, "--progress-interval",
VG_(clo_progress_interval), 0, 3600) {}
else if VG_BOOL_CLO(arg, "--read-inline-info", VG_(clo_read_inline_info)) {}
else if VG_BOOL_CLO(arg, "--read-var-info", VG_(clo_read_var_info)) {}

2
coregrind/m_options.c
View File

@ -110,6 +110,8 @@ enum FairSchedType
VG_(clo_fair_sched) = disable_fair_sched;
Bool VG_(clo_trace_sched) = False;
Bool VG_(clo_profile_heap) = False;
UInt VG_(clo_progress_interval) = 0; /* in seconds, 1 .. 3600,
or 0 == disabled */
Int VG_(clo_core_redzone_size) = CORE_REDZONE_DEFAULT_SZB;
// A value != -1 overrides the tool-specific value
// VG_(needs_malloc_replacement).tool_client_redzone_szB

55
coregrind/m_scheduler/scheduler.c
View File

@ -172,6 +172,56 @@ static struct sched_lock *the_BigLock;
Helper functions for the scheduler.
------------------------------------------------------------------ */
static void maybe_progress_report ( UInt reporting_interval_seconds )
{
/* This is when the next report is due, in user cpu milliseconds since
process start. This is a global variable so this won't be thread-safe
if Valgrind is ever made multithreaded. For now it's fine. */
static UInt next_report_due_at = 0;
/* First of all, figure out whether another report is due. It
probably isn't. */
UInt user_ms = VG_(get_user_milliseconds)();
if (LIKELY(user_ms < next_report_due_at))
return;
Bool first_ever_call = next_report_due_at == 0;
/* A report is due. First, though, set the time for the next report. */
next_report_due_at += 1000 * reporting_interval_seconds;
/* If it's been an excessively long time since the last check, we
might have gone more than one reporting interval forward. Guard
against that. */
while (next_report_due_at <= user_ms)
next_report_due_at += 1000 * reporting_interval_seconds;
/* Also we don't want to report anything on the first call, but we
have to wait till this point to leave, so that we set up the
next-call time correctly. */
if (first_ever_call)
return;
/* Print the report. */
UInt user_cpu_seconds = user_ms / 1000;
UInt wallclock_seconds = VG_(read_millisecond_timer)() / 1000;
Double millionEvCs = ((Double)bbs_done) / 1000000.0;
Double thousandTIns = ((Double)VG_(get_bbs_translated)()) / 1000.0;
Double thousandTOuts = ((Double)VG_(get_bbs_discarded_or_dumped)()) / 1000.0;
UInt nThreads = VG_(count_living_threads)();
if (VG_(clo_verbosity) > 0) {
VG_(dmsg)("PROGRESS: U %'us, W %'us, %.1f%% CPU, EvC %.2fM, "
"TIn %.1fk, TOut %.1fk, #thr %u\n",
user_cpu_seconds, wallclock_seconds,
100.0
* (Double)(user_cpu_seconds)
/ (Double)(wallclock_seconds == 0 ? 1 : wallclock_seconds),
millionEvCs,
thousandTIns, thousandTOuts, nThreads);
}
}
static
void print_sched_event ( ThreadId tid, const HChar* what )
{
@ -1315,6 +1365,11 @@ VgSchedReturnCode VG_(scheduler) ( ThreadId tid )
scheduler_sanity(tid);
VG_(sanity_check_general)(False);
/* Possibly make a progress report */
if (UNLIKELY(VG_(clo_progress_interval) > 0)) {
maybe_progress_report( VG_(clo_progress_interval) );
}
/* Look for any pending signals for this thread, and set them up
for delivery */
VG_(poll_signals)(tid);

5
coregrind/m_transtab.c
View File

@ -2565,6 +2565,11 @@ UInt VG_(get_bbs_translated) ( void )
return n_in_count;
}
UInt VG_(get_bbs_discarded_or_dumped) ( void )
{
return n_disc_count + n_dump_count;
}
void VG_(print_tt_tc_stats) ( void )
{
VG_(message)(Vg_DebugMsg,

2
coregrind/pub_core_options.h
View File

@ -201,6 +201,8 @@ extern enum FairSchedType VG_(clo_fair_sched);
extern Bool VG_(clo_trace_sched);
/* DEBUG: do heap profiling? default: NO */
extern Bool VG_(clo_profile_heap);
// DEBUG: report progress every N seconds (1 .. 3600)
extern UInt VG_(clo_progress_interval);
#define MAX_REDZONE_SZB 128
// Maximum for the default values for core arenas and for client
// arena given by the tool.

54
docs/xml/manual-core.xml
View File

@ -2581,6 +2581,60 @@ need to use them.</para>
</listitem>
</varlistentry>
<varlistentry id="opt.progress-interval" xreflabel="--progress-interval">
<term>
<option><![CDATA[--progress-interval=<number> [default: 0, meaning 'disabled'] ]]></option>
</term>
<listitem>
<para>This is an enhancement to Valgrind's debugging output. It is
unlikely to be of interest to end users.</para>
<para>When <varname>number</varname> is set to a non-zero value,
Valgrind will print a one-line progress summary
every <varname>number</varname> seconds. Valid settings
for <varname>number</varname> are between 0 and 3600
inclusive. Here's some example output
with <varname>number</varname>
set to 10:
<programlisting><![CDATA[
PROGRESS: U 110s, W 113s, 97.3% CPU, EvC 414.79M, TIn 616.7k, TOut 0.5k, #thr 67
PROGRESS: U 120s, W 124s, 96.8% CPU, EvC 505.27M, TIn 636.6k, TOut 3.0k, #thr 64
PROGRESS: U 130s, W 134s, 97.0% CPU, EvC 574.90M, TIn 657.5k, TOut 3.0k, #thr 63
]]></programlisting>
Each line shows:
<itemizedlist>
<listitem><varname>U</varname>: total user time</listitem>
<listitem><varname>W</varname>: total wallclock time</listitem>
<listitem><varname>CPU</varname>: overall average cpu use</listitem>
<listitem><varname>EvC</varname>: number of event checks. An event
check is a backwards branch in the simulated program, so this is a
measure of forward progress of the program</listitem>
<listitem><varname>TIn</varname>: number of code blocks instrumented
by the JIT</listitem>
<listitem><varname>TOut</varname>: number of instrumented code
blocks that have been thrown away</listitem>
<listitem><varname>#thr</varname>: number of threads in the
program</listitem>
</itemizedlist>
From the progress of these, it is possible to observe:
<itemizedlist>
<listitem>when the program is compute bound (<varname>TIn</varname>
rises slowly, <varname>EvC</varname> rises rapidly)</listitem>
<listitem>when the program is in a spinloop
(<varname>TIn</varname>/<varname>TOut</varname>
fixed, <varname>EvC</varname> rises rapidly)</listitem>
<listitem>when the program is JIT-bound (<varname>TIn</varname>
rises rapidly)</listitem>
<listitem>when the program is rapidly discarding code
(<varname>TOut</varname> rises rapidly)</listitem>
<listitem>when the program is about to achieve some expected state
(<varname>EvC</varname> arrives at some value you
expect)</listitem>
<listitem> when the program is idling (<varname>U</varname> rises
more slowly than <varname>W</varname>)</listitem>
</itemizedlist>
</para>
</listitem>
</varlistentry>
</variablelist>
<!-- end of xi:include in the manpage -->

9
include/pub_tool_libcproc.h
View File

@ -98,12 +98,17 @@ extern Int VG_(getegid) ( void );
Timing
------------------------------------------------------------------ */
// Returns the number of milliseconds passed since the progam started
// Returns the number of milliseconds passed since the program started
// (roughly; it gets initialised partway through Valgrind's initialisation
// steps).
// steps). This is wallclock time.
extern UInt VG_(read_millisecond_timer) ( void );
extern Int VG_(gettimeofday)(struct vki_timeval *tv, struct vki_timezone *tz);
// Returns the number of milliseconds of user cpu time we have used,
// as reported by 'getrusage'.
extern UInt VG_(get_user_milliseconds)(void);
/* ---------------------------------------------------------------------
atfork
------------------------------------------------------------------ */

5
include/vki/vki-linux.h
View File

@ -971,6 +971,11 @@ struct vki_sctp_getaddrs {
// From linux-2.6.8.1/include/linux/resource.h
//----------------------------------------------------------------------
#define VKI_RUSAGE_SELF 0
#define VKI_RUSAGE_CHILDREN (-1)
#define VKI_RUSAGE_BOTH (-2) /* sys_wait4() uses this */
#define VKI_RUSAGE_THREAD 1 /* only the calling thread */
struct vki_rusage {
struct vki_timeval ru_utime; /* user time used */
struct vki_timeval ru_stime; /* system time used */

2
none/tests/cmdline2.stdout.exp
View File

@ -170,6 +170,8 @@ usage: valgrind [options] prog-and-args
heap blocks allocated for Valgrind internal use (in bytes) [4]
--wait-for-gdb=yes|no pause on startup to wait for gdb attach
--sym-offsets=yes|no show syms in form 'name+offset'? [no]
--progress-interval=<number> report progress every <number>
CPU seconds [0, meaning disabled]
--command-line-only=no|yes only use command line options [no]
Vex options for all Valgrind tools: