This article is archived, the information has been updated or reformatted into the Getting Started with iRules series in the Logging & Comments article.

So, you've written you're first "Hello World" iRule and are now ready to move past the simple "when HTTP_RESPONSE" and "HTTP::respond 200 content {Hello World}" and move on to something a bit more, um, practical.  Well, the first thing you are going to be asking yourself is how you go about debugging the code that you've written.  This article will go over several debugging techniques that will hopefully help you build self-diagnosing iRules. Other articles in the series: 

Logging

The first tool you will want to arm yourself with is the iRules "log" command.  The syntax for the log is

log [<facility>.<level>] <message>

facility : "local0", "local1", "local2", "local3", "local4", "local5", "local6", "local7"
level: "alert", "crit", "debug", "emerg", "err", "error", "info", "none", "notice", "panic", "warn", "warning"

While the facility and level parameters are optional, it is good to know that there is a significant behavioral difference when the optional <facility>.<level> is specified. When iRule logs messages without the facility and/or level, they are rate-limited as a class and subsequently logged messages within the rate-limit period may be suppressed even though they are textually different. However, when the <facility> and/or <level> are specified, the log messages are not rate-limited (though syslog-ng will still perform suppression of repeated duplicates).

Whew, that's a lot of options.  Lucky for you all that unless you are doing some customization in syslog-ng regarding the different facilities and levels, you can stick with the defaults of "local0" and "error" which are the defaults.  Actually, we've made it even easier than that for you, in that you can omit the level parameter and we'll default it for you.  In almost every iRule you will see on DevCentral, the following syntax is used and in 99% of the cases, it will be all that you need.

log local0. "message goes here"

This will ensure that the log messages are not rate limited and go directly to the log files and that they will be stored in the system log file: /var/log/ltm.

A practical example

What and what not to log really depends on your iRule and what you are trying to accomplish with it.  If you are trying to process a HTTP request, it's probably a good idea to log the inputs to your iRule such as HTTP::host and HTTP::uri, as well as any temporary variables you are using if processing those string values.  Let's look at the following iRule

 

when HTTP_REQUEST {
  switch -glob [HTTP::uri] {
    "/app1*" {
      pool app1_pool
    }
    "*.gif" -
    "*.jpg" {
      pool images_pool
    }
    default {
      pool def_pool
    }
  }
}

This seems fairly straight forward.  All requests to the "/app1" application will be sent to the app1_pool pool, all files with the ".gif" and ".jpg" extensions will be routed to the images_pool pool, and all other requests will be sent to the def_pool pool.  Then you go to test your application and none of the images for the app1 application are being displayed.  The way to go about debugging this issue would be to log the inputs and log the decision elements of the iRules logic to determine the source of the problem.

Your first thought is to go to the webserver logs for the image servers and see why the requests are not being honored.  To your surpise, the logs show no requests on the image servers.  Your next obvious step is to put some debugging in your iRule to see exactly what's going on.

when HTTP_REQUEST {
  log local0. "Request: [HTTP::uri]"
  switch -glob [HTTP::uri] {
    "/app1*" {
      log local0. "Sending request to app1_pool"
      pool app1_pool
    }
    "*.gif" -
    "*.jpg" {
      log local0. "Sending request to images_pool"
      pool images_pool
    }
    default {
      log local0. "Sending request to def_pool"
      pool def_pool
    }
  }
}

Then when you run your traffic, you will see something like this in the logs

...
Request: /app1/index.html
Sending request to app1_pool
Request: /js/file.js
Sending request to def_pool
Request: /app1/smile.gif
Sending request to app1_pool

What!  I thought all image files were supposed to be sent to the images_pool pool but they are being sent to the app1_pool pool.  Since the condition of searching for "/app1" was before the "gif/"jpg" test, it matched and requests were sent to the app1_pool pool of servers.  Now that you have this information, it's fairly easy to reorder the conditions in the switch statement to ensure all image request go to the images_pool pool.

when HTTP_REQUEST {
  log local0. "Request: [HTTP::uri]"
  switch -glob [HTTP::uri] {
    "*.gif" -
    "*.jpg" {
      log local0. "Sending request to images_pool"
      pool images_pool
    }
    "/app1*" {
      log local0. "Sending request to app1_pool"
      pool app1_pool
    }
    default {
      log local0. "Sending request to def_pool"
      pool def_pool
    }
  }
}

Now to your pleasure, the images are displaying in your application.  Just for kicks you look at the logs and see something like the following:

...
Request: /app1/index.html
Sending request to app1_pool
Request: /js/file.js
Sending request to def_pool
Request: /app1/smile.gif
Sending request to images_poo

All is good, the app is working and all images are being displayed properly.  You're done right?  WRONG...

Remove Logging in Production

Debug logging is a great tool when testing your application deployments, or even when fixing an issue with production servers.  But, log messages do fill up the system logs and the system disks are only so big.  In most cases, debug logging should be disabled when you've got all the kinks worked out.  This can be done in several ways

1. Remove the log commands from the iRule.  This is probably the easiest to implement, just delete the log lines and click save.  This option will reduce the clutter in your iRule and makes it easier to read.

2. Comment out the log commands with a # sign.  This will enable you to easily restore the log commands if another situation comes up where you need to figure out a new app error.  Just uncomment the log lines, click save, and you are back in business.

3. Use conditional log statements based on global variables.  By wrapping log statements with an if statement testing the value of a variable, you can make turning on and off logging as simple as changing a variable.  The above iRule could be written like this.

when HTTP_REQUEST {
  set DEBUG 1
  if { $DEBUG } { log local0. "Request: [HTTP::uri]" }
  switch -glob [HTTP::uri] {
    "*.gif" -
    "*.jpg" {
      if { $DEBUG } { log local0. "Sending request to images_pool" }
      pool images_pool
    }
    "/app1*" {
      if { $DEBUG } { log local0. "Sending request to app1_pool" }
      pool app1_pool
    }
    default {
      if { $DEBUG } { log local0. "Sending request to def_pool" }
      pool def_pool
    }
  }
}


Then by setting DEBUG to 1 will enable logging and setting it to 0 will turn logging off.  The method you use will solely depend on your own situtation.  Options 1 and 2 take no CPU overhead in the log processing, while option 3 still requires performing a boolean test on a variable.  For hundreds of thousands of requests, this can add up.

Wrapping it up

First thing to know and imprint in your mind is that logging is your friend.  You should get in the habit of including some form of logging in all new iRule development to speed up diagnosing issues.  Just make sure that you remember to disable those log commands when you move your iRule into production so that you keep from filling up the BIG-IP's filesystem.

Get the Flash Player to see this player.