Skip to content

Commit 3aca432

Browse files
fabianbs96fabianbs96
authored
Improve Logger Performance (#683)
* Make use of LoggerFilterLevel to conditionally disable message formatting * Move more from the Logger header to the implementation file * Refactor StdStream + some cleanup * Re-enable PIC by default to support ASLR
1 parent 4c04ed3 commit 3aca432

4 files changed

Lines changed: 288 additions & 258 deletions

File tree

‎include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h‎

Lines changed: 93 additions & 82 deletions
Original file line numberDiff line numberDiff line change
@@ -286,15 +286,16 @@ class IDESolver
286286
const auto &ReturnSiteNs = ICF->getReturnSitesOfCallAt(n);
287287
const auto &Callees = ICF->getCalleesOfCallAt(n);
288288

289-
IF_LOG_ENABLED(
290-
PHASAR_LOG_LEVEL(DEBUG, "Possible callees:"); for (auto Callee
291-
: Callees) {
292-
PHASAR_LOG_LEVEL(DEBUG, " " << Callee->getName());
293-
} PHASAR_LOG_LEVEL(DEBUG, "Possible return sites:");
294-
for (auto ret
295-
: ReturnSiteNs) {
296-
PHASAR_LOG_LEVEL(DEBUG, " " << NToString(ret));
297-
});
289+
IF_LOG_LEVEL_ENABLED(DEBUG, {
290+
PHASAR_LOG_LEVEL(DEBUG, "Possible callees:");
291+
for (auto Callee : Callees) {
292+
PHASAR_LOG_LEVEL(DEBUG, " " << Callee->getName());
293+
}
294+
PHASAR_LOG_LEVEL(DEBUG, "Possible return sites:");
295+
for (auto ret : ReturnSiteNs) {
296+
PHASAR_LOG_LEVEL(DEBUG, " " << NToString(ret));
297+
}
298+
});
298299

299300
// for each possible callee
300301
for (f_t SCalledProcN : Callees) { // still line 14
@@ -315,11 +316,11 @@ class IDESolver
315316
CachedFlowEdgeFunctions.getSummaryEdgeFunction(n, d2,
316317
ReturnSiteN, d3);
317318
INC_COUNTER("SpecialSummary-EF Queries", 1, Full);
318-
IF_LOG_ENABLED(
319-
PHASAR_LOG_LEVEL(
320-
DEBUG, "Queried Summary Edge Function: " << SumEdgFnE);
321-
PHASAR_LOG_LEVEL(DEBUG, "Compose: " << SumEdgFnE << " * " << f
322-
<< '\n'));
319+
320+
PHASAR_LOG_LEVEL(DEBUG,
321+
"Queried Summary Edge Function: " << SumEdgFnE);
322+
PHASAR_LOG_LEVEL(DEBUG,
323+
"Compose: " << SumEdgFnE << " * " << f << '\n');
323324
WorkList.emplace_back(PathEdge(d1, ReturnSiteN, std::move(d3)),
324325
f.composeWith(SumEdgFnE));
325326
}
@@ -562,7 +563,7 @@ class IDESolver
562563
}
563564

564565
void setVal(n_t NHashN, d_t NHashD, l_t L) {
565-
IF_LOG_ENABLED({
566+
IF_LOG_LEVEL_ENABLED(DEBUG, {
566567
PHASAR_LOG_LEVEL(DEBUG,
567568
"Function : " << ICF->getFunctionOf(NHashN)->getName());
568569
PHASAR_LOG_LEVEL(DEBUG, "Inst. : " << NToString(NHashN));
@@ -580,13 +581,14 @@ class IDESolver
580581
}
581582

582583
EdgeFunction<l_t> jumpFunction(const PathEdge<n_t, d_t> Edge) {
583-
IF_LOG_ENABLED(
584-
PHASAR_LOG_LEVEL(DEBUG, "JumpFunctions Forward-Lookup:");
585-
PHASAR_LOG_LEVEL(DEBUG,
586-
" Source D: " << DToString(Edge.factAtSource()));
587-
PHASAR_LOG_LEVEL(DEBUG, " Target N: " << NToString(Edge.getTarget()));
588-
PHASAR_LOG_LEVEL(DEBUG,
589-
" Target D: " << DToString(Edge.factAtTarget())));
584+
IF_LOG_LEVEL_ENABLED(DEBUG, {
585+
PHASAR_LOG_LEVEL(DEBUG, "JumpFunctions Forward-Lookup:");
586+
PHASAR_LOG_LEVEL(DEBUG,
587+
" Source D: " << DToString(Edge.factAtSource()));
588+
PHASAR_LOG_LEVEL(DEBUG, " Target N: " << NToString(Edge.getTarget()));
589+
PHASAR_LOG_LEVEL(DEBUG,
590+
" Target D: " << DToString(Edge.factAtTarget()));
591+
});
590592

591593
auto FwdLookupRes =
592594
JumpFn->forwardLookup(Edge.factAtSource(), Edge.getTarget());
@@ -617,21 +619,22 @@ class IDESolver
617619
void pathEdgeProcessingTask(PathEdge<n_t, d_t> Edge) {
618620
PAMM_GET_INSTANCE;
619621
INC_COUNTER("JumpFn Construction", 1, Full);
620-
IF_LOG_ENABLED(
621-
PHASAR_LOG_LEVEL(
622-
DEBUG,
623-
"-------------------------------------------- "
624-
<< PathEdgeCount
625-
<< ". Path Edge --------------------------------------------");
626-
PHASAR_LOG_LEVEL(DEBUG, ' ');
627-
PHASAR_LOG_LEVEL(DEBUG, "Process " << PathEdgeCount << ". path edge:");
628-
PHASAR_LOG_LEVEL(DEBUG, "< D source: " << DToString(Edge.factAtSource())
629-
<< " ;");
630-
PHASAR_LOG_LEVEL(DEBUG,
631-
" N target: " << NToString(Edge.getTarget()) << " ;");
632-
PHASAR_LOG_LEVEL(DEBUG, " D target: " << DToString(Edge.factAtTarget())
633-
<< " >");
634-
PHASAR_LOG_LEVEL(DEBUG, ' '));
622+
IF_LOG_LEVEL_ENABLED(DEBUG, {
623+
PHASAR_LOG_LEVEL(
624+
DEBUG,
625+
"-------------------------------------------- "
626+
<< PathEdgeCount
627+
<< ". Path Edge --------------------------------------------");
628+
PHASAR_LOG_LEVEL(DEBUG, ' ');
629+
PHASAR_LOG_LEVEL(DEBUG, "Process " << PathEdgeCount << ". path edge:");
630+
PHASAR_LOG_LEVEL(DEBUG, "< D source: " << DToString(Edge.factAtSource())
631+
<< " ;");
632+
PHASAR_LOG_LEVEL(DEBUG,
633+
" N target: " << NToString(Edge.getTarget()) << " ;");
634+
PHASAR_LOG_LEVEL(DEBUG, " D target: " << DToString(Edge.factAtTarget())
635+
<< " >");
636+
PHASAR_LOG_LEVEL(DEBUG, ' ');
637+
});
635638

636639
if (!ICF->isCallSite(Edge.getTarget())) {
637640
if (ICF->isExitInst(Edge.getTarget())) {
@@ -1063,28 +1066,31 @@ class IDESolver
10631066
EdgeFunction<l_t> fPrime = JumpFnE.joinWith(f);
10641067
bool NewFunction = fPrime != JumpFnE;
10651068

1066-
IF_LOG_ENABLED(
1067-
PHASAR_LOG_LEVEL(
1068-
DEBUG, "Join: " << JumpFnE << " & " << f
1069-
<< (JumpFnE == f ? " (EF's are equal)" : " "));
1070-
PHASAR_LOG_LEVEL(DEBUG,
1071-
" = " << fPrime
1069+
IF_LOG_LEVEL_ENABLED(DEBUG, {
1070+
PHASAR_LOG_LEVEL(DEBUG,
1071+
"Join: " << JumpFnE << " & " << f
1072+
<< (JumpFnE == f ? " (EF's are equal)" : " "));
1073+
PHASAR_LOG_LEVEL(DEBUG, " = "
1074+
<< fPrime
10721075
<< (NewFunction ? " (new jump func)" : " "));
1073-
PHASAR_LOG_LEVEL(DEBUG, ' '));
1076+
PHASAR_LOG_LEVEL(DEBUG, ' ');
1077+
});
10741078
if (NewFunction) {
10751079
JumpFn->addFunction(SourceVal, Target, TargetVal, fPrime);
10761080
PathEdge Edge(SourceVal, Target, TargetVal);
10771081
PathEdgeCount++;
10781082
pathEdgeProcessingTask(std::move(Edge));
10791083

1080-
IF_LOG_ENABLED(if (!IDEProblem.isZeroValue(TargetVal)) {
1081-
PHASAR_LOG_LEVEL(DEBUG, "EDGE: <F: " << Target->getFunction()->getName()
1082-
<< ", D: " << DToString(SourceVal)
1083-
<< '>');
1084-
PHASAR_LOG_LEVEL(DEBUG, " ---> <N: " << NToString(Target) << ',');
1085-
PHASAR_LOG_LEVEL(DEBUG, " D: " << DToString(TargetVal) << ',');
1086-
PHASAR_LOG_LEVEL(DEBUG, " EF: " << fPrime << '>');
1087-
PHASAR_LOG_LEVEL(DEBUG, ' ');
1084+
IF_LOG_LEVEL_ENABLED(DEBUG, {
1085+
if (!IDEProblem.isZeroValue(TargetVal)) {
1086+
PHASAR_LOG_LEVEL(
1087+
DEBUG, "EDGE: <F: " << Target->getFunction()->getName()
1088+
<< ", D: " << DToString(SourceVal) << '>');
1089+
PHASAR_LOG_LEVEL(DEBUG, " ---> <N: " << NToString(Target) << ',');
1090+
PHASAR_LOG_LEVEL(DEBUG, " D: " << DToString(TargetVal) << ',');
1091+
PHASAR_LOG_LEVEL(DEBUG, " EF: " << fPrime << '>');
1092+
PHASAR_LOG_LEVEL(DEBUG, ' ');
1093+
}
10881094
});
10891095
} else {
10901096
PHASAR_LOG_LEVEL(DEBUG, "PROPAGATE: No new function!");
@@ -1118,41 +1124,43 @@ class IDESolver
11181124
}
11191125

11201126
void printIncomingTab() const {
1121-
IF_LOG_ENABLED(
1122-
PHASAR_LOG_LEVEL(DEBUG, "Start of incomingtab entry");
1123-
for (const auto &Cell
1124-
: IncomingTab.cellSet()) {
1125-
PHASAR_LOG_LEVEL(DEBUG, "sP: " << NToString(Cell.getRowKey()));
1126-
PHASAR_LOG_LEVEL(DEBUG, "d3: " << DToString(Cell.getColumnKey()));
1127-
for (const auto &Entry : Cell.getValue()) {
1128-
PHASAR_LOG_LEVEL(DEBUG, " n: " << NToString(Entry.first));
1129-
for (const auto &Fact : Entry.second) {
1130-
PHASAR_LOG_LEVEL(DEBUG, " d2: " << DToString(Fact));
1131-
}
1127+
IF_LOG_LEVEL_ENABLED(DEBUG, {
1128+
PHASAR_LOG_LEVEL(DEBUG, "Start of incomingtab entry");
1129+
for (const auto &Cell : IncomingTab.cellSet()) {
1130+
PHASAR_LOG_LEVEL(DEBUG, "sP: " << NToString(Cell.getRowKey()));
1131+
PHASAR_LOG_LEVEL(DEBUG, "d3: " << DToString(Cell.getColumnKey()));
1132+
for (const auto &Entry : Cell.getValue()) {
1133+
PHASAR_LOG_LEVEL(DEBUG, " n: " << NToString(Entry.first));
1134+
for (const auto &Fact : Entry.second) {
1135+
PHASAR_LOG_LEVEL(DEBUG, " d2: " << DToString(Fact));
11321136
}
1133-
PHASAR_LOG_LEVEL(DEBUG, "---------------");
1134-
} PHASAR_LOG_LEVEL(DEBUG, "End of incomingtab entry");)
1137+
}
1138+
PHASAR_LOG_LEVEL(DEBUG, "---------------");
1139+
}
1140+
PHASAR_LOG_LEVEL(DEBUG, "End of incomingtab entry");
1141+
})
11351142
}
11361143

11371144
void printEndSummaryTab() const {
1138-
IF_LOG_ENABLED(
1139-
PHASAR_LOG_LEVEL(DEBUG, "Start of endsummarytab entry");
1140-
1141-
EndsummaryTab.foreachCell(
1142-
[](const auto &Row, const auto &Col, const auto &Val) {
1143-
PHASAR_LOG_LEVEL(DEBUG, "sP: " << NToString(Row));
1144-
PHASAR_LOG_LEVEL(DEBUG, "d1: " << DToString(Col));
1145-
1146-
Val.foreachCell([](const auto &InnerRow, const auto &InnerCol,
1147-
const auto &InnerVal) {
1148-
PHASAR_LOG_LEVEL(DEBUG, " eP: " << NToString(InnerRow));
1149-
PHASAR_LOG_LEVEL(DEBUG, " d2: " << DToString(InnerCol));
1150-
PHASAR_LOG_LEVEL(DEBUG, " EF: " << InnerVal);
1151-
});
1152-
PHASAR_LOG_LEVEL(DEBUG, "---------------");
1145+
IF_LOG_LEVEL_ENABLED(DEBUG, {
1146+
PHASAR_LOG_LEVEL(DEBUG, "Start of endsummarytab entry");
1147+
1148+
EndsummaryTab.foreachCell(
1149+
[](const auto &Row, const auto &Col, const auto &Val) {
1150+
PHASAR_LOG_LEVEL(DEBUG, "sP: " << NToString(Row));
1151+
PHASAR_LOG_LEVEL(DEBUG, "d1: " << DToString(Col));
1152+
1153+
Val.foreachCell([](const auto &InnerRow, const auto &InnerCol,
1154+
const auto &InnerVal) {
1155+
PHASAR_LOG_LEVEL(DEBUG, " eP: " << NToString(InnerRow));
1156+
PHASAR_LOG_LEVEL(DEBUG, " d2: " << DToString(InnerCol));
1157+
PHASAR_LOG_LEVEL(DEBUG, " EF: " << InnerVal);
11531158
});
1159+
PHASAR_LOG_LEVEL(DEBUG, "---------------");
1160+
});
11541161

1155-
PHASAR_LOG_LEVEL(DEBUG, "End of endsummarytab entry");)
1162+
PHASAR_LOG_LEVEL(DEBUG, "End of endsummarytab entry");
1163+
})
11561164
}
11571165

11581166
void printComputedPathEdges() {
@@ -1259,7 +1267,7 @@ class IDESolver
12591267
if (ICF->isCallSite(Edge.first)) {
12601268
ValidInCallerContext[Edge.second].insert(D2s.begin(), D2s.end());
12611269
}
1262-
IF_LOG_ENABLED([this](const auto &D2s) {
1270+
IF_LOG_LEVEL_ENABLED(DEBUG, [this](const auto &D2s) {
12631271
for (auto D2 : D2s) {
12641272
PHASAR_LOG_LEVEL(DEBUG, "d2: " << DToString(D2));
12651273
}
@@ -1671,6 +1679,8 @@ class IDESolver
16711679
void finalizeInternal() {
16721680
PAMM_GET_INSTANCE;
16731681
STOP_TIMER("DFA Phase I", Full);
1682+
PHASAR_LOG_LEVEL(INFO, "[info]: IDE Phase I completed");
1683+
16741684
if (SolverConfig.computeValues()) {
16751685
START_TIMER("DFA Phase II", Full);
16761686
// Computing the final values for the edge functions
@@ -1679,6 +1689,7 @@ class IDESolver
16791689
computeValues();
16801690
STOP_TIMER("DFA Phase II", Full);
16811691
}
1692+
16821693
PHASAR_LOG_LEVEL(INFO, "Problem solved");
16831694
if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::Core) {
16841695
computeAndPrintStatistics();

0 commit comments

Comments
 (0)