Skip to content

Commit f7041f5

Browse files
committed
[analyzer] Retry UNDEF Z3 queries at most "crosscheck-with-z3-retries-on-timeout" times
If we have a refutation Z3 query timed out (UNDEF), allow a couple of retries to improve stability of the query. By default allow 2 retries. Retries should help mitigating flaky Z3 queries. See the details in the following RFC: https://discourse.llvm.org/t/analyzer-rfc-retry-z3-crosscheck-queries-on-timeout/83711 Note that with each retry, we spend more time per query. Currently, we have a 15 seconds timeout per query - which are also in effect for the retry attempts. --- Why should this help? In short, retrying queries should bring stability because if a query runs long it's more likely that it did so due to some runtime anomaly than it's on the edge of succeeding. This is because most queries run quick, and the queries that run long, usually run long by a fair amount. Consequently, retries should improve the stability of the outcome of the Z3 query. In general, the retries shouldn't increase the overall analysis time because it's really rare we hit the 0.1% of the cases when we would do retries. But keep in mind that the retry attempts can add up if many retries are allowed, or the individual query timeout is large. CPP-5920
1 parent a77346b commit f7041f5

File tree

7 files changed

+149
-47
lines changed

7 files changed

+149
-47
lines changed

clang/include/clang/StaticAnalyzer/Core/AnalyzerOptions.def

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -193,6 +193,8 @@ ANALYZER_OPTION(
193193
"with \"crosscheck-with-z3-timeout-threshold\" of 300 ms, would nicely "
194194
"guarantee that no bug report equivalence class can take longer than "
195195
"1 second, effectively mitigating Z3 hangs during refutation. "
196+
"If there were Z3 retries, only the minimum query time is considered "
197+
"when accumulating query times within a report equivalence class. "
196198
"Set 0 for no timeout.", 0)
197199

198200
ANALYZER_OPTION(
@@ -213,6 +215,15 @@ ANALYZER_OPTION(
213215
"400'000 should on average make Z3 queries run for up to 100ms on modern "
214216
"hardware. Set 0 for unlimited.", 0)
215217

218+
ANALYZER_OPTION(
219+
unsigned, Z3CrosscheckRetriesOnTimeout,
220+
"crosscheck-with-z3-retries-on-timeout",
221+
"Set how many times the oracle is allowed to retry a Z3 query. "
222+
"Set 0 for not allowing retries, in which case each Z3 query would be "
223+
"attempted only once. Increasing the number of retries is often more "
224+
"effective at reducing the number of nondeterministic diagnostics than "
225+
"\"crosscheck-with-z3-timeout-threshold\" in practice.", 2)
226+
216227
ANALYZER_OPTION(bool, ShouldReportIssuesInMainSourceFile,
217228
"report-in-main-source-file",
218229
"Whether or not the diagnostic report should be always "

clang/lib/StaticAnalyzer/Core/Z3CrosscheckVisitor.cpp

Lines changed: 29 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,9 @@
2121

2222
#define DEBUG_TYPE "Z3CrosscheckOracle"
2323

24+
// Queries retried at most `Z3CrosscheckRetriesOnTimeout` number of times if the
25+
// `check()` call returns `UNDEF` for any reason. Each query is only counted
26+
// once for these statistics, the retries are not accounted for.
2427
STATISTIC(NumZ3QueriesDone, "Number of Z3 queries done");
2528
STATISTIC(NumTimesZ3TimedOut, "Number of times Z3 query timed out");
2629
STATISTIC(NumTimesZ3ExhaustedRLimit,
@@ -77,16 +80,33 @@ void Z3CrosscheckVisitor::finalizeVisitor(BugReporterContext &BRC,
7780
RefutationSolver->addConstraint(SMTConstraints);
7881
}
7982

80-
// And check for satisfiability
81-
llvm::TimeRecord Start = llvm::TimeRecord::getCurrentTime(/*Start=*/true);
82-
std::optional<bool> IsSAT = RefutationSolver->check();
83-
llvm::TimeRecord Diff = llvm::TimeRecord::getCurrentTime(/*Start=*/false);
84-
Diff -= Start;
85-
Result = Z3Result{
86-
IsSAT,
87-
static_cast<unsigned>(Diff.getWallTime() * 1000),
88-
RefutationSolver->getStatistics()->getUnsigned("rlimit count"),
83+
auto GetUsedRLimit = [](const llvm::SMTSolverRef &Solver) {
84+
return Solver->getStatistics()->getUnsigned("rlimit count");
85+
};
86+
87+
auto AttemptOnce = [&](const llvm::SMTSolverRef &Solver) -> Z3Result {
88+
constexpr auto getCurrentTime = llvm::TimeRecord::getCurrentTime;
89+
unsigned InitialRLimit = GetUsedRLimit(Solver);
90+
double Start = getCurrentTime(/*Start=*/true).getWallTime();
91+
std::optional<bool> IsSAT = Solver->check();
92+
double End = getCurrentTime(/*Start=*/false).getWallTime();
93+
return {
94+
IsSAT,
95+
static_cast<unsigned>((End - Start) * 1000),
96+
GetUsedRLimit(Solver) - InitialRLimit,
97+
};
8998
};
99+
100+
// And check for satisfiability
101+
unsigned MinQueryTimeAcrossAttempts = std::numeric_limits<unsigned>::max();
102+
unsigned NumRetries = Opts.Z3CrosscheckRetriesOnTimeout;
103+
for (unsigned Attempt = 1; Attempt <= 1 + NumRetries; ++Attempt) {
104+
Result = AttemptOnce(RefutationSolver);
105+
Result.Z3QueryTimeMilliseconds =
106+
std::min(MinQueryTimeAcrossAttempts, Result.Z3QueryTimeMilliseconds);
107+
if (Result.IsSAT.has_value())
108+
return;
109+
}
90110
}
91111

92112
void Z3CrosscheckVisitor::addConstraints(

clang/test/Analysis/analyzer-config.c

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -41,6 +41,7 @@
4141
// CHECK-NEXT: cplusplus.SmartPtrModeling:ModelSmartPtrDereference = false
4242
// CHECK-NEXT: crosscheck-with-z3 = false
4343
// CHECK-NEXT: crosscheck-with-z3-eqclass-timeout-threshold = 0
44+
// CHECK-NEXT: crosscheck-with-z3-retries-on-timeout = 2
4445
// CHECK-NEXT: crosscheck-with-z3-rlimit-threshold = 0
4546
// CHECK-NEXT: crosscheck-with-z3-timeout-threshold = 15000
4647
// CHECK-NEXT: ctu-dir = ""
Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,39 @@
1+
// Check the default config.
2+
// RUN: %clang_analyze_cc1 -analyzer-checker=debug.ConfigDumper 2>&1 \
3+
// RUN: | FileCheck %s --match-full-lines
4+
// CHECK: crosscheck-with-z3-retries-on-timeout = 2
5+
6+
// RUN: rm -rf %t && mkdir %t
7+
// RUN: %host_cxx -shared -fPIC \
8+
// RUN: %S/z3/Inputs/MockZ3_solver_check.cpp \
9+
// RUN: -o %t/MockZ3_solver_check.so
10+
11+
// DEFINE: %{mocked_clang} = \
12+
// DEFINE: LD_PRELOAD="%t/MockZ3_solver_check.so" \
13+
// DEFINE: %clang_cc1 %s -analyze -setup-static-analyzer \
14+
// DEFINE: -analyzer-config crosscheck-with-z3=true \
15+
// DEFINE: -analyzer-checker=core
16+
17+
// DEFINE: %{retry} = -analyzer-config crosscheck-with-z3-retries-on-timeout
18+
19+
// RUN: Z3_SOLVER_RESULTS="UNDEF" %{mocked_clang} %{retry}=0 -verify=refuted
20+
// RUN: Z3_SOLVER_RESULTS="UNSAT" %{mocked_clang} %{retry}=0 -verify=refuted
21+
// RUN: Z3_SOLVER_RESULTS="SAT" %{mocked_clang} %{retry}=0 -verify=accepted
22+
23+
// RUN: Z3_SOLVER_RESULTS="UNDEF,UNDEF" %{mocked_clang} %{retry}=1 -verify=refuted
24+
// RUN: Z3_SOLVER_RESULTS="UNDEF,UNSAT" %{mocked_clang} %{retry}=1 -verify=refuted
25+
// RUN: Z3_SOLVER_RESULTS="UNDEF,SAT" %{mocked_clang} %{retry}=1 -verify=accepted
26+
27+
// RUN: Z3_SOLVER_RESULTS="UNDEF,UNDEF,UNDEF" %{mocked_clang} %{retry}=2 -verify=refuted
28+
// RUN: Z3_SOLVER_RESULTS="UNDEF,UNDEF,UNSAT" %{mocked_clang} %{retry}=2 -verify=refuted
29+
// RUN: Z3_SOLVER_RESULTS="UNDEF,UNDEF,SAT" %{mocked_clang} %{retry}=2 -verify=accepted
30+
31+
32+
// REQUIRES: z3, asserts, shell, system-linux
33+
34+
// refuted-no-diagnostics
35+
36+
int div_by_zero_test(int b) {
37+
if (b) {}
38+
return 100 / b; // accepted-warning {{Division by zero}}
39+
}

clang/test/Analysis/z3/D83660.c

Lines changed: 7 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -1,21 +1,18 @@
11
// RUN: rm -rf %t && mkdir %t
2-
// RUN: %host_cxx -shared -fPIC %S/Inputs/MockZ3_solver_check.c -o %t/MockZ3_solver_check.so
2+
// RUN: %host_cxx -shared -fPIC \
3+
// RUN: %S/Inputs/MockZ3_solver_check.cpp \
4+
// RUN: -o %t/MockZ3_solver_check.so
35
//
4-
// RUN: LD_PRELOAD="%t/MockZ3_solver_check.so" \
5-
// RUN: %clang_cc1 -analyze -analyzer-constraints=z3 -setup-static-analyzer \
6-
// RUN: -analyzer-checker=core,debug.ExprInspection %s -verify 2>&1 | FileCheck %s
6+
// RUN: Z3_SOLVER_RESULTS="SAT,SAT,SAT,SAT,UNDEF" \
7+
// RUN: LD_PRELOAD="%t/MockZ3_solver_check.so" \
8+
// RUN: %clang_cc1 -analyze -analyzer-constraints=z3 -setup-static-analyzer \
9+
// RUN: -analyzer-checker=core %s -verify
710
//
811
// REQUIRES: z3, asserts, shell, system-linux
912
//
1013
// Works only with the z3 constraint manager.
1114
// expected-no-diagnostics
1215

13-
// CHECK: Z3_solver_check returns the real value: TRUE
14-
// CHECK-NEXT: Z3_solver_check returns the real value: TRUE
15-
// CHECK-NEXT: Z3_solver_check returns the real value: TRUE
16-
// CHECK-NEXT: Z3_solver_check returns the real value: TRUE
17-
// CHECK-NEXT: Z3_solver_check returns a mocked value: UNDEF
18-
1916
void D83660(int b) {
2017
if (b) {
2118
}

clang/test/Analysis/z3/Inputs/MockZ3_solver_check.c

Lines changed: 0 additions & 28 deletions
This file was deleted.
Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,62 @@
1+
#include <cassert>
2+
#include <dlfcn.h>
3+
#include <cstdio>
4+
#include <cstdlib>
5+
#include <cstring>
6+
7+
#include <z3.h>
8+
9+
static char *Z3ResultsBegin;
10+
static char *Z3ResultsCursor;
11+
12+
static __attribute__((constructor)) void init() {
13+
const char *Env = getenv("Z3_SOLVER_RESULTS");
14+
if (!Env) {
15+
fprintf(stderr, "Z3_SOLVER_RESULTS envvar must be defined; abort\n");
16+
abort();
17+
}
18+
Z3ResultsBegin = strdup(Env);
19+
Z3ResultsCursor = Z3ResultsBegin;
20+
if (!Z3ResultsBegin) {
21+
fprintf(stderr, "strdup failed; abort\n");
22+
abort();
23+
}
24+
}
25+
26+
static __attribute__((destructor)) void finit() {
27+
if (strlen(Z3ResultsCursor) > 0) {
28+
fprintf(stderr, "Z3_SOLVER_RESULTS should have been completely consumed "
29+
"by the end of the test; abort\n");
30+
abort();
31+
}
32+
free(Z3ResultsBegin);
33+
}
34+
35+
static bool consume_token(char **pointer_to_cursor, const char *token) {
36+
assert(pointer_to_cursor);
37+
int len = strlen(token);
38+
if (*pointer_to_cursor && strncmp(*pointer_to_cursor, token, len) == 0) {
39+
*pointer_to_cursor += len;
40+
return true;
41+
}
42+
return false;
43+
}
44+
45+
Z3_lbool Z3_API Z3_solver_check(Z3_context c, Z3_solver s) {
46+
consume_token(&Z3ResultsCursor, ",");
47+
48+
if (consume_token(&Z3ResultsCursor, "UNDEF")) {
49+
printf("Z3_solver_check returns UNDEF\n");
50+
return Z3_L_UNDEF;
51+
}
52+
if (consume_token(&Z3ResultsCursor, "SAT")) {
53+
printf("Z3_solver_check returns SAT\n");
54+
return Z3_L_TRUE;
55+
}
56+
if (consume_token(&Z3ResultsCursor, "UNSAT")) {
57+
printf("Z3_solver_check returns UNSAT\n");
58+
return Z3_L_FALSE;
59+
}
60+
fprintf(stderr, "Z3_SOLVER_RESULTS was exhausted; abort\n");
61+
abort();
62+
}

0 commit comments

Comments
 (0)