Investigating Performance Issues

Frontend Performance Tracing

There are two possible ways to record performance logging for the frontend:

• Offline: where the values are stored in a CSV file.

• Online: using New Relic.

This frontend performance logging can be enabled by setting frontend.performance option to true, in the configuration service.

To enable online performance logging (using New Relic), please set the frontend.new_relic option to true.

In case the frontend.performance option is set to true and frontend.new_relic is set to false, then offline logging will take place.

For information on how to update configuration options, see Configuration.

Backend Performance Tracing

Install jaeger

$ sudo yum install squirro-jaeger

Configure the firewall

$ iptables -I INPUT -p tcp -m tcp --dport 14267 -j ACCEPT -s localhost -d localhost
$ iptables -I INPUT -p tcp -m tcp --dport 14268 -j ACCEPT -s localhost -d localhost
$ iptables -I INPUT -p tcp -m tcp --dport 16686 -j ACCEPT -s localhost -d localhost

Enable tracing, ensure the following section is in /etc/squirro/common.ini:

[jaeger]
tracing = true
reporting_host = (localhost or ip of clusternode)
reporting_port = 5775

Restart the services you want to trace, e.g.:

$ service sqtopicd restart
$ service sqfrontendd restart

Start the collector, agent and query sevices using the start_jaeger.sh script. Also, make sure to specify the Elasticsearch endpoint for storing the timing metrics:

$ /opt/squirro/jaeger/start_jaeger.sh http://(localhost or ip of your storagenode):9200

The jaeger GUI now is available at http://127.0.0.1:16686

NOTE: When done performance testing, set the tracing flag back to false, restart services, stop the jaeger processes, and drop jaeger indices:

$ curl -s -H "Content-Type: application/x-ndjson" -XGET http://localhost:81/ext/elastic/_cat/indices    | grep jaeger    | awk '{print $3}'    | xargs -I % curl -s -H "Content-Type: application/x-ndjson" -X DELETE http://localhost:81/ext/elastic/%

Finding the Most Time Consuming Component in a Request

If a Squirro request is slow (e.g when querying a result), you can investigate which component is using excessive time by using parameter &timing=true in the request to see a detailed time report of the request.

To investigate a Squirro request, from your browser, open the menu Tools > Web Developer > Network (Firefox) or View > Developer > Developer Tools (Chrome), and submit the query again. You should see the request in the developer tool:

copy this request, add &timing=true&token={your_squirro_token}, and enter it into the address bar of your browser to get the response.

The timing report should look like the example code below.

Note: time_took_ms is the execution of each component and time_ms is the total execution time. If you suspect the Elasticsearch request is slow, look at the node Elasticsearch\/squirro... in the response to see how long it took.

{
  "timing_report": {
    "wrapped_f": {
      "start_time": 1518611439.118776083,
      "_validate_request_params": {
        "time_took_ms": 0,
        "start_time": 1518611439.1258709431
      },
      "time_took_ms": 36,
      "_run_query_with": {
        "time_took_ms": 20,
        "read_items_by": {
          "time_took_ms": 18,
          "_do_read_items_by": {
            "_read_items_by_query": {
              "time_took_ms": 11,
              "start_time": 1518611439.141078949,
              "_execute_query": {
                "Elasticsearch/squirro_v8_3pwqmqilsz-t3w3u6xts1q/item/_search": {
                  "time_took_ms": 8,
                  "start_time": 1518611439.1428649426
                },
                "time_took_ms": 10,
                "start_time": 1518611439.1418509483,
                "_cache_if_result_not_empty_on_timeout": {
                  "time_took_ms": 0,
                  "start_time": 1518611439.1512749195
                }
              }
            }
          },
          "start_time": 1518611439.1355009079,
          "_validate_params": {
            "time_took_ms": 0,
            "start_time": 1518611439.1356248856
          }
        }
      },
      "_get_query_params": {
        "time_took_ms": 7,
        "_expand_all_aggregations": {
          "time_took_ms": 0,
          "start_time": 1518611439.1336150169
        },
        "start_time": 1518611439.1260149479
      }
    }
  },
  "time_ms": 40,
  "total": 7
}