Lobo - Continuous Tuning

Lobo, Continuous Tuning

USER MANUAL

Click here to have a view of the latest Lobo's version API.

Case: a case is a class which has at least one of its methods annotated as @Profile, which represents a scenario.

Scenario: it's a method in the case class that is annotated as @Profile. A scenario always contains at least one metric.

Metric: a metric is something being measured in a scenario. A scenario has at least the default single metric. Other metrics are managed through the Telemetry class. The MetricType class contains constants used to setup the metric types, which can be single, average, maximum or minimum value.

Build-Metrics XML: it is the artifact that stores the build specific metrics, categorized by scenario and case.

Merged-Metrics XML: it is the artifact that stores all the project's performance history.

2. Lobo profile cycle

The Lobo is designed to monitor the performance of your application while it is being developed. By this way, you can track how your changes impacted performance. To do that Lobo needs to collect and store the metrics you specify.

Lobo defines two main tasks, one to collect metrics on every build, and another to store the information coming from several builds into just one consolidated file. There is also a third task that is used to generate a human readable report from the consolidated data file. The following image illustrates that:

Lobo profile cycle

There are two scopes defined:

The Build Scope;
The Continuous Integration Scope.

The next two topics will make reference to the Lobo ant tasks. Lobo Ant tasks are detailed in chapter 3 - Ant Tasks.

The Build Scope

The build of your project might be responsible for collecting the metrics, in other words, it has to translate production classes and profile cases into a series of performance metrics.

It is done by calling the ProfileTask, which generates an XML with the information specific to that build, also called Build-Metrics XML.

This is all done in the build scope.

The Continuous Integration Scope

The continuous integration scope is aware that the build will be run a lot of times. It is responsible for defining the place that the merge file will be maintained, being crucial that the merge file won't be deleted among build executions, because the project build must not be responsible for that.

In case you're using CruiseControl as your continuous integration tool, use the CruiseControl Build to place the tasks in the continuous integration scope. These tasks are to be placed right after the project build file is called so that the performance will have already been collected.

The first task in the continuous integration scope will store the metrics collected in the Build Scope into the merge.xml file, creating your project performance history.

The second task will generate the reports as an HTML, containing the charts that illustrates the metrics evolution.

3. Ant tasks

Lobo exposes the following ant tasks:

Build scope task:

Profile Task

Continuous integration scope tasks:

Merge Task
Report Task

This chapter details each of these tasks.

Profile Task

Task Class:	br.com.oncast.dev.lobo.task.ProfilerTask
Input:	classpath - an ant path defining all the classes needed for production and profiling. Optional. classpathref - reference to a pre-defined path defining all the classes needed for production and profiling. Optional if classpath is undefined. Classpathref and classpath may be used together. batchprofile - list of filesets to the classes that implement the profile cases. It must refer to the already-compiled classes (".class" files).
Output:	output - the name of the XML file to store the build metrics.

The profile task takes as input the production classes and the profile case classes, executes them and them outputs a build-metrics XML file. Take a look at some examples:

Using classpath and batchprofile:

Using classpathref and batchprofile:

Merge Task

Task Class:	br.com.oncast.dev.lobo.task.ProfilerMergeTask
Input:	buildname - the name of the build that generated the build metrics XML. buildmetrics - the build metrics XML file.
Input-Output:	merge - that's the merge file. If exists, all its contents will be merged to those in the build metrics file and will be overwritten to reflect the new data. If doesn't exist it will be created with the metrics in the build metrics.

The merge task centralizes the metrics history into a single XML merge file. You may consider the merge file as the final repository for your project's performance information. Every time the merge task is executed the merge file, the merge file will be updated with the latest performance information.
It's usage is very simple! Take a look at the following example:

The buildname parameter is still mandatory. Future versions of the profile-merge may infer the bulidname from previous build metrics files. Currently, it is a good idea to use your continuous integration infrastructure to inject the build name into the merge file. This parameter will be used to label the builds in the performance evolution report.

Report Task

Task Class:	br.com.oncast.dev.lobo.task.ProfilerReporterTask
Input:	input - the XML merge file reference.
Output:	output - the directory to store the generated report HTML and images.

The report task simply formats the metric evolutions to a format appropriate to analysis. The output report consist of an HTML listing all collected metrics categorized by scenario and case. Each metric is formatted as a line chart listing all the builds in the X axis and the time bound to the metric in the Y axis.
Here follows an usage example for this task:

Remember to have the ../artifacts/report directory already created.

4. Lobo in action

Lobo is used to measure the execution time of some piece of software. The method annotation @Profile is used to indicate that some given method is a scenario, that is, it has some metrics to collect. Every scenario has at least a single typed metric that covers all the method execution. Unless the desired metric name is set in the @Profile annotation, like in @Profile("myMetric"), the default metric name is "scenario-timespan". Every other metrics collected in a scenario are controlled by the Telemetry API, which is easy, as follows...

The API to control profiling is very simple. The Telemetry class contains the following methods that control the metric gathering:

startMetric(String metricName [, MetricType type]): the startMetric method can be called with one parameter, just the metric name, or two parameters, the metric name followed by the metric type. To start a metric means to start to chronometer until an endMetric is called;

endMetric(String metricName): given the name of a metric previously started, the endMetric method stops to chronometer and it registers the timespan;

switchMetric(String metricName):switching a metric means to end and to start the given metric. It isn't useful for single-typed metrics, because a single metric considers just the first metric register. As explained below, to switch (or to restart) a metric is useful to collect maximum, minimum or average.

Hereunder are the types of metrics supported by Lobo:

MetricType.SINGLE: it considers just the first metric register, that is, the first pair of startMetric and endMetric calls;
MetricType.AVERAGE: it calculates the arithmetical average for all registered timespans;
MetricType.MAX: it indicates the greatest value from all the registered timespans;
MetricType.MIN: and it indicates the lowest values from the registered timespans.

Following there are some examples using the Telemetry methods and all the metric types:

Example 1

import br.com.oncast.dev.lobo.Profile;

(...)

@Profile
public void singleProfile() {
Collections.binarySearch(someList, someKey);
}

This is the simplest way to setup a scenario. The scenario name is the name of the method "singleProfile" and the default metric is (as its name wasn't informed) "scenario-timespan". The default metric is a single metric that chronometers the whole scenario execution time.

Example 2

    
          import
          static br.com.oncast.dev.lobo.Telemetry.startMetric;

          import static
          br.com.oncast.dev.lobo.Telemetry.endMetric;

          import
          br.com.oncast.dev.lobo.Profile;

          (...)

          @Profile

          public void singleSearchCost() {

          startMetric("binarySearchCost");

            Collections.binarySearch(someList, someKey);

          endMetric("binarySearchCost");

          startMetric("mySearchCost");

            MyAlgorithm.search(someList, someKey);

          endMetric("mySearchCost");

          }

This example adds some information in comparison to the previous one. It uses the Telemetry API to configure two single metrics called "binarySearchCost" and "mySearchCost". This is a hypothetical scenario, which considers that the programmer would like to compare two implementations of a search algorithm: the Collections' binary search and its own algorithm. The scenario name is the name of the method "singleSearchCost" and there are also the default single metric called "scenario-timespan", which will register the full scenario execution time.

Example 3

The code above shows a scenario with the default metric renamed to "fullExecutionMetric" and an average metric called "searchAverage". The "fullExecutionMetric" measures the whole scenario execution time. While the "searchAverage" is registered 3 times, one for each binary search execution. The resultant metric value is the arithmetic average between all the "searchAverage" registers.

Example 4

import static br.com.oncast.dev.lobo.Telemetry.startMetric;
import static br.com.oncast.dev.lobo.Telemetry.endMetric;
import static br.com.oncast.dev.lobo.Telemetry.switchMetric;
import static br.com.oncast.dev.lobo.MetricType.AVERAGE;
import static br.com.oncast.dev.lobo.MetricType.MAX;
import static br.com.oncast.dev.lobo.MetricType.MIN;
import br.com.oncast.dev.lobo.Profile;

(...)

@Profile("100timesBusinessMethod")
public void profileMyBusinessLayer() {
startMetric("avgBusinessMethod", AVERAGE);
startMetric("maxBusinessMethod", MAX);
startMetric("minBusinessMethod", MIN);
BusinessLayer.businessMethod();

for (int i = 0; i < 100; i++) {
    switchMetric("avgBusinessMethod");
    switchMetric("maxBusinessMethod");
    switchMetric("minBusinessMethod");
    BusinessLayer.businessMethod();
}

endMetric("avgBusinessMethod");
endMetric("maxBusinessMethod");
endMetric("minBusinessMethod");
}

That is a very complete example of Lobo usage and it's still very simple.
The code above executes a scenario which has a hundred executions of a method in the business layer. The default metric is renamed to "100timesBusinessMethod" and there are more three metrics called "avgBusinessMethod", "maxBusinessMethod" and "minBusinessMethod". These metrics registers the average, the maximum and the minimum execution times of all the 100 businessMethod calls.

5. Analyzing results

Lobo generates graphics which show the execution time evolution through the build time line. The Y axis represent the execution time in milliseconds, by this way, the higher a point is in the graphic, slower your code is. The X axis represents the build evolution. Check the example:

Graphic 1: the execution time growing throughout the builds

The above example indicates that the scenario called "performaticMethod" starts to decrease it's performance throughout the releases. In the build 1.1, its execution time was 2.8ms and after ten builds, in the build 1.10, its execution time reached 11ms. It doesn't necessarily indicate that its performance is poor, because 11ms really takes an eye blink. However, maybe the method under profiling represents a critical portion of the software, being executed millions of times. In this case, an increase from 2.8ms to 11ms could represent a huge increase. The graphic generated by Lobo would help you to turn your attention to this method.

The example below presents a scenario where the need for attention is subtler:

Graphic 2: the execution time seams stable unless for the last build

While the first example exposes a continuous performance degradation, the second graphic indicates a stabler scenario. The execution time has some punctual increases until the build 1.9, then in the last build it increases almost 100ms. In a case like this, Lobo would help you to quickly acknowledge that the last build modifications possibly had impacted the scenario's performance. By this way, an eventual investigation for performance improvements is really more focused, being much more probable to reach some performance gain.

Appendix A. Version 1.0.alpha limitations

The following limitations were identified in the current Lobo distribution:

Single page report;
Build graphics not scalable (shows all the builds every time);
Cannot infer build version names;
Machine workload interference;
Precision.

Single page report

The reports are currently consolidated into a single HTML file. When your build infrastructure starts to collect a lot of metrics it will be very difficult to find the metric you want. A better reporting approach (possibly using multiple HTMLs and a frameset, like JUnit) will be available in the next versions.

Build graphics not scalable

The graphics generation reports all the values collected in all the builds for a single metric. If you have a month of data and your CruiseControl ran twice a day, you'll have about 60 values in each graphic, which may lead to unreadability. Strategies to solve this problem, like aggregating data or using just the last set of it, will fix this problem in the future versions.

Cannot infer build version names

The version name (used to label the X axis in the graphs) are input in the merge task and must always be specified. It is foreseen a default incremental behavior in the case this property is not specified, thus allowing a more intuitive usage.

Machine workload interference

The workload of the machine interferes in the result of the performance analysis. The recommendation here is to use a server which has a fixed and rarely changed number of services running (your CruiseControl server possibly will do fine). Also schedule the performance analysis to be done in a time that the server is hardly required.

Precision

Lobo is still very vulnerable to JVM and OS thread escalation, so variations of a few milliseconds can be considered normal from execution to execution. If you are evaluating the execution of code that takes a lot of time to execute (some seconds for instance) you should not worry about it. But if you're analyzing a much faster code, than you should execute the measurement several times and use the MetricType.AVERAGE to have a more reliable metric.

Appendix B. Dependencies

The current Lobo distribution is tested to work with java 5 or java 6 and also ant 1.6 or ant 1.7.

The Lobo distribution is dependent of the following libraries:

jcommon 1.0.9;
jfreechart 1.0.5.

The above dependent libraries - jcommon and jfreechart - are embedded to the "with-deps" distribution: oncast-lobo-with-deps-1.0.alpha.jar.

The complete Lobo distribution comes with its source code. To build it you'll need:

junit 4.2;
ant-testunit;
ant-launcher;
mockobjects 0.09.

All these libraries, including runtime and test time dependencies (except java and ant), source code, binaries, the getting started guide and this user manual can be found in the complete distribution: oncast-lobo-1.0.alpha.zip.

Appendix C. License

Lobo is free software and is licensed under GPL version 2 (or any latter version at your choice).

As such it is distributed AS IS, WITHOUT ANY WARRANTY. See the GNU General Public License for more details. The full license is available in the complete distribution: oncast-lobo-1.0.alpha.zip.

OnCast

Lobo, Continuous Tuning

Continuous Tuning