Month: August 2013

Here’s an example of how to use the Logging API to inspect an application’s logs. This function extracts all logs dated within the last hour, averages the execution time of all requests, and records how many requests resulted in errors (in other words recorded a FATAL level log report).

The String this function returns will look like this:

In the last 1 hour, requests took an average of 
451255 microseconds (451 ms) to execute. 0 errors reported.

This function is entirely self-contained; you don’t need to pass in any variables or set any global variables. However it needs to be run within an App Engine environment, either production or development.

public String doLogExam() {
    /**
     * For this example, we'll look into this application's logs, pull out the last few logs, 
     * and calculate the average length of servlet requests. 
     * We'll also examine each line of the log and see if there are any errors reported.
     */
    //Access the log service, pull out logs, and grab an Iterator over the logs.
    LogService log = LogServiceFactory.getLogService();
    //Get all logs starting from 1 hour ago.
    long end_time = (new java.util.Date()).getTime();
    long start_time = end_time - (1000 * 60 * 60 * 1);
    LogQuery q = LogQuery.Builder.withDefaults().includeAppLogs(true).startTimeMillis(start_time).endTimeMillis(end_time);
    Iterator<RequestLogs> log_iterator = log.fetch(q).iterator();
    //Holds the sum of the execution time of all HTTP requests; we'll divide this by the 
    //num_of_logs_counted to get the average execution time.
    long execution_time_microseconds_sum = 0;
    //Number of log lines that are reporting errors.
    int num_of_error_log_lines = 0;
    //Number of logs that we pulled out of the LogService
    int num_of_logs_counted = 0;
    //Iterate over each log.
    while (log_iterator.hasNext()) {
        //Each request_log represents a single HTTP request.
        RequestLogs request_log = log_iterator.next();
        num_of_logs_counted++;
        //Retrieve the execution time of this request, and add it to our sum variable.
        long execution_time_microseconds = request_log.getLatencyUsec();
        execution_time_microseconds_sum = execution_time_microseconds_sum + execution_time_microseconds;
        //Pull out any lines in this request log, and examine them to see 
        //if they report an error.
        List<AppLogLine> log_line_list = request_log.getAppLogLines();
        for (int i = 0; i < log_line_list.size(); i++) {
            AppLogLine app_log_line = log_line_list.get(i);
            LogService.LogLevel line_level = app_log_line.getLogLevel();
            //If this log line's reporting level is classified as fatal 
            //(causing the request to fail), record it.
            if (LogService.LogLevel.FATAL.equals(line_level)) {
                num_of_error_log_lines++;
            }
        }//end looping through each line of the request log
    }//End looping through each request log
    long avg_execution_time_microsec = (execution_time_microseconds_sum / num_of_logs_counted);
    long avg_execution_time_millisec = avg_execution_time_microsec / 1000;
    String comment_text = "In the last 1 hour, requests took an average of ";
    comment_text += avg_execution_time_microsec + " microseconds (" + avg_execution_time_millisec;
    comment_text += " ms) to execute. " + num_of_error_log_lines + " errors reported.";
    return comment_text;
}

Remember to import the following classes:

import java.util.Iterator;
import java.util.List;
import com.google.appengine.api.log.AppLogLine;
import com.google.appengine.api.log.LogQuery;
import com.google.appengine.api.log.LogService;
import com.google.appengine.api.log.LogServiceFactory;
import com.google.appengine.api.log.RequestLogs;