[Apache Camel] Easy output of throughput to log

Easily log throughput

Learn how to easily measure the throughput of Apache Camel routes. By using the Log component in Camel, the number of data processed by the route within the specified time can be output to the log.

To output the throughput, specify the log component for the TO endpoint as follows.

to("log:example.camelbegginer.throughput.PutThroughput?groupInterval=1000")

The "example.camelbegginer.throughput.PutThroughput" in this example is called the logging category and can be given any name. Since the logging category is output to the log, it is convenient to separate the name for each process to be measured. The groupInterval option is set to output the throughput every 1 second (1000 milliseconds).

Throughput output example

The following is an example of throughput output.

ThroughputLogger, example.camelbegginer.throughput.PutThroughput, Received: 100 new messages, with total 300 so far. Last group took: 1001 millis which is: 99.9 messages per second. average: 103.199

First, "ThroughputLogger, example.camelbegginer.throughput.PutThroughput" outputs the name of the specified logging category. "Received: 100 new messages, with total 300 so far. Last group took: 1001 milliseconds" indicates that 100 new messages were processed in 1001 milliseconds, for a total of 300 processed. I have set the throughput to be output every 1000 milliseconds, but it may deviate by 1 millisecond. "99.9 messages per second. Average: 103.199" shows that 99.9 messages can be processed in 1 second and an average of 103.199 can be processed. In this way, the LOG component makes it easy to output the throughput.

Throughput output option list

The options specified for throughput output are shown in the table below. In addition to the table below, the Log component has options such as log level, but they are omitted because they are not directly related to throughput.

Implementation example

Here, I would like to actually flow 1000 data and see how the throughput is output.

First, prepare 1000 data. In the code below, the SimpleDataSet class is used and 1000 data are specified by the setSize method. The SimpleDataSet class is a test component that allows you to easily create large amounts of data for use in system load tests and the like.

            SimpleDataSet dataSet = new SimpleDataSet();
            dataSet.setSize(1000);

Next, register an instance of the SimpleDataSet class in the registry and create an instance of CamelContext. I have added a SimpleDataSet with the 1000 data generated earlier to the registry.

            SimpleRegistry registry = new SimpleRegistry();
            registry.put("testDataSet", dataSet);

            CamelContext context = new DefaultCamelContext(registry);

Finally, add a route to the CamelContext to process 1000 data.

	static RouteBuilder createRouteBuilder() {
        return new RouteBuilder() {
			public void configure() throws Exception {
				from("dataset:testDataSet?produceDelay=-1")
					.split().simple("${header.CamelDataSetIndex}")
						.throttle(100)
						.to("log:example.camelbegginer.throughput.PutThroughput?level=INFO&groupInterval=1000");
			}
        };
    }

In "from (" dataset: testDataSet? ProduceDelay = -1 ")", the 1000 data generated earlier is specified as the from endpoint. In "split (). Simple (" $ {header.CamelDataSetIndex} "). Throttle (100)", 1000 messages are split by the HeaderDataSetIndex of the header, and 100 messages are specified to be sent per second. The header. CamelDataSetIndex is automatically numbered from 1 by SimpleDataSet.

The output example of the log output by log4j2 after executing the application is as follows. You can see that the log is output every second and the throughput at that time is displayed.

[2019-01-13 08:27:46.429], [INFO ], e.c.t.PutThroughput, Camel (camel-1) thread #1 - ThroughputLogger, example.camelbegginer.throughput.PutThroughput, Received: 100 new messages, with total 100 so far. Last group took: 906 millis which is: 110.375 messages per second. average: 110.375
[2019-01-13 08:27:47.422], [INFO ], e.c.t.PutThroughput, Camel (camel-1) thread #1 - ThroughputLogger, example.camelbegginer.throughput.PutThroughput, Received: 100 new messages, with total 200 so far. Last group took: 1000 millis which is: 100 messages per second. average: 104.932
[2019-01-13 08:27:48.423], [INFO ], e.c.t.PutThroughput, Camel (camel-1) thread #1 - ThroughputLogger, example.camelbegginer.throughput.PutThroughput, Received: 100 new messages, with total 300 so far. Last group took: 1001 millis which is: 99.9 messages per second. average: 103.199
[2019-01-13 08:27:49.421], [INFO ], e.c.t.PutThroughput, Camel (camel-1) thread #1 - ThroughputLogger, example.camelbegginer.throughput.PutThroughput, Received: 100 new messages, with total 400 so far. Last group took: 998 millis which is: 100.2 messages per second. average: 102.433
[2019-01-13 08:27:50.422], [INFO ], e.c.t.PutThroughput, Camel (camel-1) thread #1 - ThroughputLogger, example.camelbegginer.throughput.PutThroughput, Received: 100 new messages, with total 500 so far. Last group took: 1001 millis which is: 99.9 messages per second. average: 101.916
[2019-01-13 08:27:51.423], [INFO ], e.c.t.PutThroughput, Camel (camel-1) thread #1 - ThroughputLogger, example.camelbegginer.throughput.PutThroughput, Received: 100 new messages, with total 600 so far. Last group took: 1001 millis which is: 99.9 messages per second. average: 101.574
[2019-01-13 08:27:52.421], [INFO ], e.c.t.PutThroughput, Camel (camel-1) thread #1 - ThroughputLogger, example.camelbegginer.throughput.PutThroughput, Received: 100 new messages, with total 700 so far. Last group took: 998 millis which is: 100.2 messages per second. average: 101.376

The whole sample program this time is as follows.

package example.camelbegginer.throughput;

import org.apache.camel.CamelContext;
import org.apache.camel.builder.RouteBuilder;
import org.apache.camel.component.dataset.SimpleDataSet;
import org.apache.camel.impl.DefaultCamelContext;
import org.apache.camel.impl.SimpleRegistry;

public class PutThroughput {

	public static void main(String[] args) {
		try {
			SimpleDataSet dataSet = new SimpleDataSet();
			dataSet.setSize(1000);

			SimpleRegistry registry = new SimpleRegistry();
			registry.put("testDataSet", dataSet);

			CamelContext context = new DefaultCamelContext(registry);
			context.addRoutes(createRouteBuilder());

			context.start();
			Thread.sleep(20000);
			context.stop();

		} catch (Exception e) {
			e.printStackTrace();
		}
	}

	static RouteBuilder createRouteBuilder() {
        return new RouteBuilder() {
			public void configure() throws Exception {
				from("dataset:testDataSet?produceDelay=-1")
					.split().simple("${header.CamelDataSetIndex}")
						.throttle(100)
						.to("log:example.camelbegginer.throughput.PutThroughput?level=INFO&groupInterval=1000");
			}
        };
    }
}

Finally

With Apache Camel, you could easily output the throughput to the log as described above. I think that this throughput output can be used in the following cases.

--Check the throughput as a trial during the unit test. You can check that parallel processing is possible. --Used as a method for measuring the performance of each process during performance tests. --In a production environment, if you cannot prepare a means to measure performance, use it as a simple performance measurement method.

Since the throughput output load is low, it is a function that can be fully used even in a production environment.

reference

-Log Component (official site) -DataSet Component (official site)

• Exploring Apache Camel Core - Log Component