Use Rack::CommonLogger in Sinatra

Question

I have a small web-server that I wrote with Sinatra. I want to be able to log messages to a log file. I've read through http://www.sinatrarb.com/api/index.html and www.sinatrarb.com/intro.html, and I see that Rack has something called Rack::CommonLogger, but I can't find any examples of how it can be accessed and used to log messages. My app is simple so I wrote it as a top-level DSL, but I can switch to subclassing it from SinatraBase if that's part of what's required.

Answer 1

Rack::CommonLogger won't provide a logger to your main app, it will just logs the request like Apache would do.

Check the code by yourself: https://github.com/rack/rack/blob/master/lib/rack/common_logger.rb

All Rack apps have the call method that get's invoked with the HTTP Request env, if you check the call method of this middleware this is what happens:

def call(env)
  began_at = Time.now
  status, header, body = @app.call(env)
  header = Utils::HeaderHash.new(header)
  log(env, status, header, began_at)
  [status, header, body]
end

The @app in this case is the main app, the middleware is just registering the time the request began at, then it class your middleware getting the [status, header, body] triple, and then invoke a private log method with those parameters, returning the same triple that your app returned in the first place.

The logger method goes like:

def log(env, status, header, began_at)
  now = Time.now
  length = extract_content_length(header)

  logger = @logger || env['rack.errors']
  logger.write FORMAT % [
    env['HTTP_X_FORWARDED_FOR'] || env["REMOTE_ADDR"] || "-",
    env["REMOTE_USER"] || "-",
    now.strftime("%d/%b/%Y %H:%M:%S"),
    env["REQUEST_METHOD"],
    env["PATH_INFO"],
    env["QUERY_STRING"].empty? ? "" : "?"+env["QUERY_STRING"],
    env["HTTP_VERSION"],
    status.to_s[0..3],
    length,
    now - began_at ]
end

As you can tell, the log method just grabs some info from the request env, and logs in on a logger that is specified on the constructor call, if there is no logger instance then it goes to the rack.errors logger (it seems there is one by default)

The way to use it (in your config.ru):

logger = Logger.new('log/app.log')

use Rack::CommonLogger, logger
run YourApp

If you want to have a common logger in all your app, you could create a simple logger middleware:

class MyLoggerMiddleware

  def initialize(app, logger)
    @app, @logger = app, logger
  end

  def call(env)
    env['mylogger'] = @logger
    @app.call(env)
  end

end

To use it, on your config.ru:

logger = Logger.new('log/app.log')
use Rack::CommonLogger, logger
use MyLoggerMiddleware, logger
run MyApp

Hope this helps.

Answer 2

I followed what I found on this blog post - excerpted below

require 'rubygems'
require 'sinatra'

disable :run
set :env, :production
set :raise_errors, true
set :views, File.dirname(__FILE__) + '/views'
set :public, File.dirname(__FILE__) + '/public'
set :app_file, __FILE__

log = File.new("log/sinatra.log", "a")
STDOUT.reopen(log)
STDERR.reopen(log)

require 'app'
run Sinatra.application

then use puts or print. It worked for me.

Answer 3

In your config.ru:

root = ::File.dirname(__FILE__)
logfile = ::File.join(root,'logs','requests.log')

require 'logger'
class ::Logger; alias_method :write, :<<; end
logger  = ::Logger.new(logfile,'weekly')

use Rack::CommonLogger, logger

require ::File.join(root,'myapp')
run MySinatraApp.new # Subclassed from Sinatra::Application

Answer 4

Reopening STDOUT and redirecting it to a file is not a good idea if you use Passenger. It causes in my case that Passenger does not start. Read https://github.com/phusion/passenger/wiki/Debugging-application-startup-problems#stdout-redirection for this issue.

This would be the right way instead:

logger = ::File.open('log/sinatra.log', 'a+')
Sinatra::Application.use Rack::CommonLogger, logger

Answer 5

class ErrorLogger
  def initialize(file)
    @file = ::File.new(file, "a+")
    @file.sync = true
  end

  def puts(msg)
    @file.puts
    @file.write("-- ERROR -- #{Time.now.strftime("%d %b %Y %H:%M:%S %z")}: ")
    @file.puts(msg)
  end
end


class App < Sinatra::Base

  if production?
    error_logger = ErrorLogger.new('log/error.log')

    before {
      env["rack.errors"] =  error_logger
    }
  end

  ...

end