Log rails console always to file in production env

Question

As you maybe know by yourself, sometimes you have to do tasks on a live production machine, via the rails console...

I usually start it with: bundle exec rails console -e production

But since its the production machine, I would like to log all in+outputs of the rails console to a file, f.e. to /home/sshuser/myproject/console_sessions/2016_09_09__14_33_33.txt

Anybody knows how to do this? I would like to start the logger atuomatically, but only if I run the console?

(I'm running Rails 3.2) Thanks!

Answer 1

Here's a solution with only one file for a whole system, no modification to your Rails projects and no modification to your console command.

You can put this in your ~/.irbrc, I tested it with Ruby 2.1.5 and Rails 3.2/4.0/4.2 :

# ~/.irbrc for http://stackoverflow.com/questions/39411783/log-rails-console-always-to-file-in-production-env
if defined? Rails
  puts "Loading configuration for Rails console from #{__FILE__}"
  time = Time.now.strftime('%Y_%m_%d__%H_%M_%S')
  log_file = File.join(Rails.root, "log", "rails_console_#{Rails.env}_#{time}.log")
  #log_file = "/home/sshuser/myproject/console_sessions/#{time}.txt"
  puts "  logging to #{log_file}"
  logger = Logger.new(log_file)
  Rails.logger = logger
  ActiveRecord::Base.logger = logger if defined? ActiveRecord

  # Intercepts STDIN from IRB
  module Readline
    module History
      def self.write_log(line)
        Rails.logger.info(line)
      end

      def self.start_session_log
        write_log("# session start: #{Time.now}")
        at_exit { write_log(" # session stop: #{Time.now}") }
      end
    end

    alias :old_readline :readline
    def readline(*args)
      ln = old_readline(*args)
      begin
        History.write_log("STDIN : #{ln}")
      rescue
      end
      ln
    end
  end

  # $stdout writes to STDOUT and Rails.logger
  # $stderr writes to STDERR and Rails.logger
  class MultiLog
    def initialize(io)
      @io = io
      @desc = io.inspect[/STD\w+/]
    end

    def write(str)
      Rails.logger.info("#{@desc} : #{str}")
      @io.write(str)
    end

    def close
      @io.close
    end
  end

  $stdout = MultiLog.new(STDOUT)
  $stderr = MultiLog.new(STDERR)

  Readline::History.start_session_log
end

For Pry, you should use this ~/.pryrc :

# ~/.pryrc for http://stackoverflow.com/questions/39411783/log-rails-console-always-to-file-in-production-env

if defined? Rails
  puts "Loading configuration for Rails console from #{__FILE__}"
  time = Time.now.strftime('%Y_%m_%d__%H_%M_%S')
  log_file = File.join(Rails.root, "log", "rails_console_#{Rails.env}_#{time}.log")
  #log_file = "/home/sshuser/myproject/console_sessions/#{time}.txt"
  puts "  logging to #{log_file}"
  logger = Logger.new(log_file)
  Rails.logger = logger
  ActiveRecord::Base.logger = logger if defined? ActiveRecord

  # Intercepts STDIN from pry (from http://www.hardscrabble.net/2015/how-to-log-all-input-in-your-pry-rails-console)
  class LoggingReadline
    delegate :completion_proc, :completion_proc=, to: Readline

    def readline(prompt)
      Readline.readline(prompt).tap do |user_input|
        Rails.logger.info("STDIN : #{user_input}")
      end
    end
  end

  Pry.config.input = LoggingReadline.new

  # $stdout writes to STDOUT and Rails.logger
  # $stderr writes to STDERR and Rails.logger
  class MultiLog
    # Needed for #tty?, #flush : https://github.com/pry/pry/issues/1464
    def method_missing(sym,*p)
      @io.send(sym,*p)
    end

    def initialize(io)
      @io = io
      @desc = io.inspect[/STD\w+/]
    end

    def write(str)
      Rails.logger.info("#{@desc} : #{str}")
      @io.write(str)
    end

    alias_method :print, :write
  end

  $stdout = MultiLog.new(STDOUT)
  $stderr = MultiLog.new(STDERR)

end

It saves console input, output and errors, as well as database queries into the specified file. For example :

 ~/www/my_movies> bundle exec rails console -e development                                                                  
Loading development environment (Rails 4.0.4)
Loading configuration for Rails console from /home/ricou/.irbrc
  logging to /home/ricou/www/my_movies/log/rails_console_development_2016_10_28__11_58_41.log
2.1.5 :001 > Movie.first
 => Est - Ouest 
2.1.5 :002 > puts 2+2
4
 => nil 
2.1.5 :003 > exit

outputs this log file :

# Logfile created on 2016-10-28 11:58:41 +0200 by logger.rb/44203
I, [2016-10-28T11:58:41.062811 #3860]  INFO -- : # session start: 2016-10-28 11:58:41 +0200
I, [2016-10-28T11:58:46.822753 #3860]  INFO -- : STDIN : Movie.first
D, [2016-10-28T11:58:46.883974 #3860] DEBUG -- :   Movie Load (0.7ms)  SELECT "movies".* FROM "movies" ORDER BY "movies"."id" ASC LIMIT 1
I, [2016-10-28T11:58:46.896787 #3860]  INFO -- : STDOUT :  => Est - Ouest 

I, [2016-10-28T11:58:48.922083 #3860]  INFO -- : STDIN : puts 2+2
I, [2016-10-28T11:58:48.922486 #3860]  INFO -- : STDOUT : 4
I, [2016-10-28T11:58:48.922524 #3860]  INFO -- : STDOUT : 

I, [2016-10-28T11:58:48.922584 #3860]  INFO -- : STDOUT :  => nil 

I, [2016-10-28T11:58:50.341326 #3860]  INFO -- : STDIN : exit
I, [2016-10-28T11:58:50.342142 #3860]  INFO -- :  # session stop: 2016-10-28 11:58:50 +0200

Answer 2

More accurate solution with tee would be:

alias railsc="TIMESTAMP=\$(date +"%y_%d_%m_%H_%M_%S") eval 'bundle exec rails c > >(tee stdout_\${TIMESTAMP}.log) 2> >(tee stderr_\${TIMESTAMP}.log >&2)'"

But I would better write a script, not sure why it's a problem.