Replicating chef-client log and report settings when run as a service

Hi Everyone

Hopefully a very simple question, please excuse my lack of knowledge. We are running chef-client 12.5.1 on windows server 2012R2.

When I run chef-client directly from a PowerShell window using just ‘chef-client’ I get a reasonable level of detail in the log including when not_if and only_if gauds have been skipped. I also get a summary at the end of the chef-client run telling me how many resources have been updated etc.

When the chef run is started using a scheduled task (we are running the chef-client::Task cookbook) I do not get the summary of resources updated and details of not_if and only_if skips etc.

I have read about report and exception handlers, do I need to configure the chef-handler cookbook to emulate the log and report when run using chef-client? If so any idea of what to set?

Thanks in advance

David

This can depend on how you are bootstrapping, but usually the log_level in c:\chef\client.rb defaults to :auto. This is intended to have the opposite effect of what you are seeing: :warn level output from the console and :info level from the service. As to why you are getting :info level logging from the console (I prefer this too), it could be that you have a knife.rb file that is being used and is configuring the log_level to :info. As to your actual question of why the service is logging with :warn level, it may be that inside of a scheduled task, there is TTY and it is therefore choosing :warn. You can force it to use :info by changing the log_level in your client.rb.

sorry I prematurely replied. The rest of my answer was: it may be that inside of a scheduled task, there is TTY and it is therefore choosing :warn. You can force it to use :info by changing the log_level in your client.rb.

Hi Matt

Thanks for the reply! Can I take this opportunity to thank you for your amazing blog posts! We use your nodes provisioner on a daily basis and almost every issues I have had around windows and Chef has been answered by your posts!

I am slightly confused. My client.rb has log level set to :info

Running chef-client I get

* directory[c:\build] action create[2016-02-01T15:54:51+00:00] INFO: Processing directory[c:\build] action create (c:/chef/cache/cookbooks/server_config/resources/deploy_package_unc.rb line 15)

(up to date)

Running it via the scheduled task I get

[2016-02-01T15:45:35+00:00] INFO: Processing directory[c:\build] action create (c:/chef/cache/cookbooks/server_config/resources/deploy_package_unc.rb line 15)

So why do I not see the (up to date) message when run from the service and how can I get the scheduled task run to print the ‘Chef Client finished, 0/33 resources updated in 02 minutes 10 seconds’ message.

The scheduled task has the following command line

/c " C:/opscode/chef/bin/chef-client -L C:/chef/log/client.log -c C:/chef/client.rb -s 300 > NUL 2>&1"

Regards

David

Thanks for the kind words David. Really happy the posts help!

So I looked deeper into this and discovered it has nothing to do with log_level. Rather its related to log_formatters. When you run chef-client in a console, chef adds a :doc formatter to add those bits of detail. While if run under a service context, they are not included. My best guess as to why is that you can get the same information from manage in an even better format and save the disk space on the node. However, I can see use cases where the convenience of it being in the log is handy.

There is a way to get this in your log by adding a add_formatter config setting to your client.rb. This can be used to add not only the “in the box” :doc formatter but your own or third party custom formatters as well. So to get the doc formatted text into your log, add this to your client.rb:

add_formatter :doc, <path to your log file>

Now there are some gotchas here. You need to add the log path or else the formatting will basically write to the ether in a service context, The problem this presents is that if you run chef-client in a console, you have now lost your formatting on the screen and it will be in the file and all by itself, looking quite strange. One way to mitigate this is to create a separate client.rb for your service that adds this line and edit your scheduled task command line to point to that config file.

Matt