Django has great API documentation - as do most of the libraries and apps in the ecosystem. But I have been having a hard time finding examples that put all the pieces together. So as an aid to myself - and anyone else who is having trouble stringing image upload, thumbnail creation and S3 storage together, I put together a minimal project that supports uploading a user avatar in a Django 1.8 project. (Sorry, there are no unit tests, but the tests in the django-cleanup repository might be useful examples.)

The example is here: https://github.com/cnk/easy_thumbnails_example

Someday I may expand this to a longer post on Ruby debugging, but until then I am writing it down so I don’t have to search for it on Stack Overflow again.

If you need to debug an erb snippet in irb, this function gives you a handy shortcut for combining the template and arbitrary instance variables. Copy it into your irb session:

    require 'erb'
    require 'ostruct'

    def erb(template, vars)
      ERB.new(template).result(OpenStruct.new(vars).instance_eval { binding })
    end

And then you can use it as follows:

    erb("Hey, <%= first_name %> <%= last_name %>", :first_name => "James", :last_name => "Moriarty")
     => "Hey, James Moriarty"

Kind of handy especially if you need to test out some ruby inside the <%= %> tag.

Using Mixins Inside of Chef Recipes

There are a couple of wrinkles about mixing ruby modules into your chef code. The first appears to be that the chef DSL takes over everything (or nearly everything) - including the include command. So using normal ruby like include MyModule inside a recipe file causes a compile time error:

    ..... omitted ...
    resolving cookbooks for run list: ["testcookbook::default"]
    Synchronizing Cookbooks:
      - testcookbook
      Compiling Cookbooks...
      [2015-07-09T13:53:52-07:00] WARN: this should log node info bar from 'Chef::Log'

    ================================================================================
    Recipe Compile Error in .../testcookbook/recipes/default.rb
    ================================================================================

    NoMethodError
    -------------
    No resource or method named `include' for `Chef::Recipe "default"'

That seems odd - but it is probaby a good thing since if it worked, it might end up including your library code into the wrong place. With nearly all libraries, you want your module code available in some specific execution scope - which is probably not the compile time scope. To use our UsefulMethods module in our recipe context, we need the following in our recipe file:

    ::Chef::Recipe.send(:include, UsefulMethods)

This blog post on the Chef.io site does a really nice job of explaining how (and why) to write libraries and then use them in your recipes. In their example code, the library code needs to be used inside the user resource: Chef::Resource::User.

Creating Modules Inside a Namespace

The second example in the custom libraries section of Customizing Ruby shows another option for how to get your library code exactly where you want it. Instead of defining a generic module and then including it in your recipe, as above, you can set up your library within the namespace in which you want to use it. In the case of our UsefulModules code, we rewrite the library as a class inside the Chef::Recipe namespace:

    class Chef::Recipe::StopFile
        def self.stop_file_exists?
            ::File.exists?("/tmp/stop_chef")
        end
    end

And then in our recipe file we don’t have to send any message to include the new class. Because it was created inside the Chef::Recipe namespace, it gets loaded into our recipe context when the library file is loaded at the beginning of the chef run. We can just call the class method like so:

    if StopFile.stop_file_exists?
       ....

There are a couple of different techniques for logging during a chef client run. The simplest option for debugging things in any programming language is by adding print statements - or in the case of Ruby, puts statements (print with a newline added). However, in order for print statements to work, they need to be executed in a context where stdout is available AND where you, the user, can see stdout. When running chef manually (either using chef-client or via test kitchen’s ‘kitchen converge’ command), you are watching output go by on the console. So you can do things like:

    puts "This is normal Ruby code inside a recipe file."

And in a client run, you will see that output - in the compile phase.

    $ chef-client --once --why-run --local-mode \
                  --config /Users/cnk/Code/sandbox/customizing_chef/part3_examples/solo.rb
                  --override-runlist testcookbook::default

    Starting Chef Client, version 12.3.0
    [2015-07-09T16:25:06-07:00] WARN: Run List override has been provided.
    [2015-07-09T16:25:06-07:00] WARN: Original Run List: []
    [2015-07-09T16:25:06-07:00] WARN: Overridden Run List: [recipe[testcookbook::default]]
    resolving cookbooks for run list: ["testcookbook::default"]
    Synchronizing Cookbooks:
      - testcookbook
      Compiling Cookbooks...
      This is normal Ruby code inside a recipe file.  ########### this is the message ##########
      Converging 0 resources

    Running handlers:
      Running handlers complete
      Chef Client finished, 0/0 resources would have been updated

You can get nearly the same functionality - but with a timestamp and some terminal coloring, if you use Chef::Log in the same context:

    puts "This is a puts from the top of the default recipe; node info: #{node['foo']}"
    Chef::Log.warn("You can log node info #{node['foo']} from a recipe using 'Chef::Log'")

Gives:

     $ chef-client --once --why-run --local-mode \
                   --config /Users/cnk/Code/sandbox/customizing_chef/part3_examples/solo.rb \
                   --override-runlist testcookbook::default

     Starting Chef Client, version 12.3.0
     [2015-07-09T16:33:44-07:00] WARN: Run List override has been provided.
     [2015-07-09T16:33:44-07:00] WARN: Original Run List: []
     [2015-07-09T16:33:44-07:00] WARN: Overridden Run List: [recipe[testcookbook::default]]
     resolving cookbooks for run list: ["testcookbook::default"]
     Synchronizing Cookbooks:
       - testcookbook
       Compiling Cookbooks...
       This is a puts from the top of the default recipe; node info: bar
       [2015-07-09T16:33:44-07:00] WARN: You can log node info bar from a recipe using 'Chef::Log'
       Converging 0 resources
    Running handlers:
      Running handlers complete
      Chef Client finished, 0/0 resources would have been updated

NB the default log level for chef-client writing messages to the terminal is warn or higher. So if you try to use Chef::Log.debug('something') you won’t see your message unless you have turned up the verbosity. This unexpected feature, caused me a bit of grief initially as I couldn’t find my log messages anywhere. Now what I do is use Chef::Log.warn while debugging locally and then plan to take the messages out before I commit the code.

From my experiments, just about anywhere you might use puts, you can use Chef::Log. I think the later is probably better because it will probably put information into actual log files in contexts like test kitchen that write log files for examining later.

If you need something logged at converge time instead of compile time, you have 2 options, use the log resource, or wrap Chef::Log inside a ruby_block call. In either case, during the compile phase, a new resource gets created and added to the resouce collection. Then during the converge phase, that resource gets executed. Creating a Chef::Log statement inside a ruby_block probably isn’t too useful on its own, though it may be useful if you have created a ruby_block for some other reason. This gist has some example code and the output: https://gist.github.com/cnk/e5fa8cafea8c2953cf91

Each chef run has 2 phases - the compile phase and the converge phase.

Compile phase

In the compile phase, the chef client loads libraries, cookbooks, and recipess. Then it takes the run list, reads the listed recipes, and buids a collection of the resources that need to be executed in this run. Ruby code within the recipe may alter what resources are added to the resource collection based on information about the node. For example, if the node’s OS family is ‘debian’, package commands need to use ‘apt’ to install packages. So if you are installing emacs, the resource collection on an ubuntu box will have an ‘apt’ resource for installing that package - but the resource collection on a RHEL box will have a ‘yum’ resource instead.

The compile phase also has logic for creating a minimal, ordered collection of resources to run. Part of this process is deduplication. If multiple recipies include apt’s default recipe (which calls ‘apt-get update’), the compile phase adds this to the resource collection once. Any other calls to the same resource are reported in the run output as duplicates.

    [2015-07-09T22:34:01+00:00] WARN: Previous bash[pip install to VE]:
      /tmp/kitchen/cookbooks/dev-django-skeleton/recipes/django_project.rb:75:in `from_file'
    [2015-07-09T22:34:01+00:00] WARN: Current  bash[pip install to VE]:
      /tmp/kitchen/cookbooks/dev-django-skeleton/recipes/django_project.rb:86:in `from_file'

Converge phase

The converge phase is the phase in which the resource code actually gets run. As the each resource runs, information is added to the run status object - some of which can later be written back to the chef server as the node status at the end of the run.

Run status information

The Customizing Chef book has some useful information about what chef collects in the run status object. For example, the run status object has a reference to the node object at the start of each run (basically node information from the chef server combined with the data collected by ohai). It also has a reference to the run context object:

This object contains a variety of useful data about the overall Chef run, such as the cookbook files needed to perform the run, the list of all resources to be applied during the run, and the list of all notifications triggered by resources during the run.

Excerpt From: “Customizing Chef” chapter 5 by Jon Cowie

Two very useful methods are ‘all_resources’ and ‘updated_resources’. One of the examples on the book is a reporting handler that logs both of those lists to a log file (see Handler Example 2: Report Handler)