Using logging

In Chapter 1, Starting with Gradle, we learned about several command-line options we can use to show either more or fewer log messages when we run a Gradle build. These messages were from the Gradle internal tasks and classes. We used a println method in our Gradle build scripts to see some output, but we can also use Gradle's logging mechanisms to have a more customizable way to define logging messages.

Gradle supports several logging levels that we can use for our own messages. The level of our messages is important because we can use the command-line options to filter the messages for log levels.

The following table shows the log levels that are supported by Gradle:

Level

Used for

DEBUG

Debug messages

INFO

Information messages

LIFECYCLE

Progress information messages

WARNING

Warning messages

QUIET

Import information messages

ERROR

Error messages

Every Gradle build file and task has a logger object. The logger object is an instance of a Gradle-specific extension of the SLF4J Logger interface. SLF4J is a Java logging library and stands for Simple Logging Facade for Java. This library provides a logging API that is independent of the underlying logging framework. A specific logging framework can be used at deploy time or runtime to output the actual log message.

To use the logger object in our Gradle build files, we only have to reference logger and invoke the method for the logging level we want to use, or we can use the common method log() and pass the log level as a parameter to this method.

Let's create a simple task and use the different log levels:

task logLevels << {
    // Simple logging sample.
    logger.debug 'debug: Most verbose logging level.'
    logger.log LogLevel.DEBUG, 'debug: Most verbose logging level.'

    logger.info 'info: Use for information messages.'
    logger.log LogLevel.INFO, 'info: Most verbose logging level.'

    logger.lifecycle 'lifecycle: Progress information messages'
    logger.log LogLevel.LIFECYCLE, 'lifecycle: Most verbose logging level.'

    logger.warn 'warn: Warning messages like invalid configuration'
    logger.log LogLevel.WARN, 'warn: Most verbose logging level.'

    logger.quiet 'quiet: This is important but not an error'
    logger.log LogLevel.QUIET, 'quiet: Most verbose logging level.'

    logger.error 'error: Use for errors'
    logger.log LogLevel.ERROR, 'error: Most verbose logging level.'
}

When we run this task from the command line, we get the following output:

$ gradle logLevels
:logLevels
lifecycle: Progress information messages
lifecycle: Most verbose logging level.
warn: Warning messages like invalid configuration
warn: Most verbose logging level.
quiet: This is important but not an error
quiet: Most verbose logging level.
error: Use for errors
error: Most verbose logging level.

BUILD SUCCESSFUL

Total time: 2.356 secs

We notice that only the LIFECYCLE, WARN, QUIET, and ERROR log levels are shown if we don't add any extra command-line options. To see the INFO messages, we must use the --info command-line option. Then we get the following output:

$ gradle --info logLevels
Starting Build
Settings evaluated using empty settings file.
Projects loaded. Root project using build file '/chapter3/logging.gradle'.
Included projects: [root project 'chapter3']
Evaluating root project 'chapter3' using build file '/chapter3/logging.gradle'.
All projects evaluated.
Selected primary task 'logLevels'
Tasks to be executed: [task ':logLevels']
:logLevels
Task ':logLevels' has not declared any outputs, assuming that it is out-of-date.
info: Use for information messages.
info: Most verbose logging level.
lifecycle: Progress information messages
lifecycle: Most verbose logging level.
warn: Warning messages like invalid configuration
warn: Most verbose logging level.
quiet: This is important but not an error
quiet: Most verbose logging level.
error: Use for errors
error: Most verbose logging level.

BUILD SUCCESSFUL

Total time: 1.879 secs

Notice that we also get more messages from Gradle itself. Earlier, we only saw the log messages from our script, but this time a lot of extra logging is shown about the build process itself.

To get even more output and our DEBUG level logging messages, we must use the --debug command-line option to invoke the logLevels task:

$ gradle --debug logLevels
...
06:23:16.578 [DEBUG] [org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter] Executing actions for task ':logLevels'.
06:23:16.585 [DEBUG] [org.gradle.api.Task] debug: Most verbose logging level.
06:23:16.590 [DEBUG] [org.gradle.api.Task] debug: Most verbose logging level.
06:23:16.592 [INFO] [org.gradle.api.Task] info: Use for information messages.
06:23:16.593 [INFO] [org.gradle.api.Task] info: Most verbose logging level.
06:23:16.595 [LIFECYCLE] [org.gradle.api.Task] lifecycle: Progress information messages
06:23:16.596 [LIFECYCLE] [org.gradle.api.Task] lifecycle: Most verbose logging level.
06:23:16.598 [WARN] [org.gradle.api.Task] warn: Warning messages like invalid configuration
06:23:16.599 [WARN] [org.gradle.api.Task] warn: Most verbose logging level.
06:23:16.601 [QUIET] [org.gradle.api.Task] quiet: This is important but not an error
06:23:16.602 [QUIET] [org.gradle.api.Task] quiet: Most verbose logging level.
06:23:16.604 [ERROR] [org.gradle.api.Task] error: Use for errors
06:23:16.606 [ERROR] [org.gradle.api.Task] error: Most verbose logging level.
06:23:16.607 [DEBUG] [org.gradle.api.internal.tasks.execution.ExecuteAtMostOnceTaskExecuter] Finished executing task ':logLevels'
06:23:16.608 [DEBUG] [org.gradle.execution.DefaultTaskGraphExecuter] Timing: Executing the DAG took 0.045 secs
06:23:16.611 [LIFECYCLE] [org.gradle.BuildResultLogger]
06:23:16.612 [LIFECYCLE] [org.gradle.BuildResultLogger] BUILD SUCCESSFUL
...

This time, we get a lot of messages and we really have to look closely for our own. The output format of the logging has also changed; notice that while only the log message was shown before, now the time, log level, and originating class for the log message are also displayed.

So, we know every Gradle project and task has a logger we can use. But we can also explicitly create a logger instance with the Logging class. If, for example, we define our own class and want to use it in a Gradle build, we can use the getLogger() method of the Logging class to get a Gradle logger object. We can use the extra lifecycle() and quiet() methods on this logger instance, just like in projects and tasks.

We will now add a class definition in our build file and use an instance of this class to see the output:

class Simple {
    private static final Logger logger = Logging.getLogger('Simple')

    int square(int value) {
        int square = value * value
        logger.lifecycle "Calculate square for ${value} = ${square}"
        return square
    }
}

logger.lifecycle 'Running sample Gradle build.'

task useSimple {
    doFirst {
        logger.lifecycle 'Running useSimple'
    }
    doLast {
        new Simple().square(3)
    }
}

We have used the logger of the project and task; in the class Simple, we use Logging.getLogger() to create a Gradle logger instance. When we run our script, we get the following output:

$ gradle useSimple
:useSimple
Running useSimple
Calculate square for 3 = 9

BUILD SUCCESSFUL

Total time: 1.605 secs

To see the originating class of the logger, we can use the --debug (or -d) command-line option. Then we will see not only the time the message was logged, but also the name of the logger:

$ gradle useSimple -d
...
06:48:58.130 [LIFECYCLE] [org.gradle.api.Project] Running sample Gradle build.
...
06:49:45.395 [LIFECYCLE] [org.gradle.api.Task] Running useSimple
06:49:45.416 [LIFECYCLE] [Simple] Calculate square for 3 = 9
...

Notice that our project logger is named org.gradle.api.Project, the task logger is named org.gradle.api.Task, and our logger in the Simple class is named Simple.

Controlling output

Before we used the logger instance for logging messages, we used the println() method. Gradle redirects the output sent to System.out—which is what we do when we use println()—to the logger with the log level quiet. That is why we get to see the println() output when we run a Gradle build. Gradle intercepts the output and uses its logging support.

When we run the following very simple Gradle build with the --debug option, we can see that Gradle has redirected the output to the QUIET log level:

println 'Simple logging message'

Let's see the output if we run the build:

$ gradle --debug
...
06:54:54.442 [QUIET] [system.out] Simple logging message
...

Gradle redirects standard error to log messages, with log level ERROR. This also applies to classes we use from external libraries in our Gradle build. If the code in those libraries uses standard output and error, Gradle will capture the output and error messages and redirect them to the logger instance.

We can configure this ourselves if we want to change which log level is used for the redirected output and error messages. Every project and task has an instance of the org.gradle.api.logging.LoggingManager class with the name logging. LoggingManager has the captureStandardOutput() and captureStandardError()methods that we can use to set the log level for output and error messages. Remember that Gradle will, by default, use the QUIET log level for output messages and the ERROR log level for error messages. In the following script, we change the log level for output messages to INFO:

logging.captureStandardOutput LogLevel.INFO
println 'This message is now logged with log level info instead of quiet'

task redirectLogging {
    doFirst {
        // Use default redirect log level quiet.
        println 'Start task redirectLogging'
    }
    doLast {
        logging.captureStandardOutput LogLevel.INFO
        println 'Finished task redirectLogging'
    }
}

First we run the build without any extra command-line options:

$ gradle redirectLogging
:redirectLogging
Start task redirectLogging

BUILD SUCCESSFUL

Total time: 2.291 secs

Notice that the println statement we have defined in the doFirst method of our task is shown, but the output of the other println statements is not shown. We redirected the output of those println statements to Gradle's logging with log level INFO. The INFO log level is now shown by default.

Let's run the script again, but now we add the --info command-line option so we can see all the output of our println statements:

$ gradle redirectLogging --info
Starting Build
Settings evaluated using empty settings file.
Projects loaded. Root project using build file '/chapter3/loggingredirect.gradle'.
Included projects: [root project 'chapter3']
Evaluating root project 'chapter3' using build file '/chapter3/loggingredirect.gradle'.
This message is now logged with log level info instead of quiet
All projects evaluated.
Selected primary task 'redirectLogging'
Tasks to be executed: [task ':redirectLogging']
:redirectLogging
Task ':redirectLogging' has not declared any outputs, assuming that it is out-of-date.
Start task redirectLogging
Finished task redirectLogging

BUILD SUCCESSFUL

Total time: 1.646 secs
..................Content has been hidden....................

You can't read the all page of ebook, please click here login for view all page.
Reset
18.216.255.250