routing logging to file #484

Closed
auxbuss opened this Issue Mar 12, 2012 · 39 comments
@auxbuss

What is the canonical method for writing the sinatra log to a file?

Say I have the following:

require "sinatra/base"

module App
  class Main < Sinatra::Base

    configure do
      enable :logging
    end

    before do
      logger.datetime_format = "%Y/%m/%d @ %H:%M:%S "
      logger.level = Logger::INFO
    end

    get '/' do
      logger.debug "debug message"
      logger.info "info message"
      "hello world"
    end
  end
end

I basically want to say, somewhere:

logger = Logger.new('log/app.log', 5, 'weekly')

How do I do that?

@rkh
Sinatra member

Usually the Rack handler takes care of setting the proper log file, eg with thin -l FILE, you could always just use ruby app.rb 2>&1 >FILE, but as you want something more advanced, here is how you could do it:

before { env['rack.logger'] = Logger.new(...)  }

Look into Rack's logging middleware for more options.

@rkh rkh closed this Mar 12, 2012
@auxbuss

I'm fine with the Rack handler taking care of things, that's what I'd like to do, but despite my best efforts, I can't figure out how to do this in production where I'm using nginx and passenger. Is your solution above the best in that case?

@rkh
Sinatra member

I don't know, I haven't used Passenger to deploy Sinatra, I would just start checking the docs/code right now.

@ryanwi

Glad I'm not the only one struggling to figure out how to do basic logging with Sinatra. Same thing in my case with Passenger+Sinatra. Everything written about logging in Sinatra seems to be at least 2 years old, I guess the world has moved on to Node.js or something.

@auxbuss, did you ever come up with a solution? How did you separate logging config between Passenger and Sinatra?

@rkh rkh reopened this Apr 4, 2012
@yeban

A look into Rack::Logger suggests that setting rack.errors environment variable to the desired file name should work. Something like this perhaps:

before { env['rack.errors'] = '~/app.error.log'  }
@auxbuss

@ryanwi I wrote my own. I don't mean to sound snarky, but there doesn't seem to be much interest in sorting this out. I also added to an issue with nginx -- I'm not sure where the problem is -- as sinatra is writing to both standard and error logs, and that doesn't fly in production. http://forum.nginx.org/read.php?2,223288,223288#msg-223288

I've tried reopening logs and so on, but it never fixes all the issues. You can fix it by building loggers in before but it's all very messy; I'd prefer to have everything set-up during start-up, which makes sense with a daemon.

In the end I got frustrated trying to fix it, and the amount of time wasted, so rolled my own.

@rkh
Sinatra member
@auxbuss

No problem. I understand it's a tricky one to fix. I was going to tackle the passenger folk, but I ran out of energy. It needs someone who knows all the components, I think, and I don't have enough detailed knowledge of the innards of any of them.

@rkh
Sinatra member
rkh commented Apr 4, 2012

I will look into this, though I have some other things to deal with, first. Let's have some easy solution for the 1.4.0 release.

@rkh rkh was assigned Apr 4, 2012
@bugant

I'm also struggling with this issue in a Passenger + Sinatra environment. Any news?

@auxbuss

I moved to fluentd. I run it as a daemon, but it's trivial to use under foreman also. I doubt I'll be returning to any logger-type solution.

@seanredmond

There has to be a simple solution to this, no? If I don't try to set up any logging and run my app everything goes to stdout, I want to run it as a daemon (rackup -D) so I need the logs to go somewhere and the recipes I've found either don't work or are too poorly explained to sort out. The best result I've gotten is to see the log file created but nothing ever goes into it.

A common answer seems to be "Why don't you use Passenger?" but my particular app won't run in passenger.

@tuupola

When using Passenger and Sinatra I just reopen stdout and stderr to a log file in my config.ru. Works for my needs.

require "rubygems"
require "bundler/setup"

Bundler.require(:default)

require "app"

root_dir = File.dirname(__FILE__)

set :environment, ENV["RACK_ENV"].to_sym
set :root,        root_dir
set :app_file,    File.join(root_dir, "app.rb")
disable :run

log = File.new("log/sinatra.log", "a+")
$stdout.reopen(log)
$stderr.reopen(log)

run Sinatra::Application
@seanredmond

Thanks, @tuupola. The most common recipe is the one you give

log = File.new("log/sinatra.log", "a+") 
$stdout.reopen(log)
$stderr.reopen(log)

Maybe it works with Passenger but, like I said, I can't use Passenger and when I add this to my config.ru here's what happens:

  • If I run it as a daemon, no logging (log file is created but it's empy)
  • If I don't run it as a daemon, the log file is created but it's empty until I kill the server, then the entire log is dumped into the file at once.

Needless to say neither of these is really useful.

@seanredmond

Here's a curious twist. If I log STDOUT and STDERR separately:

sudo rackup >> stdout.log 2>> stderr.log

STDERR works like you'd expect (i.e. you can tail it and see the log messages rolling in) but nothing happens on STDOUT until I kill the server, then as I described above, a bunch of backed up up messages get dumped into a file at once.

So what's up with STDOUT?

@bugant

@seanredmond try with (after having reopen the two file descriptors)

$stderr.sync = true
$stdout.sync = true

@seanredmond

And one more. If I put it in the background:

sudo rackup >> stdout.log 2>> stderr.log &

I never get any output from STDOUT. stdout.log is empty even after killing the process.

@seanredmond

Aha! @bugant, that works (mostly)!

log = File.new("log/sinatra.log", "a+") 
$stdout.reopen(log)
$stderr.reopen(log)

$stderr.sync = true
$stdout.sync = true

It works if you run it straight and when you put it in the background (rackup &) but not when you run it as a daemon (rackup -D).

@ericgj

Having dealt with the tricky question of logging in Sinatra recently I found this thread on the sinatra mailing list helpful, particularly Randy Fischer's notes.

@seanredmond

Ok, this stdout.sync thing turns out to be a pretty common gotcha. I think documenting this one item would save a lot of anguish when people just want really simple logging.

@renich

Any progress or comments on this one?

@rkh
Sinatra member

To solve this, we have to get rid of all Rack logging.

@renich

Is it in progress or is it too big of a task to undertake just for the sake of sinatra?

@rkh
Sinatra member
rkh commented Mar 1, 2013

It's in the "planned but not yet being worked on" state. I wanna do a major rewrite anyways, which will make this very easy.

@renich

Great news; thanks

@zzak zzak referenced this issue in sinatra/sinatra-recipes Mar 17, 2013
Merged

Add a recipe about Rack::CommonLogger #43

@bambery

This recipe did not work for me, or at least, not as I anticipated it would from reading the recipe. It would only write the requests to the log file, but none of the errors or any of the logger messages I set. @tuupola's strategy worked for me to be able to write all of my output to a file. It has been frustrating attempting to get this working. The recipe, if it is working as expected, should have its description updated to include that it will only write requests and no other logs to the file, or if it should be writing all logs to the file, there is some missing information on that page as to how to get that working.

@rb2k

A small problem I have in relation to this is that within the configure block, I don't have access to env and thus I don't have access to either env['rack.logger'] and Sinatra hasn't defined its own logger from what I can tell

@rkh
Sinatra member

Confirm. This is an issue with Rack in general. I'm not sure how to solve this yet. Maybe Sinatra should not use rack.logger at all? That would suck, too, though.

@rb2k

So for now, to be able to log everywhere, I'd have to:

  1. Have a little logger middleware that sets env['rack.logger']
    This will be used by Sinatra within the routes if somebody calls e.g. logger.info('bla')

  2. require and set that same customer logger in configure do, because within there we don't have access to anything env related

@rkh
Sinatra member

Confirm.

@rb2k

Sorry to bring this up again, but what would be the relevance of env['rack.error'] ?
A few stackoverflow questions also mention that. Would I also have to set that?

@rkh
Sinatra member
rkh commented Jun 3, 2013

In Rack land, that's the IO object you're supposed to log to. More specific, middleware setting env['rack.logger'] usually uses it.

@fguillen

Do we have a already a solution for Sinatra logging to a file?

@907th

Hi to all! I just proposed a solution for custom logging capabilities for Sinatra apps in this PR to sinatra-contrib repo. Can you look at it? Thanks!

@simrb

So, the solution is this ? #484 (comment)

@907th

@simrb Solution for what? It just forwards stdout output to the file. If you want to use custom logger you would try sinatra/custom_logger extension from sinatra-contrib gem.
PS. It is not released yet, so you need to use github version of the gem.

@simrb

@907th The solution of how to write the log to file in the newest version of Sinatra.

@zzak
Sinatra member

I believe this can be worked around by using custom_logger as explained in this comment: #484 (comment)

Since this has been released and works to solve this issue, I'm giving this ticket a close.

If anyone has some ideas how to make this experience better, please submit a patch :)

@zzak zzak closed this Jan 31, 2016
@diei
diei commented May 25, 2016 edited

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

This works for me:

logger = ::File.open('log/sinatra.log', 'a+')
Sinatra::Application.use Rack::CommonLogger, logger
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment