Permalink
Browse files

Add frontend option "-warn-long-function-bodies=<N>".

This is a /slightly/ more user-friendly option than
-debug-time-function-bodies; pass it a limit in milliseconds and
the compiler will warn whenever a function or multi-statement closure
takes longer than that to type-check.

Since it's a frontend option (and thus usually passed with -Xfrontend),
I went with the "joined" syntax as the common case. The usual "separate"
syntax of "-warn-long-function-bodies <N>" is also available.

As a frontend option, this is UNSUPPORTED and may be removed without
notice at any future date.

Additional caveats:
- Other parts of type-checking not measured by this may also be slow.
- May include first-use penalties (i.e. "this is slow because it's
  the first function that references an imported type, which causes
  many things to be imported")
- Does not report anything whatsoever about other phases of compilation
  (SILGen, optimization, IRGen, assembly emission, whatever).
- Does not catch anything accidentally being type-checked multiple times
  (a known issue for initial value expressions on properties).
  • Loading branch information...
1 parent ecd8821 commit 18c75928639acf0ccf0e1fb6729eea75bc09cbd5 @jrose-apple jrose-apple committed May 11, 2016
@@ -2911,6 +2911,17 @@ ERROR(circular_reference, none,
NOTE(circular_reference_through, none,
"through reference here", ())
+//------------------------------------------------------------------------------
+// Debug diagnostics
+//------------------------------------------------------------------------------
+
+WARNING(debug_long_function_body, none,
+ "%0 %1 took %2ms to type-check (limit: %3ms)",
+ (DescriptiveDeclKind, DeclName, unsigned, unsigned))
+WARNING(debug_long_closure_body, none,
+ "closure took %0ms to type-check (limit: %1ms)",
+ (unsigned, unsigned))
+
#ifndef DIAG_NO_UNDEF
# if defined(DIAG)
# undef DIAG
@@ -128,6 +128,12 @@ class FrontendOptions {
/// The path to collect the group information for the compiled source files.
std::string GroupInfoPath;
+ /// If non-zero, warn when a function body takes longer than this many
+ /// milliseconds to type-check.
+ ///
+ /// Intended for debugging purposes only.
+ unsigned WarnLongFunctionBodies = 0;
+
enum ActionType {
NoneAction, ///< No specific action
Parse, ///< Parse and type-check only
@@ -247,6 +247,12 @@ def swift3_migration :
Flag<["-"], "swift3-migration">,
HelpText<"Enable Fix-It based migration aids for Swift 3">;
+def warn_long_function_bodies : Separate<["-"], "warn-long-function-bodies">,
+ MetaVarName<"<n>">,
+ HelpText<"Warns when type-checking a function takes longer than <n> ms">;
+def warn_long_function_bodies_EQ : Joined<["-"], "warn-long-function-bodies=">,
+ Alias<warn_long_function_bodies>;
+
def warn_omit_needless_words :
Flag<["-"], "Womit-needless-words">,
HelpText<"Warn about needless words in names">;
@@ -160,10 +160,14 @@ namespace swift {
/// types and diagnose problems therein.
///
/// \param StartElem Where to start for incremental type-checking in the main
- /// source file.
+ /// source file.
+ ///
+ /// \param WarnLongFunctionBodies If non-zero, warn when a function body takes
+ /// longer than this many milliseconds to type-check
void performTypeChecking(SourceFile &SF, TopLevelContext &TLC,
OptionSet<TypeCheckingFlags> Options,
- unsigned StartElem = 0);
+ unsigned StartElem = 0,
+ unsigned WarnLongFunctionBodies = 0);
/// Once type checking is complete, this walks protocol requirements
/// to resolve default witnesses.
@@ -175,6 +175,16 @@ static bool ParseFrontendArgs(FrontendOptions &Opts, ArgList &Args,
Opts.DebugTimeFunctionBodies |= Args.hasArg(OPT_debug_time_function_bodies);
Opts.DebugTimeCompilation |= Args.hasArg(OPT_debug_time_compilation);
+ if (const Arg *A = Args.getLastArg(OPT_warn_long_function_bodies)) {
+ unsigned attempt;
+ if (StringRef(A->getValue()).getAsInteger(10, attempt)) {
+ Diags.diagnose(SourceLoc(), diag::error_invalid_arg_value,
+ A->getAsString(Args), A->getValue());
+ } else {
+ Opts.WarnLongFunctionBodies = attempt;
+ }
+ }
+
Opts.PlaygroundTransform |= Args.hasArg(OPT_playground);
if (Args.hasArg(OPT_disable_playground_transform))
Opts.PlaygroundTransform = false;
@@ -465,10 +465,10 @@ void CompilerInstance::performSema() {
if (PrimaryBufferID == NO_SUCH_BUFFER) {
TypeCheckOptions |= TypeCheckingFlags::DelayWholeModuleChecking;
}
- if (Invocation.getFrontendOptions().DebugTimeFunctionBodies) {
+ if (options.DebugTimeFunctionBodies) {
TypeCheckOptions |= TypeCheckingFlags::DebugTimeFunctionBodies;
}
- if (Invocation.getFrontendOptions().actionIsImmediate()) {
+ if (options.actionIsImmediate()) {
TypeCheckOptions |= TypeCheckingFlags::ForImmediateMode;
}
@@ -497,7 +497,8 @@ void CompilerInstance::performSema() {
&PersistentState, DelayedCB.get());
if (mainIsPrimary) {
performTypeChecking(MainFile, PersistentState.getTopLevelContext(),
- TypeCheckOptions, CurTUElem);
+ TypeCheckOptions, CurTUElem,
+ options.WarnLongFunctionBodies);
}
CurTUElem = MainFile.Decls.size();
} while (!Done);
@@ -516,7 +517,8 @@ void CompilerInstance::performSema() {
if (auto SF = dyn_cast<SourceFile>(File))
if (PrimaryBufferID == NO_SUCH_BUFFER || SF == PrimarySourceFile)
performTypeChecking(*SF, PersistentState.getTopLevelContext(),
- TypeCheckOptions);
+ TypeCheckOptions, /*curElem*/0,
+ options.WarnLongFunctionBodies);
// Even if there were no source files, we should still record known
// protocols.
@@ -134,29 +134,56 @@ namespace {
}
};
+ /// Used for debugging which parts of the code are taking a long time to
+ /// compile.
class FunctionBodyTimer {
- PointerUnion<const AbstractFunctionDecl *,
- const AbstractClosureExpr *> Function;
+ AnyFunctionRef Function;
llvm::TimeRecord StartTime = llvm::TimeRecord::getCurrentTime();
+ unsigned WarnLimit;
+ bool ShouldDump;
public:
- FunctionBodyTimer(decltype(Function) Fn) : Function(Fn) {}
+ FunctionBodyTimer(AnyFunctionRef Fn, bool shouldDump,
+ unsigned warnLimit)
+ : Function(Fn), WarnLimit(warnLimit), ShouldDump(shouldDump) {}
+
~FunctionBodyTimer() {
llvm::TimeRecord endTime = llvm::TimeRecord::getCurrentTime(false);
auto elapsed = endTime.getProcessTime() - StartTime.getProcessTime();
- llvm::errs() << llvm::format("%0.1f", elapsed * 1000) << "ms\t";
-
- if (auto *AFD = Function.dyn_cast<const AbstractFunctionDecl *>()) {
- AFD->getLoc().print(llvm::errs(), AFD->getASTContext().SourceMgr);
- llvm::errs() << "\t";
- AFD->print(llvm::errs(), PrintOptions());
- } else {
- auto *ACE = Function.get<const AbstractClosureExpr *>();
- ACE->getLoc().print(llvm::errs(), ACE->getASTContext().SourceMgr);
- llvm::errs() << "\t(closure)";
+ unsigned elapsedMS = static_cast<unsigned>(elapsed * 1000);
+
+ ASTContext &ctx = Function.getAsDeclContext()->getASTContext();
+
+ if (ShouldDump) {
+ llvm::errs() << llvm::format("%0.1f", elapsed * 1000) << "ms\t";
+ Function.getLoc().print(llvm::errs(), ctx.SourceMgr);
+
+ if (auto *AFD = Function.getAbstractFunctionDecl()) {
+ llvm::errs() << "\t";
+ AFD->print(llvm::errs(), PrintOptions());
+ } else {
+ llvm::errs() << "\t(closure)";
+ }
+ llvm::errs() << "\n";
+ }
+
+ if (WarnLimit != 0 && elapsedMS >= WarnLimit) {
+ if (auto *AFD = Function.getAbstractFunctionDecl()) {
+ DeclName name = AFD->getFullName();
+ if (!name) {
+ if (auto *method = dyn_cast<FuncDecl>(AFD)) {
+ name = method->getAccessorStorageDecl()->getFullName();
+ }
+ }
+ ctx.Diags.diagnose(AFD, diag::debug_long_function_body,
+ AFD->getDescriptiveKind(), name,
+ elapsedMS, WarnLimit);
+ } else {
+ ctx.Diags.diagnose(Function.getLoc(), diag::debug_long_closure_body,
+ elapsedMS, WarnLimit);
+ }
}
- llvm::errs() << "\n";
}
};
}
@@ -1191,8 +1218,8 @@ bool TypeChecker::typeCheckAbstractFunctionBody(AbstractFunctionDecl *AFD) {
return false;
Optional<FunctionBodyTimer> timer;
- if (DebugTimeFunctionBodies)
- timer.emplace(AFD);
+ if (DebugTimeFunctionBodies || WarnLongFunctionBodies)
+ timer.emplace(AFD, DebugTimeFunctionBodies, WarnLongFunctionBodies);
if (typeCheckAbstractFunctionBodyUntil(AFD, SourceLoc()))
return true;
@@ -1433,8 +1460,8 @@ void TypeChecker::typeCheckClosureBody(ClosureExpr *closure) {
BraceStmt *body = closure->getBody();
Optional<FunctionBodyTimer> timer;
- if (DebugTimeFunctionBodies)
- timer.emplace(closure);
+ if (DebugTimeFunctionBodies || WarnLongFunctionBodies)
+ timer.emplace(closure, DebugTimeFunctionBodies, WarnLongFunctionBodies);
StmtChecker(*this, closure).typeCheckBody(body);
if (body) {
@@ -498,7 +498,8 @@ void swift::typeCheckExternalDefinitions(SourceFile &SF) {
void swift::performTypeChecking(SourceFile &SF, TopLevelContext &TLC,
OptionSet<TypeCheckingFlags> Options,
- unsigned StartElem) {
+ unsigned StartElem,
+ unsigned WarnLongFunctionBodies) {
if (SF.ASTStage == SourceFile::TypeChecked)
return;
@@ -516,6 +517,7 @@ void swift::performTypeChecking(SourceFile &SF, TopLevelContext &TLC,
TypeChecker TC(Ctx);
SharedTimer timer("Type checking / Semantic analysis");
+ TC.setWarnLongFunctionBodies(WarnLongFunctionBodies);
if (Options.contains(TypeCheckingFlags::DebugTimeFunctionBodies))
TC.enableDebugTimeFunctionBodies();
@@ -545,6 +545,12 @@ class TypeChecker final : public LazyResolver {
/// The index of the next response metavariable to bind to a REPL result.
unsigned NextResponseVariableIndex = 0;
+ /// If non-zero, warn when a function body takes longer than this many
+ /// milliseconds to type-check.
+ ///
+ /// Intended for debugging purposes only.
+ unsigned WarnLongFunctionBodies = 0;
+
/// If true, the time it takes to type-check each function will be dumped
/// to llvm::errs().
bool DebugTimeFunctionBodies = false;
@@ -571,6 +577,14 @@ class TypeChecker final : public LazyResolver {
DebugTimeFunctionBodies = true;
}
+ /// If \p timeInMS is non-zero, warn when a function body takes longer than
+ /// this many milliseconds to type-check.
+ ///
+ /// Intended for debugging purposes only.
+ void setWarnLongFunctionBodies(unsigned timeInMS) {
+ WarnLongFunctionBodies = timeInMS;
+ }
+
bool getInImmediateMode() {
return InImmediateMode;
}

0 comments on commit 18c7592

Please sign in to comment.