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).

Author: jrose-apple

include/swift/AST/DiagnosticsSema.def

@@ -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

include/swift/Frontend/FrontendOptions.h

@@ -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

include/swift/Option/FrontendOptions.td

@@ -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">;

include/swift/Subsystems.h

@@ -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.

lib/Frontend/CompilerInvocation.cpp

@@ -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;

lib/Frontend/Frontend.cpp

@@ -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.

lib/Sema/TypeCheckStmt.cpp

@@ -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) {

lib/Sema/TypeChecker.cpp

@@ -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();
 

lib/Sema/TypeChecker.h

@@ -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;
   }