[chef] Re: Re: Logging less from resources, aka using the logger for logging and not STDOUT

[Peter Norton < >]

On Mon, Mar 19, 2012 at 2:55 PM, Daniel DeLeo < "> > wrote:

On Monday, March 19, 2012 at 10:32 AM, Peter Norton wrote:

> I'm doing some work to make launching multiple systems more friendly to human observation. My specific goal right now is to force more things to go through the logger, and to only log warning or error (and not debug and info) to the console. Info and above goes to a file for later perusal if needed.
>
> However, I'm confused by this bit of code in some of the resources:
>
> opts[:log_tag] = @new_resource.to_s

> if STDOUT.tty? && !Chef::Config[:daemon] && Chef::Log.info (http://Log.info)? # <<< this specfically

> opts[:live_stream] = STDOUT
> end
>
>

> if I have Log.info (http://Log.info) defined, why is chef spamming stdout instead of using the logger? Wouldn't it make more sense to have one of the following two options:

>
> 1) Be able to disable live_stream from the resource
> 2) Have live_stream asynchronously call the logger to print log lines
>
> The pain point here is that most of the commands that I run from chef using the execute resource are not verbose (tar, cp, etc.). However, the apt LWRP uses execute for apt-get update, etc. which is incredibly verbose and which therefore drowns out all useful info in a parallel launch. Any suggestions on how to reduce this is appreciated. The option I think I'm going to have to go with at the moment is to start monkey-patching from within client.rb, but I'd like it if there was a clearer way to deal with this.
>
> Thanks,
>
> -Peter

The idea is that when you're watching the output (stdout is a tty and Chef isn't daemonized) and the log level is info or debug[0], the live stream is helpful to see what's going on with long running commands. You can disable it for everything by piping output through cat.


0. http://ruby-doc.org/stdlib-1.9.3/libdoc/logger/rdoc/index.html
--
Dan DeLeo

But I don't want to ignore everything.  My assumption is that if you have a logger, and logging levels, etc. you want to use them.  What I want to happen is that I can log info to a file, and warning to the console if I'm working interactively (e.g. a bootstrap).  What happens in this case is that instead of using the logger, chef spits to stdout, defeating the purpose of configuring logging.

BTW, to actually get the logging that I want I need to do this:

# Need to monkeypatch the logging initialization in Chef::Application                                         

class Chef::Application

  def configure_logging

    l1 = Chef::Log.init("/var/log/chef/chef-info.log")

    l1.level=(Mixlib::Log::LEVELS[:info])

    l2 = Chef::Log.init(STDOUT)

    l2.level=(Mixlib::Log::LEVELS[:warn])

    STDOUT.sync = true

    l2.formatter = Chef::Log.logger.formatter

    Chef::Log::use_log_devices([l1, l2])

  end

end

Chef::Log.warn("Logging INFO and higher to /var/log/chef/chef-info.log")

I'm not particularly happy about this, but I haven't found a better way to both have my output logged and minimize interactive spam.

-Peter