Log all messages (at all levels) to a filesegiddins/log-everything-in-tmp

18 files changed, 128 insertions, 50 deletions

diff --git a/lib/bundler.rb b/lib/bundler.rb
index 2411ac20c2..dc078e6b95 100644
--- a/lib/bundler.rb
+++ b/lib/bundler.rb
@@ -66,8 +66,21 @@ module Bundler
       @configured ||= configure_gem_home_and_path
     end
 
+    def ui_logger
+      @ui_logger ||= begin
+        io = begin
+          path = tmp.join("output.log")
+          File.open(path, "w")
+        rescue
+          nil
+        end
+
+        UI::Logger.new(io)
+      end
+    end
+
     def ui
-      (defined?(@ui) && @ui) || (self.ui = UI::Silent.new)
+      (defined?(@ui) && @ui) || (self.ui = UI::Silent.new(:logger => ui_logger))
     end
 
     def ui=(ui)
diff --git a/lib/bundler/cli.rb b/lib/bundler/cli.rb
index 53241b15f6..56b35ee183 100644
--- a/lib/bundler/cli.rb
+++ b/lib/bundler/cli.rb
@@ -17,7 +17,7 @@ module Bundler
     def self.start(*)
       super
     rescue Exception => e
-      Bundler.ui = UI::Shell.new
+      Bundler.ui = UI::Shell.new(:logger => Bundler.ui_logger)
       raise e
     ensure
       Bundler::SharedHelpers.print_major_deprecations!
@@ -48,7 +48,7 @@ module Bundler
     ensure
       self.options ||= {}
       unprinted_warnings = Bundler.ui.unprinted_warnings
-      Bundler.ui = UI::Shell.new(options)
+      Bundler.ui = UI::Shell.new(options.merge(:logger => Bundler.ui_logger))
       Bundler.ui.level = "debug" if options["verbose"]
       unprinted_warnings.each {|w| Bundler.ui.warn(w) }
 
diff --git a/lib/bundler/cli/lock.rb b/lib/bundler/cli/lock.rb
index 7dd078b1ef..d87931670b 100644
--- a/lib/bundler/cli/lock.rb
+++ b/lib/bundler/cli/lock.rb
@@ -16,7 +16,7 @@ module Bundler
 
       print = options[:print]
       ui = Bundler.ui
-      Bundler.ui = UI::Silent.new if print
+      Bundler.ui = UI::Silent.new(:logger => Bundler.ui_logger) if print
 
       Bundler::Fetcher.disable_endpoint = options["full-index"]
 
diff --git a/lib/bundler/env.rb b/lib/bundler/env.rb
index 51738139fa..b1c17815c9 100644
--- a/lib/bundler/env.rb
+++ b/lib/bundler/env.rb
@@ -12,6 +12,7 @@ module Bundler
     def self.report(options = {})
       print_gemfile = options.delete(:print_gemfile) { true }
       print_gemspecs = options.delete(:print_gemspecs) { true }
+      print_log = options.delete(:print_log) { false }
 
       out = String.new
       append_formatted_table("Environment", environment, out)
@@ -28,33 +29,41 @@ module Bundler
         out << "```\n"
       end
 
-      return out unless SharedHelpers.in_bundle?
+      if SharedHelpers.in_bundle?
+        if print_gemfile
+          gemfiles = [Bundler.default_gemfile]
+          begin
+            gemfiles = Bundler.definition.gemfiles
+          rescue GemfileNotFound
+            nil
+          end
 
-      if print_gemfile
-        gemfiles = [Bundler.default_gemfile]
-        begin
-          gemfiles = Bundler.definition.gemfiles
-        rescue GemfileNotFound
-          nil
-        end
+          out << "\n## Gemfile\n"
+          gemfiles.each do |gemfile|
+            out << "\n### #{Pathname.new(gemfile).relative_path_from(SharedHelpers.pwd)}\n\n"
+            out << "```ruby\n" << read_file(gemfile).chomp << "\n```\n"
+          end
 
-        out << "\n## Gemfile\n"
-        gemfiles.each do |gemfile|
-          out << "\n### #{Pathname.new(gemfile).relative_path_from(SharedHelpers.pwd)}\n\n"
-          out << "```ruby\n" << read_file(gemfile).chomp << "\n```\n"
+          out << "\n### #{Bundler.default_lockfile.relative_path_from(SharedHelpers.pwd)}\n\n"
+          out << "```\n" << read_file(Bundler.default_lockfile).chomp << "\n```\n"
         end
 
-        out << "\n### #{Bundler.default_lockfile.relative_path_from(SharedHelpers.pwd)}\n\n"
-        out << "```\n" << read_file(Bundler.default_lockfile).chomp << "\n```\n"
+        if print_gemspecs
+          dsl = Dsl.new.tap {|d| d.eval_gemfile(Bundler.default_gemfile) }
+          out << "\n## Gemspecs\n" unless dsl.gemspecs.empty?
+          dsl.gemspecs.each do |gs|
+            out << "\n### #{File.basename(gs.loaded_from)}"
+            out << "\n\n```ruby\n" << read_file(gs.loaded_from).chomp << "\n```\n"
+          end
+        end
       end
 
-      if print_gemspecs
-        dsl = Dsl.new.tap {|d| d.eval_gemfile(Bundler.default_gemfile) }
-        out << "\n## Gemspecs\n" unless dsl.gemspecs.empty?
-        dsl.gemspecs.each do |gs|
-          out << "\n### #{File.basename(gs.loaded_from)}"
-          out << "\n\n```ruby\n" << read_file(gs.loaded_from).chomp << "\n```\n"
-        end
+      if print_log && log = Bundler.ui_logger.path
+        Bundler.ui_logger.flush
+        out << "\n## Log\n\n"
+        out << "<details><summary>The full bundler log</summary>\n\n"
+        out << "```\n" << read_file(log) << "\n```\n"
+        out << "\n</details>\n"
       end
 
       out
diff --git a/lib/bundler/fetcher.rb b/lib/bundler/fetcher.rb
index 4dd42e42ff..6f5c9feacf 100644
--- a/lib/bundler/fetcher.rb
+++ b/lib/bundler/fetcher.rb
@@ -146,7 +146,7 @@ module Bundler
 
       index
     rescue CertificateFailureError
-      Bundler.ui.info "" if gem_names && use_api # newline after dots
+      Bundler.ui.post_log_progress if gem_names && use_api # newline after dots
       raise
     ensure
       Bundler.rubygems.sources = old
diff --git a/lib/bundler/fetcher/base.rb b/lib/bundler/fetcher/base.rb
index 27987f670a..95ea3702b2 100644
--- a/lib/bundler/fetcher/base.rb
+++ b/lib/bundler/fetcher/base.rb
@@ -41,11 +41,8 @@ module Bundler
     private
 
       def log_specs(debug_msg)
-        if Bundler.ui.debug?
-          Bundler.ui.debug debug_msg
-        else
-          Bundler.ui.info ".", false
-        end
+        Bundler.ui.log_progress unless Bundler.ui.debug?
+        Bundler.ui.debug debug_msg
       end
     end
   end
diff --git a/lib/bundler/fetcher/dependency.rb b/lib/bundler/fetcher/dependency.rb
index 1430d1ebeb..e740a21531 100644
--- a/lib/bundler/fetcher/dependency.rb
+++ b/lib/bundler/fetcher/dependency.rb
@@ -35,11 +35,11 @@ module Bundler
         returned_gems = spec_list.map(&:first).uniq
         specs(deps_list, full_dependency_list + returned_gems, spec_list + last_spec_list)
       rescue MarshalError
-        Bundler.ui.info "" unless Bundler.ui.debug? # new line now that the dots are over
+        Bundler.ui.post_log_progress unless Bundler.ui.debug? # new line now that the dots are over
         Bundler.ui.debug "could not fetch from the dependency API, trying the full index"
         nil
       rescue HTTPError, GemspecError
-        Bundler.ui.info "" unless Bundler.ui.debug? # new line now that the dots are over
+        Bundler.ui.post_log_progress unless Bundler.ui.debug? # new line now that the dots are over
         Bundler.ui.debug "could not fetch from the dependency API\nit's suggested to retry using the full index via `bundle install --full-index`"
         nil
       end
diff --git a/lib/bundler/friendly_errors.rb b/lib/bundler/friendly_errors.rb
index ae3299a7c8..0020ac17c4 100644
--- a/lib/bundler/friendly_errors.rb
+++ b/lib/bundler/friendly_errors.rb
@@ -45,6 +45,10 @@ module Bundler
           "Alternatively, you can increase the amount of memory the JVM is able to use by running Bundler with jruby -J-Xmx1024m -S bundle (JRuby defaults to 500MB)."
       else request_issue_report_for(error)
       end
+
+      if log = Bundler.ui_logger.path
+        Bundler.ui.error "\nThe full bundler log is available in #{log}"
+      end
     rescue
       raise error
     end
@@ -95,7 +99,7 @@ module Bundler
           #{e.backtrace && e.backtrace.join("\n          ").chomp}
         ```
 
-        #{Bundler::Env.report}
+        #{Bundler::Env.report(:print_log => true)}
         --- TEMPLATE END ----------------------------------------------------------------
 
       EOS
diff --git a/lib/bundler/gem_helper.rb b/lib/bundler/gem_helper.rb
index 8ed1af231f..79630d513f 100644
--- a/lib/bundler/gem_helper.rb
+++ b/lib/bundler/gem_helper.rb
@@ -26,7 +26,7 @@ module Bundler
     attr_reader :spec_path, :base, :gemspec
 
     def initialize(base = nil, name = nil)
-      Bundler.ui = UI::Shell.new
+      Bundler.ui = UI::Shell.new(:logger => Bundler.ui_logger)
       @base = (base ||= SharedHelpers.pwd)
       gemspecs = name ? [File.join(base, "#{name}.gemspec")] : Dir[File.join(base, "{,*}.gemspec")]
       raise "Unable to determine name from existing gemspec. Use :name => 'gemname' in #install_tasks to manually set it." unless gemspecs.size == 1
diff --git a/lib/bundler/inline.rb b/lib/bundler/inline.rb
index 9d25f3261a..ba39141cfc 100644
--- a/lib/bundler/inline.rb
+++ b/lib/bundler/inline.rb
@@ -35,7 +35,7 @@ def gemfile(install = false, options = {}, &gemfile)
   require "bundler"
 
   opts = options.dup
-  ui = opts.delete(:ui) { Bundler::UI::Shell.new }
+  ui = opts.delete(:ui) { Bundler::UI::Shell.new(:logger => Bundler.ui_logger) }
   raise ArgumentError, "Unknown options: #{opts.keys.join(", ")}" unless opts.empty?
 
   old_root = Bundler.method(:root)
diff --git a/lib/bundler/resolver.rb b/lib/bundler/resolver.rb
index fac28ced90..d067203478 100644
--- a/lib/bundler/resolver.rb
+++ b/lib/bundler/resolver.rb
@@ -92,7 +92,7 @@ module Bundler
     end
 
     def indicate_progress
-      Bundler.ui.info ".", false unless debug?
+      Bundler.ui.log_progress unless debug?
     end
 
     include Molinillo::SpecificationProvider
diff --git a/lib/bundler/retry.rb b/lib/bundler/retry.rb
index 5e4f0c502d..4ce921d2b5 100644
--- a/lib/bundler/retry.rb
+++ b/lib/bundler/retry.rb
@@ -45,11 +45,11 @@ module Bundler
     def fail_attempt(e)
       @failed = true
       if last_attempt? || @exceptions.any? {|k| e.is_a?(k) }
-        Bundler.ui.info "" unless Bundler.ui.debug?
+        Bundler.ui.post_log_progress unless Bundler.ui.debug?
         raise e
       end
       return true unless name
-      Bundler.ui.info "" unless Bundler.ui.debug? # Add new line incase dots preceded this
+      Bundler.ui.post_log_progress unless Bundler.ui.debug? # Add new line incase dots preceded this
       Bundler.ui.warn "Retrying #{name} due to error (#{current_run.next}/#{total_runs}): #{e.class} #{e.message}", Bundler.ui.debug?
     end
 
diff --git a/lib/bundler/shared_helpers.rb b/lib/bundler/shared_helpers.rb
index dca17885dd..b45a86a314 100644
--- a/lib/bundler/shared_helpers.rb
+++ b/lib/bundler/shared_helpers.rb
@@ -147,7 +147,7 @@ module Bundler
       end
 
       return unless bundler_major_version >= major_version || prints_major_deprecations?
-      @major_deprecation_ui ||= Bundler::UI::Shell.new("no-color" => true)
+      @major_deprecation_ui ||= Bundler::UI::Shell.new("no-color" => true, :logger => Bundler.ui_logger)
       ui = Bundler.ui.is_a?(@major_deprecation_ui.class) ? Bundler.ui : @major_deprecation_ui
       ui.warn("[DEPRECATED FOR #{major_version}.0] #{message}")
     end
diff --git a/lib/bundler/source/rubygems.rb b/lib/bundler/source/rubygems.rb
index 9e5032c079..315b41ff23 100644
--- a/lib/bundler/source/rubygems.rb
+++ b/lib/bundler/source/rubygems.rb
@@ -411,7 +411,7 @@ module Bundler
           if dependency_names
             Bundler.ui.info "Fetching gem metadata from #{f.uri}", Bundler.ui.debug?
             index.use f.specs_with_retry(dependency_names, self), override_dupes
-            Bundler.ui.info "" unless Bundler.ui.debug? # new line now that the dots are over
+            Bundler.ui.post_log_progress unless Bundler.ui.debug? # new line now that the dots are over
           else
             Bundler.ui.info "Fetching source index from #{f.uri}"
             index.use f.specs_with_retry(nil, self), override_dupes
diff --git a/lib/bundler/ui.rb b/lib/bundler/ui.rb
index 8138b30d38..6dffd283eb 100644
--- a/lib/bundler/ui.rb
+++ b/lib/bundler/ui.rb
@@ -2,6 +2,7 @@
 
 module Bundler
   module UI
+    autoload :Logger,  "bundler/ui/logger"
     autoload :RGProxy, "bundler/ui/rg_proxy"
     autoload :Shell,   "bundler/ui/shell"
     autoload :Silent,  "bundler/ui/silent"
diff --git a/lib/bundler/ui/logger.rb b/lib/bundler/ui/logger.rb
new file mode 100644
index 0000000000..9ac6eb36a6
--- /dev/null
+++ b/lib/bundler/ui/logger.rb
@@ -0,0 +1,33 @@
+# frozen_string_literal: true
+
+module Bundler
+  module UI
+    class Logger
+      LEVEL_PADDING = UI::Shell::LEVELS.map(&:size).max + 2
+      private_constant :LEVEL_PADDING
+
+      attr_reader :io
+
+      def initialize(io)
+        @io = io
+      end
+
+      def log(level, message)
+        return unless io
+        level_string = "[#{level}]".rjust(LEVEL_PADDING)
+        time = Time.now.utc.strftime("%FT%T.%3NZ")
+        prefix = "#{time} #{level_string} "
+        padding = prefix.size - 3
+        io << prefix << message.gsub(/(?<!\A)^/, " " * padding + " | ") << "\n"
+      end
+
+      def path
+        io.respond_to?(:path) && io.path
+      end
+
+      def flush
+        io.respond_to?(:flush) && io.flush
+      end
+    end
+  end
+end
diff --git a/lib/bundler/ui/shell.rb b/lib/bundler/ui/shell.rb
index 16e3d15713..debe03b9b1 100644
--- a/lib/bundler/ui/shell.rb
+++ b/lib/bundler/ui/shell.rb
@@ -15,6 +15,7 @@ module Bundler
         end
         @shell = Thor::Base.shell.new
         @level = ENV["DEBUG"] ? "debug" : "info"
+        @logger = options[:logger]
         @warning_history = []
       end
 
@@ -23,14 +24,17 @@ module Bundler
       end
 
       def info(msg, newline = nil)
+        @logger.log(__method__, msg)
         tell_me(msg, nil, newline) if level("info")
       end
 
       def confirm(msg, newline = nil)
+        @logger.log(__method__, msg)
         tell_me(msg, :green, newline) if level("confirm")
       end
 
       def warn(msg, newline = nil)
+        @logger.log(__method__, msg)
         return unless level("warn")
         return if @warning_history.include? msg
         @warning_history << msg
@@ -40,12 +44,14 @@ module Bundler
       end
 
       def error(msg, newline = nil)
+        @logger.log(__method__, msg)
         return unless level("error")
         return tell_err(msg, :red, newline) if Bundler.feature_flag.error_on_stderr?
         tell_me(msg, :red, newline)
       end
 
       def debug(msg, newline = nil)
+        @logger.log(__method__, msg)
         tell_me(msg, nil, newline) if debug?
       end
 
@@ -58,6 +64,7 @@ module Bundler
       end
 
       def ask(msg)
+        @logger.log(__method__, msg)
         @shell.ask(msg)
       end
 
@@ -65,10 +72,6 @@ module Bundler
         @shell.yes?(msg)
       end
 
-      def no?
-        @shell.no?(msg)
-      end
-
       def level=(level)
         raise ArgumentError unless LEVELS.include?(level.to_s)
         @level = level.to_s
@@ -83,11 +86,22 @@ module Bundler
       end
 
       def trace(e, newline = nil, force = false)
+        @logger.log(__method__, "#{e.class}: #{e.message}")
         return unless debug? || force
         msg = "#{e.class}: #{e.message}\n#{e.backtrace.join("\n  ")}"
         tell_me(msg, nil, newline)
       end
 
+      def log_progress
+        return unless level("info")
+        tell_me(".", nil, false)
+      end
+
+      def post_log_progress
+        return if debug?
+        tell_me("", nil, nil)
+      end
+
       def silence(&blk)
         with_level("silent", &blk)
       end
diff --git a/lib/bundler/ui/silent.rb b/lib/bundler/ui/silent.rb
index dca1b2ac86..e7354a046b 100644
--- a/lib/bundler/ui/silent.rb
+++ b/lib/bundler/ui/silent.rb
@@ -5,8 +5,9 @@ module Bundler
     class Silent
       attr_writer :shell
 
-      def initialize
+      def initialize(options = {})
         @warnings = []
+        @logger = options[:logger]
       end
 
       def add_color(string, color)
@@ -14,19 +15,24 @@ module Bundler
       end
 
       def info(message, newline = nil)
+        @logger.log(__method__, msg)
       end
 
       def confirm(message, newline = nil)
+        @logger.log(__method__, msg)
       end
 
       def warn(message, newline = nil)
+        @logger.log(__method__, msg)
         @warnings |= [message]
       end
 
       def error(message, newline = nil)
+        @logger.log(__method__, msg)
       end
 
       def debug(message, newline = nil)
+        @logger.log(__method__, msg)
       end
 
       def debug?
@@ -38,16 +44,13 @@ module Bundler
       end
 
       def ask(message)
+        @logger.log(__method__, msg)
       end
 
       def yes?(msg)
         raise "Cannot ask yes? with a silent shell"
       end
 
-      def no?
-        raise "Cannot ask no? with a silent shell"
-      end
-
       def level=(name)
       end
 
@@ -55,6 +58,10 @@ module Bundler
       end
 
       def trace(message, newline = nil, force = false)
+        @logger.log(__method__, "#{e.class}: #{e.message}")
+      end
+
+      def log_progress
       end
 
       def silence