«    »

How to Add Logging to Ant Builds

The Apache Ant build tool is a great aid in automating builds and deployments. When the build fails, however, diagnosing the problem can be painful - especially if it only occurs intermittently. Logging details of the Ant build can therefore be useful.

By default Ant writes informational messages to the console. While this is usually sufficient for a successful build, more detail is often useful in the case of failed builds. Relying on the console output for information about the build has limitations – there might be too much output to fix in the console's buffer, or you might clear or close the console. The solution is to write Ant's output to a log file. This can be done using the <record> task, which allows you to specify a log level of "verbose" or "debug" to provide more details than the standard "info" log level. This task should be the first one performed by the build for any target to ensure that a log is always produced. To accomplish this, I put the <record> task at the start of a target named "init" which I ensure is the first dependency of every other target. An example is given below:

<target name="init">
  <record name="build.log" loglevel="verbose" append="false"/>
</target>

Normally I prefer to use the "verbose" level for the log file, as the "debug" level provides so much additional detail that it is only really useful for debugging bad behavior within Ant code. Notice that I specified the option append="false" which ensures that at the start of the build any existing log file is deleted and a new one created. This makes it easier to see what happens for an individual execution of the build and avoids having the log become too large. This can be a problem, however, if you need to refer back to the log from a prior build to resolve problems or for auditing purposes. I have had situations where after a build fails I look at the build log for the problem, run some other ant target (such as clean) before I have finished resolving the problem, then realize that I have wiped the record of the problem.

One solution to this issue is to create a separate log file for each execution of the build. This can be done by using a build timestamp as part of the log file name, as shown in the below example:

<target name="init">
  <tstamp>
    <format property="timestamp" pattern="yyyy-MM-dd_HH-mm-ss"/>
  </tstamp>
  <property name="build.log.dir" location="${basedir}/buildlogs"/>
  <mkdir dir="${build.log.dir}"/>
  <property name="build.log.filename" value="build_${timestamp}.log"/>
  <record name="${build.log.dir}/${build.log.filename}" 
    loglevel="verbose" append="false"/>
  <echo message="Build logged to ${build.log.filename}"/>
</target>

The log files are written to a buildlogs subdirectory to avoid cluttering the main directory. For some reason the <record> task requires an absolute path when specifying a directory, so the build.log.dir property is prefixed with ${basedir}. After setting up the logging, a message is written to the console displaying the log filename used to make it easier to look up the log file if a problem occurs. This approach will cause log files to accumulate within the log directory. If this becomes a problem, you could add some Ant logic to delete log files older than a certain date. I will leave the implementation of this as an exercise to the reader. Hint: use a <delete> task with a <fileset> that contains a <date> selector.

If you find this article helpful, please make a donation.

4 Comments on “How to Add Logging to Ant Builds”

  1. Floyd says:

    Yo Basil, it looks like my previous comment got the source stripped from it… here’s another go:

    Hi Basil,

    I noticed an echo command in your example up there which reminded me of some ant scripts I wrote in a previous job…
    The default log level for in Ant is _warning_, thus if you don’t specify a log level external tools will assume the text you are echoing is of warning severity.

    Tools including Eclipse and CruiseControl take note of the log level and treat warnings differently from info, Eclipse for example renders warning text in a different colour.

    As such, it became common practise for me to write:

    <echo level=”info” message=”blah”/>

    for any informational messages, omitting the ‘level=”info”‘ for text that I wanted to bring to the user’s attention.
    This all became a bit cumbersome, so I ended up writing a macro like the following:-

    <macrodef name=”say”>
    <attribute name=”message” default=””/>
    <text name=”text” optional=”true”/>
    <sequential>
    <echo level=”info” message=”@{message}”>@{text}</echo>
    </sequential>
    </macrodef>

    so I could then write:

    <say message=”blah”/>

    or

    <say>blah blah blah</say>

    and the message would be logged at the info log level.

    It is also simple to extend the say macro to include the current date/time in the message, something I also found useful.

    Just thought this might be interesting to some anyway… Cheers, and thanks for the blog.

  2. Great comment, Floyd. I wasn’t aware that the default level is warning. Thanks for the information.

  3. James says:

    Thanks for the post; the detailed init example was appreciated; helped resolve an immediate problem we were facing in a complex ant build which performed file encryption.

  4. sagar says:

    Thanks for this hint. really helped my development

«    »