Debugging Ruby Applications with Instana AutoProfile™ Production Profiler

Instana Adds Production Ruby Profiling

In the latest Instana release (Instana Release 201), AutoProfile for Ruby is generally available. This allows teams developing and supporting Ruby based applications to continuously collect and analyze CPU profiles, without modification to their applications[1].

To help acquaint you with how AutoProfile for Ruby can enhance your observability workflows, let’s walk through a simple example of when profiling can enhance our tracing experience.

A Sample Ruby Problem

To have a sample problem, we need a sample application. In this walkthrough, we will use a website hit counter which attempts to naively check if the hit count number is prime.

require 'bundler/setup'
Bundler.require

$visitor_count = 0

class Example < Sinatra::Application
 get('/') do
          $visitor_count += 1
  	  factors = (2...$visitor_count).reject { |n| ($visitor_count.to_f/n).denominator != 1 }
      
          factors.empty? ? "#{$visitor_count} is prime.\n" : "#{$visitor_count} is not prime.\n"
 end
end

run Example

Using tools like Apache Bench, we can simulate a large number of requests and see how our sample application will perform under load.

These test results aren’t the best. From the service summary, we can see that as we run our load test the number of requests we can process per minute decreases and the time each request takes to complete increases. These monotonically changing health metrics speak to a problem inside of the application. Let’s take a look at the slowest request and try to see if we can figure out the issue.

Understanding the Problem Space

Out of the 55,664 requests we made, the slowest request took 1.13 seconds. Unfortunately, this request’s trace can’t point us to the source of the slowness. Unlike a “traditional” application, which would have some number of downstream dependent services (e.g. databases, cache servers or COTS SAAS APIs), which could explain the slowdown, our example application has nothing. This leaves us with avenues for further investigation:

  1. Modify and add custom tracing to the application around code paths that could be causing the slowness.
  2. Exfiltrate other information from the running application using a profiling tool.

Adding custom tracing requires two key considerations. Primarily, a new deployment artifact will be created and must be released to gain the insights that custom tracing offers. For our simple example application, this would not be an issue. If this were a “real” application, our request to deploy will need to follow any business rules and guidelines present to gain access to our newly created insights. Secondarily, custom tracing is going to help you see what you’ve monitored is slow. More specifically, it’s not going to the source of the slowness. This means that in a large application, the person adding the instrumentation will need to have a degree of understanding as to its function and architecture to add value with custom tracing.

Our second proposed option is to exfiltrate other forms of information from the target process that can assist us in diagnosing our performance problem. Tools like `strace`, `ptrace`, and `perf` can allow us to gain insight into the current state of the running application and get a view into how the target application is interacting with resources like memory, disk, cpu and network. With some understanding, the data provided is very effective in resolving performance issues like the one we are encountering with our sample application. These tools have a number of considerations worth considering before use:

  • Generally, these tools require elevated user permissions to invoke. This means that the investigator needs to be trusted enough to have the necessary permissions to run these tools, and perform a whole host of other activities on a system that may or may not be acceptable depending on your security posture.
  • Using these tools in many environments is a manual process. For a single host, this is generally fine but if the problem requires the inspection of processes across multiple hosts it will take some ad-hoc automation to be able to accomplish this.
  • Using these tools creates a snapshot of the application’s running context. Unlike trace data, which is generally aggregated by some service, `strace`, `ptrace`, and `perf` report their findings to the standard output. Unless care is taken to archive and preserve these outputs, it’s hard to understand changes during the lifetime of a process.

Profiling Based Solutions

While our sample application is very small and easy to work with, both of our investigative avineus would be stymied by the cavates and considerations discussed above. The “best of both worlds” would be to have access to a profiling tool that runs automatically, continuously and stores its output in a system that aggregates it for further analysis. This data can then drive further improvements in custom, in-application tracing. With Instana AutoProfile™ for Ruby, we are able to have our “best of both worlds” solution, all included with no modifications needed to the application.

Let’s take a look back at the trace for our slowest request. My local agent had AutoTrace enabled, so we now have access to the cpu profiling information from the trace itself.

We can drill down into the profile data and see that one call stack profile took up all of the time spent processing.

Scrolling to the bottom of the flame graph, we see the two most called methods are occurring in a block on line nine of our example.

Thanks to our continuous profiling, we know that the following line was the issue:

  factors = (2...$visitor_count).reject { |n| ($visitor_count.to_f/n).denominator != 1 }

Calls to `denominator` used almost half of the user space cpu time. We can clearly see our naive approach to a primality test isn’t going to cut it.

Takeaways

Using the new AutoProfile for Ruby, we’ve been able to understand a performance problem that historically would have needed a deployment to add monitoring code or needed hands on access to the host(s) where the application was running on. By collecting and correlating profiling data ahead of time, we were able to quickly identify the cause in conjunction with tracing. In the real world, this translates to significant reductions in mean time to recovery and helps resolve issues faster.

  1. You don’t even need to update the ruby sensor!

Play with Instana’s APM Observability Sandbox

Developer, Engineering, Product
One look at the Instana website lets you know that Instana is in the Observability (and APM) business — providing the nascent Enterprise Observability Platform, especially useful for Cloud-native and containerized microservices...
|
Developer, Thought Leadership
Kubernetes (also known as k8s) is an orchestration platform and abstract layer for containerized applications and services. As such, k8s manages and limits container available resources on the physical machine, as well...
|
Profiling
There are multiple reasons why a program will consume more CPU resources than excepted. In the case of a high computational complexity of an algorithm, the amount of data it operates on...
|

Start your FREE TRIAL today!

Instana, an IBM company, provides an Enterprise Observability Platform with automated application monitoring capabilities to businesses operating complex, modern, cloud-native applications no matter where they reside – on-premises or in public and private clouds, including mobile devices or IBM Z.

Control hybrid modern applications with Instana’s AI-powered discovery of deep contextual dependencies inside hybrid applications. Instana also gives visibility into development pipelines to help enable closed-loop DevOps automation.

This provides actionable feedback needed for clients as they to optimize application performance, enable innovation and mitigate risk, helping Dev+Ops add value and efficiency to software delivery pipelines while meeting their service and business level objectives.

For further information, please visit instana.com.