From 589b122416fc120a5a4efbf4ac031e4a9dd6a554 Mon Sep 17 00:00:00 2001
From: Ashwin Maroli <ashmaroli@users.noreply.github.com>
Date: Thu, 21 May 2020 15:36:14 +0530
Subject: [PATCH] Profile various stages of a site's build process (#6760)

Merge pull request 6760
---
 .rubocop.yml                        |  1 +
 lib/jekyll.rb                       |  1 +
 lib/jekyll/liquid_renderer/table.rb | 22 +----------
 lib/jekyll/profiler.rb              | 58 +++++++++++++++++++++++++++++
 lib/jekyll/site.rb                  |  6 ++-
 5 files changed, 65 insertions(+), 23 deletions(-)
 create mode 100644 lib/jekyll/profiler.rb

diff --git a/.rubocop.yml b/.rubocop.yml
index e0caab0dcd1..7a4e8b87a6a 100644
--- a/.rubocop.yml
+++ b/.rubocop.yml
@@ -139,6 +139,7 @@ Style/FormatStringToken:
   Exclude:
     - lib/jekyll/utils/ansi.rb
     - lib/jekyll/liquid_renderer/table.rb
+    - lib/jekyll/profiler.rb
 Style/FrozenStringLiteralComment:
   EnforcedStyle: always
 Style/GuardClause:
diff --git a/lib/jekyll.rb b/lib/jekyll.rb
index a1e59fb9a76..15e7c90c8fc 100644
--- a/lib/jekyll.rb
+++ b/lib/jekyll.rb
@@ -69,6 +69,7 @@ module Jekyll
   autoload :PathManager,         "jekyll/path_manager"
   autoload :PluginManager,       "jekyll/plugin_manager"
   autoload :Publisher,           "jekyll/publisher"
+  autoload :Profiler,            "jekyll/profiler"
   autoload :Reader,              "jekyll/reader"
   autoload :Regenerator,         "jekyll/regenerator"
   autoload :RelatedPosts,        "jekyll/related_posts"
diff --git a/lib/jekyll/liquid_renderer/table.rb b/lib/jekyll/liquid_renderer/table.rb
index a55bb8c9201..b354b15d379 100644
--- a/lib/jekyll/liquid_renderer/table.rb
+++ b/lib/jekyll/liquid_renderer/table.rb
@@ -10,31 +10,11 @@ def initialize(stats)
       end
 
       def to_s(num_of_rows = 50)
-        tabulate(data_for_table(num_of_rows))
+        Jekyll::Profiler.tabulate(data_for_table(num_of_rows))
       end
 
       private
 
-      def tabulate(data)
-        require "terminal-table"
-
-        header = data.shift
-        footer = data.pop
-        output = +"\n"
-
-        table = Terminal::Table.new do |t|
-          t << header
-          t << :separator
-          data.each { |row| t << row }
-          t << :separator
-          t << footer
-          t.style = { :alignment => :right, :border_top => false, :border_bottom => false }
-          t.align_column(0, :left)
-        end
-
-        output << table.to_s << "\n"
-      end
-
       # rubocop:disable Metrics/AbcSize
       def data_for_table(num_of_rows)
         sorted = @stats.sort_by { |_, file_stats| -file_stats[:time] }
diff --git a/lib/jekyll/profiler.rb b/lib/jekyll/profiler.rb
new file mode 100644
index 00000000000..0025912cf00
--- /dev/null
+++ b/lib/jekyll/profiler.rb
@@ -0,0 +1,58 @@
+# frozen_string_literal: true
+
+module Jekyll
+  class Profiler
+    TERMINAL_TABLE_STYLES = {
+      :alignment     => :right,
+      :border_top    => false,
+      :border_bottom => false,
+    }.freeze
+    private_constant :TERMINAL_TABLE_STYLES
+
+    def self.tabulate(table_rows)
+      require "terminal-table"
+
+      rows   = table_rows.dup
+      header = rows.shift
+      footer = rows.pop
+      output = +"\n"
+
+      table = Terminal::Table.new do |t|
+        t << header
+        t << :separator
+        rows.each { |row| t << row }
+        t << :separator
+        t << footer
+        t.style = TERMINAL_TABLE_STYLES
+        t.align_column(0, :left)
+      end
+
+      output << table.to_s << "\n"
+    end
+
+    def initialize(site)
+      @site = site
+    end
+
+    def profile_process
+      profile_data = { "PHASE" => "TIME" }
+      total_time = 0
+
+      [:reset, :read, :generate, :render, :cleanup, :write].each do |method|
+        start_time = Time.now
+        @site.send(method)
+        end_time = (Time.now - start_time).round(4)
+        profile_data[method.to_s.upcase] = format("%.4f", end_time)
+        total_time += end_time
+      end
+
+      profile_data["TOTAL TIME"] = format("%.4f", total_time)
+
+      Jekyll.logger.info "\nBuild Process Summary:"
+      Jekyll.logger.info Profiler.tabulate(Array(profile_data))
+
+      Jekyll.logger.info "\nSite Render Stats:"
+      @site.print_stats
+    end
+  end
+end
diff --git a/lib/jekyll/site.rb b/lib/jekyll/site.rb
index da8dce68d3c..b90999e7dca 100644
--- a/lib/jekyll/site.rb
+++ b/lib/jekyll/site.rb
@@ -10,7 +10,7 @@ class Site
                   :gems, :plugin_manager, :theme
 
     attr_accessor :converters, :generators, :reader
-    attr_reader   :regenerator, :liquid_renderer, :includes_load_paths, :filter_cache
+    attr_reader   :regenerator, :liquid_renderer, :includes_load_paths, :filter_cache, :profiler
 
     # Public: Initialize a new Site.
     #
@@ -26,6 +26,7 @@ def initialize(config)
       @filter_cache    = {}
 
       @reader          = Reader.new(self)
+      @profiler        = Profiler.new(self)
       @regenerator     = Regenerator.new(self)
       @liquid_renderer = LiquidRenderer.new(self)
 
@@ -71,13 +72,14 @@ def config=(config)
     #
     # Returns nothing.
     def process
+      return profiler.profile_process if config["profile"]
+
       reset
       read
       generate
       render
       cleanup
       write
-      print_stats if config["profile"]
     end
 
     def print_stats