Padrino Logger Seems to Bypass boot.rb Config When Running Rake

[sgonyea]

In boot.rb, my configuration looks as follows:

      Padrino::Logger::Config[:production]  = { :log_level => :info, :stream => :to_file }
      Padrino::Logger::Config[:uat]         = Padrino::Logger::Config[:production]
      Padrino::Logger::Config[:staging]     = Padrino::Logger::Config[:production]

      Padrino::Logger::Config[:development] = { :log_level => :debug, :stream => :to_file }

Yet the Padrino.logger object looks as follows:

    #<Padrino::Logger:0x007f948e92f890 @buffer=[], @auto_flush=true, @level=0, @log=#<StringIO:0x007f948e92f9a8>, @mutex=#<Mutex:0x007f948e92f818>, @format_datetime="%d/%b/%Y %H:%M:%S", @format_message="%s -%s%s", @log_static=false>

When in the Padrino Console, the object is correct:

    #<Padrino::Logger:0x007ff863b765e8 @buffer=[], @auto_flush=true, @level=0, @log=#<File:/usr/local/share/workspace/my_project/log/development.log>, @mutex=#<Mutex:0x007ff863b76520>, @format_datetime=" ", @format_message="%s -%s%s", @log_static=false>

I'm looking into this issue, but I wanted to create this issue in the mean time.

[DAddYE]

Mmm also in padrino --pre ?

[cnadytruecar]

I notice in the Padrino::Cli Base class rake task the default for :environment is :development, and yet ENV['PADRINO_LOG_LEVEL'], which is first choice in Padrino::Logger.setup!, is defaulted to "test". Padrino::Logger.setup! seems to also eventually prefer "test". This incongruence is annoying; but then I have not spent any great deal of time in the Padrino code base.

[DAddYE]

@cnadytruecar should be fixed in --pre version. Could you check with padrino 0.10.6.c ?

[arman-h]

I'm using 10.0.6, and this issue is still there. Trying to change Logger to output to file inside a rake file:

Padrino::Logger::Config[:development] = { :log_level => :devel, :format_datetime => " [%Y-%m-%d %H:%M:%S] ", :stream => :to_file }

makes no difference. Log is outputted to console, log/development.log is not being generated.

[sgonyea]

Can someone reopen this issue? @DAddYE

[ujifgc]

Try this:

Padrino::Logger::Config[:development] = { :log_level => :devel, :format_datetime => " [%Y-%m-%d %H:%M:%S] ", :stream => :to_file }
Padrino::Logger.setup!

Without second line the logger stays the same, it's configured when someone touches Padrino.logger.

If it's enough solution, please close the issue.

[nesquena]

I think that fixes it? I am going to move to 0.11.1 either way but looks like this could be closed.

[dariocravero]

I think we should document it better, perhaps adding a commented out example on config/boot.rb would do?

Btw, was looking at this a bit better and Padrino::Logger.setup! is called on Padrino.load! so if this config is included before that line in config/boot.rb we shouldn't need to run setup! again? As a matter of fact, it does (just tried it)... Perhaps on the docs we just add that if you want to redefine logging after Padrino.load! you need to run setup!?

Thoughts @nesquena @ujifgc?

[ujifgc]

A note about configuring the logger in the docs should be enough. Do we have a chapter about configuring the app somewhere?

[nesquena]

Let's just slap in onto github wiki for now: https://github.com/padrino/padrino-framework/wiki/Configuring-the-Logger and then once we have the new site (with markdown guides) we can transfer it easily? We can do similarly for other missing docs right now.

[dariocravero]

Brilliant, I've just created that basic page. We will need to explain the options a bit better.

[Altonymous]

In boot.rb I'm trying to change the default log location for the logger.
Some things I've tried..

Attempt #1
Padrino::Logger::Config.default = { :log_level => :debug, :stream => File.open("#{PADRINO_ROOT}/log/my_custom.log", 'w') }
Padrino::Logger.setup!

Attempt #2
Padrino::Logger::Config.default = { :log_level => :debug, :stream => :to_file }
Padrino::Logger::Config[:default][:stream] = File.open("#{PADRINO_ROOT}/log/my_custom.log", 'w')
Padrino::Logger.setup!

Attempt #3
PADRINO_LOGGER = { :default => { :log_level => :debug, :stream => File.open("#{PADRINO_ROOT}/log/my_custom.log", 'w') }}
Padrino::Logger.setup!

I've also tried replacing "default" with "development" just to see if I could get it to work for development at a minimum. I've had no luck so far.

Any ideas?

[dariocravero]

Hey @Altonymous,

Could you try Padrino::Logger::Config[:default][:stream] = File.new(Padrino.root('log', "my_custom.log"), 'a+')?

You don't need Padrino::Logger.setup! afterwards then.

You would have to make sure the file path to it exists though, e.g.: FileUtils.mkdir_p(Padrino.root('log')) unless File.exists?(Padrino.root('log'))

However, I reckon we could have an easier way and instead of to_file we just let you enter the file's path directly? So it would read like this:

Padrino::Logger::Config[:default][:stream] = Padrino.root('log', "my_custom.log")

We would first compare stream against :null, :stdout, and :stderr and then try the file if the path exists? However that leaves the possibility of a custom stream out :( which is not really desirable. Another alternative is to include a file option that is used if stream == :to_file?

Thoughts? /cc @nesquena

[Altonymous]

I gave that a try. It's still not working.

Here's what it seems to be doing...

It creates development.log and then creates my_custom.log, however, it continues to log to development.log. The creation of my_custom.log is the only thing it does. This is with both with your request and the attempts I made.

[dariocravero]

Which version of Padrino are you on? Could you try edge? gem 'padrino', :github => 'padrino/padrino-framework'

[Altonymous]

We are already using...

gem 'padrino', git: 'https://github.com/padrino/padrino-framework.git', branch: 'master'

I just ran bundle update padrino to make sure it's at the latest revision, and the issue is the same.

[Altonymous]

Okay I'm getting a little further. Same issue is happening but found this in the logs...

org.jruby.rack.RackInitializationException: undefined method []=' for nil:NilClass from ~/Projects/adaptor/config/boot.rb:16:in(root)'

Line 16 is currently:
Padrino::Logger::Config[:default][:stream] = File.new(Padrino.root('log', 'adaptor.log'), 'a+')

When I drop in some puts statements...

puts "#{Padrino.root('log', 'adaptor.log')}" # ~/Projects/adaptor/log/adaptor.log
puts "#{File.new(Padrino.root('log', 'adaptor.log'), 'a+')}" ##File:0x7647df5e

[dariocravero]

Well, at least here I don't have a :default logger but :development, :production, :test. See this. Would you try with, let's say development?

[Altonymous]

I'm not following what you would want me to try?

If you are simply asking me to change it from :default to :development, I did that...

Padrino::Logger::Config[:development][:stream] = File.new(Padrino.root('log', "my_custom.log"), 'a+')

That seems to get it logging to the correct place. So it appears that it's just default I can't set?

So instead I'm doing this...

Padrino::Logger::Config[PADRINO_ENV.to_sym][:stream] = File.new(Padrino.root('log', "my_custom.log"), 'a+')

See any problems with this approach for now?

[dariocravero]

Hey @Altonymous, that approach would work alright!..

The reason why :default wasn't working like that is here:

def self.setup!
  ...
  config_level = (PADRINO_LOG_LEVEL || Padrino.env || :test).to_sym
  ...

So it will try the environmental variable PADRINO_LOG_LEVEL, followed by Padrino.env and if nothing works, it will use :test.

In your code, you can use Padrino.env instead of PADRINO_ENV since it's already a symbol.

[Altonymous]

It worked until we deployed it to one of our lower environments.

The Padrino.env is :whiskey for us which is correct. But it returns nil when using: Padrino::Logger::Config[:whiskey].

So I'm not sure how to handle this at the moment.