Profile various stages of a site's build process

lib/jekyll/liquid_renderer.rb

@@ -39,6 +39,27 @@ def stats_table(n = 50)
       LiquidRenderer::Table.new(@stats).to_s(n)
     end
 
+    # rubocop:disable Metrics/AbcSize
+    def print(data)
+      cell_width  = data.keys.map(&:length).max
+      cell_border = "-" * (cell_width + 2)
+      total_time  = data.delete("TOTAL TIME")
+
+      String.new("\nBuild Process Summary:\n").tap do |table|
+        table << "-" * 22 << "\n\n"
+        table << format_data_cell("METHOD", "TIME", cell_width)
+        table << divider(cell_border)
+
+        data.each do |key, value|
+          table << format_data_cell(key, format("%.4f", value), cell_width)
+        end
+
+        table << divider(cell_border)
+        table << format_data_cell("TOTAL TIME", format("%.4f", total_time), cell_width)
+      end
+    end
+    # rubocop:enable Metrics/AbcSize
+
     def self.format_error(e, path)
       "#{e.message} in #{path}"
     end
@@ -47,5 +68,18 @@ def self.format_error(e, path)
     def new_profile_hash
       Hash.new { |hash, key| hash[key] = 0 }
     end
+
+    private
+    def format_data_cell(key, val, width)
+      String.new("").tap do |row|
+        row << key.to_s.ljust(width - 2).center(width + 2) << " | "
+        row << val.to_s.rjust(width - 4).center(width + 2) << "\n"
+      end
+    end
+
+    private
+    def divider(cell_border)
+      String.new("") << cell_border << "-+-" << cell_border << "\n"
+    end
   end
 end

lib/jekyll/site.rb

@@ -67,13 +67,8 @@ def config=(config)
     #
     # Returns nothing.
     def process
-      reset
-      read
-      generate
-      render
-      cleanup
-      write
-      print_stats if config["profile"]
+      return profile_process if config["profile"]
+      process_methods.each { |method| public_send(method) }
     end
 
     def print_stats
@@ -476,5 +471,30 @@ def render_regenerated(document, payload)
       document.output = Jekyll::Renderer.new(self, document, payload).run
       document.trigger_hooks(:post_render)
     end
+
+    private
+    def process_methods
+      %w(reset read generate render cleanup write)
+    end
+
+    private
+    def profile_process
+      profile_data = {}
+      total_time = 0
+
+      process_methods.each do |method|
+        start_time = Time.now
+        public_send(method)
+        end_time = (Time.now - start_time).round(4)
+        profile_data[method.upcase] = end_time
+        total_time += end_time
+      end
+
+      profile_data["TOTAL TIME"] = total_time
+
+      Jekyll.logger.info @liquid_renderer.print(profile_data).cyan
+      Jekyll.logger.info "\nSite Render Stats:\n------------------"
+      print_stats
+    end
   end
 end

script/default-site

@@ -16,5 +16,5 @@ ruby -e "contents = File.read('Gemfile'); File.write('Gemfile', contents.sub(/ge
 echo "$0: installing default site dependencies"
 BUNDLE_GEMFILE=Gemfile bundle install
 echo "$0: building the default site"
-BUNDLE_GEMFILE=Gemfile bundle exec jekyll build --verbose
+BUNDLE_GEMFILE=Gemfile bundle exec jekyll build --verbose --profile
 popd