@ -26,16 +26,9 @@
# include <proc/readproc.h>
# endif
# ifdef __MACH__ // required to build on MacOS
# include <time.h>
# include <sys/time.h>
# include <mach/clock.h>
# include <mach/mach.h>
# endif
namespace libsnark {
int64_t get_nsec_time ( )
long long get_nsec_time ( )
{
auto timepoint = std : : chrono : : high_resolution_clock : : now ( ) ;
return std : : chrono : : duration_cast < std : : chrono : : nanoseconds > ( timepoint . time_since_epoch ( ) ) . count ( ) ;
@ -45,20 +38,10 @@ int64_t get_nsec_time()
long long get_nsec_cpu_time ( )
{
: : timespec ts ;
# ifdef __MACH__
clock_serv_t cclock ;
mach_timespec_t mts ;
host_get_clock_service ( mach_host_self ( ) , CALENDAR_CLOCK , & cclock ) ;
clock_get_time ( cclock , & mts ) ;
mach_port_deallocate ( mach_task_self ( ) , cclock ) ;
ts . tv_sec = mts . tv_sec ;
ts . tv_nsec = mts . tv_nsec ;
# else
if ( : : clock_gettime ( CLOCK_PROCESS_CPUTIME_ID , & ts ) )
throw : : std : : runtime_error ( " clock_gettime(CLOCK_PROCESS_CPUTIME_ID) failed " ) ;
// If we expected this to work, don't silently ignore failures, because that would hide the problem and incur an unnecessarily system-call overhead. So if we ever observe this exception, we should probably add a suitable #ifdef .
//TODO: clock_gettime(CLOCK_PROCESS_CPUTIME_ID) is not supported by native Windows. What about Cygwin? Should we #ifdef on CLOCK_PROCESS_CPUTIME_ID or on __linux__?
# endif
return ts . tv_sec * 1000000000ll + ts . tv_nsec ;
}
@ -74,20 +57,20 @@ void start_profiling()
}
std : : map < std : : string , size_t > invocation_counts ;
std : : map < std : : string , int64_t > enter_times ;
std : : map < std : : string , int64_t > last_times ;
std : : map < std : : string , int64_t > cumulative_times ;
std : : map < std : : string , long long > enter_times ;
std : : map < std : : string , long long > last_times ;
std : : map < std : : string , long long > cumulative_times ;
//TODO: Instead of analogous maps for time and cpu_time, use a single struct-valued map
std : : map < std : : string , int64_t > enter_cpu_times ;
std : : map < std : : string , int64_t > last_cpu_times ;
std : : map < std : : pair < std : : string , std : : string > , int64_t > op_counts ;
std : : map < std : : pair < std : : string , std : : string > , int64_t > cumulative_op_counts ; // ((msg, data_point), value)
std : : map < std : : string , long long > enter_cpu_times ;
std : : map < std : : string , long long > last_cpu_times ;
std : : map < std : : pair < std : : string , std : : string > , long long > op_counts ;
std : : map < std : : pair < std : : string , std : : string > , long long > cumulative_op_counts ; // ((msg, data_point), value)
// TODO: Convert op_counts and cumulative_op_counts from pair to structs
size_t indentation = 0 ;
std : : vector < std : : string > block_names ;
std : : list < std : : pair < std : : string , int64_t * > > op_data_points = {
std : : list < std : : pair < std : : string , long long * > > op_data_points = {
# ifdef PROFILE_OP_COUNTS
std : : make_pair ( " Fradd " , & Fr < default_ec_pp > : : add_cnt ) ,
std : : make_pair ( " Frsub " , & Fr < default_ec_pp > : : sub_cnt ) ,
@ -115,7 +98,7 @@ void clear_profiling_counters()
cumulative_times . clear ( ) ;
}
void print_cumulative_time_entry ( const std : : string & key , const int64_t factor )
void print_cumulative_time_entry ( const std : : string & key , const long long factor )
{
const double total_ms = ( cumulative_times . at ( key ) * 1e-6 ) ;
const size_t cnt = invocation_counts . at ( key ) ;
@ -123,7 +106,7 @@ void print_cumulative_time_entry(const std::string &key, const int64_t factor)
printf ( " %-45s: %12.5fms = %lld * %0.5fms (%zu invocations, %0.5fms = %lld * %0.5fms per invocation) \n " , key . c_str ( ) , total_ms , factor , total_ms / factor , cnt , avg_ms , factor , avg_ms / factor ) ;
}
void print_cumulative_times ( const int64_t factor )
void print_cumulative_times ( const long long factor )
{
printf ( " Dumping times: \n " ) ;
for ( auto & kv : cumulative_times )
@ -172,7 +155,7 @@ void print_op_profiling(const std::string &msg)
printf ( " (opcounts) = ( " ) ;
bool first = true ;
for ( std : : pair < std : : string , int64_t * > p : op_data_points )
for ( std : : pair < std : : string , long long * > p : op_data_points )
{
if ( ! first )
{
@ -188,14 +171,14 @@ void print_op_profiling(const std::string &msg)
# endif
}
static void print_times_from_last_and_start ( int64_t now , int64_t last ,
int64_t cpu_now , int64_t cpu_last )
static void print_times_from_last_and_start ( long long now , long long last ,
long long cpu_now , long long cpu_last )
{
int64_t time_from_start = now - start_time ;
int64_t time_from_last = now - last ;
long long time_from_start = now - start_time ;
long long time_from_last = now - last ;
int64_t cpu_time_from_start = cpu_now - start_cpu_time ;
int64_t cpu_time_from_last = cpu_now - cpu_last ;
long long cpu_time_from_start = cpu_now - start_cpu_time ;
long long cpu_time_from_last = cpu_now - cpu_last ;
if ( time_from_last ! = 0 ) {
double parallelism_from_last = 1.0 * cpu_time_from_last / time_from_last ;
@ -216,8 +199,8 @@ void print_time(const char* msg)
return ;
}
int64_t now = get_nsec_time ( ) ;
int64_t cpu_now = get_nsec_cpu_time ( ) ;
long long now = get_nsec_time ( ) ;
long long cpu_now = get_nsec_cpu_time ( ) ;
printf ( " %-35s \t " , msg ) ;
print_times_from_last_and_start ( now , last_time , cpu_now , last_cpu_time ) ;
@ -248,7 +231,7 @@ void print_indent()
void op_profiling_enter ( const std : : string & msg )
{
for ( std : : pair < std : : string , int64_t * > p : op_data_points )
for ( std : : pair < std : : string , long long * > p : op_data_points )
{
op_counts [ std : : make_pair ( msg , p . first ) ] = * ( p . second ) ;
}
@ -262,9 +245,9 @@ void enter_block(const std::string &msg, const bool indent)
}
block_names . emplace_back ( msg ) ;
int64_t t = get_nsec_time ( ) ;
long long t = get_nsec_time ( ) ;
enter_times [ msg ] = t ;
int64_t cpu_t = get_nsec_cpu_time ( ) ;
long long cpu_t = get_nsec_cpu_time ( ) ;
enter_cpu_times [ msg ] = cpu_t ;
if ( inhibit_profiling_info )
@ -305,15 +288,15 @@ void leave_block(const std::string &msg, const bool indent)
+ + invocation_counts [ msg ] ;
int64_t t = get_nsec_time ( ) ;
long long t = get_nsec_time ( ) ;
last_times [ msg ] = ( t - enter_times [ msg ] ) ;
cumulative_times [ msg ] + = ( t - enter_times [ msg ] ) ;
int64_t cpu_t = get_nsec_cpu_time ( ) ;
long long cpu_t = get_nsec_cpu_time ( ) ;
last_cpu_times [ msg ] = ( cpu_t - enter_cpu_times [ msg ] ) ;
# ifdef PROFILE_OP_COUNTS
for ( std : : pair < std : : string , int64_t * > p : op_data_points )
for ( std : : pair < std : : string , long long * > p : op_data_points )
{
cumulative_op_counts [ std : : make_pair ( msg , p . first ) ] + = * ( p . second ) - op_counts [ std : : make_pair ( msg , p . first ) ] ;
}
FireMartZ
6 years ago