From a7bc1d07b1758302891c406145108ee6d996e651 Mon Sep 17 00:00:00 2001
From: clc5q <clc5q@git.zephyr-software.com>
Date: Thu, 11 Jun 2015 07:06:15 +0000
Subject: [PATCH] Add timing output for analysis phases.
Former-commit-id: 4f3e70021a2b509b80db0caf8c99b2141896333f
---
src/base/SMPProgram.cpp | 41 +++++++++++++++++++++++++++++++++++++++++
1 file changed, 41 insertions(+)
diff --git a/src/base/SMPProgram.cpp b/src/base/SMPProgram.cpp
index 080c9026..41ce313b 100644
--- a/src/base/SMPProgram.cpp
+++ b/src/base/SMPProgram.cpp
@@ -44,6 +44,7 @@
#include <cstring>
#include <cstdlib>
#include <cassert>
+#include <ctime>
#include "interfaces/SMPDBInterface.h"
#include "base/SMPDataFlowAnalysis.h"
@@ -228,6 +229,7 @@ void SMPProgram::Analyze(ProfilerInformation *pi, FILE *AnnotFile, FILE *InfoAnn
long TotalUntypedPhiDefs = 0;
long TotalSafeFuncs = 0;
size_t TotalInstructions = 0;
+ time_t StartTime = time(NULL), EndTime;
this->ProfInfo = pi;
@@ -345,6 +347,11 @@ void SMPProgram::Analyze(ProfilerInformation *pi, FILE *AnnotFile, FILE *InfoAnn
SMP_msg("INFO: Number of functions in FuncMap: %zu\n", this->FuncMap.size());
#endif
+ EndTime = time(NULL);
+ double TimeDiff = difftime(EndTime, StartTime);
+ SMP_msg("INFO: TIME: Phase 1: AnalyzeFunc: %7.2f\n", TimeDiff);
+ StartTime = time(NULL);
+
if (global_STARS_program->ShouldSTARSPerformReducedAnalysis()) {
this->EmitDataAnnotations(this->AnnotationFile, this->InfoAnnotationFile);
this->GlobalVarTable.clear();
@@ -366,6 +373,11 @@ void SMPProgram::Analyze(ProfilerInformation *pi, FILE *AnnotFile, FILE *InfoAnn
} // end for all functions in FuncList
} // end for all functions in TempFuncMap
+ EndTime = time(NULL);
+ TimeDiff = difftime(EndTime, StartTime);
+ SMP_msg("INFO: TIME: Phase 2: AdvancedAnalysis: %7.2f\n", TimeDiff);
+ StartTime = time(NULL);
+
// In order to reduce memory consumption, emit the global data annotations now,
// and then release the memory for the global data. Note that this means we
// cannot presently apply type inference info to the global data table. If we
@@ -375,6 +387,11 @@ void SMPProgram::Analyze(ProfilerInformation *pi, FILE *AnnotFile, FILE *InfoAnn
this->GlobalVarTable.clear();
this->GlobalNameMap.clear();
+ EndTime = time(NULL);
+ TimeDiff = difftime(EndTime, StartTime);
+ SMP_msg("INFO: TIME: Phase 3: EmitDataAnnotations: %7.2f\n", TimeDiff);
+ StartTime = time(NULL);
+
#ifndef SMP_REDUCED_ANALYSIS
// STEP 2: Compute SSA form.
@@ -407,6 +424,11 @@ void SMPProgram::Analyze(ProfilerInformation *pi, FILE *AnnotFile, FILE *InfoAnn
CurrFunc->FreeUnusedMemory3(); // free memory
}
+ EndTime = time(NULL);
+ TimeDiff = difftime(EndTime, StartTime);
+ SMP_msg("INFO: TIME: Phase 4: SSA+SCCP+FuncSafe: %7.2f\n", TimeDiff);
+ StartTime = time(NULL);
+
#if 0 // need to debug
// Remove any basic blocks that had a direct indication of being unreachable, e.g. "call 0" instruction.
// If any function becomes empty as a result, the function is unreachable, so any block calling it
@@ -446,6 +468,11 @@ void SMPProgram::Analyze(ProfilerInformation *pi, FILE *AnnotFile, FILE *InfoAnn
}
// end of step 3
+ EndTime = time(NULL);
+ TimeDiff = difftime(EndTime, StartTime);
+ SMP_msg("INFO: TIME: Phase 5: RetAddrStatus: %7.2f\n", TimeDiff);
+ StartTime = time(NULL);
+
for (FuncListIter = this->PrioritizedFuncList.begin(); FuncListIter != this->PrioritizedFuncList.end(); ++FuncListIter) {
CurrFunc = (*FuncListIter);
if (NULL == CurrFunc) {
@@ -536,6 +563,11 @@ void SMPProgram::Analyze(ProfilerInformation *pi, FILE *AnnotFile, FILE *InfoAnn
TotalInstructions += CurrFunc->GetInstCount();
} // end for all functions
+ EndTime = time(NULL);
+ TimeDiff = difftime(EndTime, StartTime);
+ SMP_msg("INFO: TIME: Phase 6: MetaData+InferTypes+InferFG: %7.2f\n", TimeDiff);
+ StartTime = time(NULL);
+
#if STARS_INTERPROCEDURAL_TYPE_INFERENCE
// STEP 4: Interprocedural type inference and propagation.
SMP_msg("Performing interprocedural type inference.\n");
@@ -582,6 +614,10 @@ void SMPProgram::Analyze(ProfilerInformation *pi, FILE *AnnotFile, FILE *InfoAnn
#endif
+ EndTime = time(NULL);
+ TimeDiff = difftime(EndTime, StartTime);
+ SMP_msg("INFO: TIME: Phase 7: InterproceduralTypes: %7.2f\n", TimeDiff);
+
// Free memory not needed to emit annotations, now that type inference is done.
CurrFunc->FreeUnusedMemory4();
@@ -728,6 +764,7 @@ void SMPProgram::EmitDataAnnotations(FILE *AnnotFile, FILE *InfoAnnotFile) {
void SMPProgram::EmitAnnotations(FILE *AnnotFile, FILE *InfoAnnotFile) {
long TotalSafeBlocks = 0; // basic blocks with no unsafe writes
long TotalUnsafeBlocks = 0; // basic blocks with unsafe writes
+ time_t StartTime = time(NULL), EndTime;
// Mark exception-handling functions as unsafe for fast returns.
if (this->ProgramThrowsExceptions()) {
@@ -749,6 +786,10 @@ void SMPProgram::EmitAnnotations(FILE *AnnotFile, FILE *InfoAnnotFile) {
#endif
} // end for all functions
+ EndTime = time(NULL);
+ double TimeDiff = difftime(EndTime, StartTime);
+ SMP_msg("INFO: TIME: Phase 8: EmitAnnotations: %7.2f\n", TimeDiff);
+
#if ZST_EMIT_SPARK_ADA_TRANSLATION
SMP_msg("SPARK: Total subword registers translated: %lu\n", SubwordRegCount);
SMP_msg("SPARK: Total subword memory accesses translated: %lu\n", SubwordMemCount);
--
GitLab