Zach's Blog

We’ve been doing some profiling on http://pongr.com recently and have started using Ostrich.  Our site uses Lift and I thought I’d put together a brief tutorial showing how to use Ostrich in a Lift-based web app.  Our approach was heavily inspired by the usage of Ostrich in ESME, is described below and is available on Github.

In this example we’ll use Lift 2.1 and Ostrich 2.2.10.  Update: As Steve commented, there is a newer release of Ostrich (2.3.3 as of this post) but it requires Scala 2.8.1, so to use it you would also need to use Lift 2.2.  You’d also need to add the Twitter maven repo to the sbt project.

Setup

First off, we need to add the JBoss maven repo and the Ostrich dependency to the sbt project:

val jbossRepo = "jboss" at "http://repository.jboss.org/nexus/content/groups/public/"

override def libraryDependencies = Set(
  "net.liftweb" %% "lift-webkit" % liftVersion % "compile->default",
  "net.liftweb" %% "lift-mapper" % liftVersion % "compile->default",
  "org.mortbay.jetty" % "jetty" % "6.1.22" % "test->default",
  "junit" % "junit" % "4.5" % "test->default",
  "org.scala-tools.testing" %% "specs" % "1.6.5" % "test->default",
  "com.h2database" % "h2" % "1.2.138",
  "com.twitter" % "ostrich_2.8.0" % "2.2.10"
  ) ++ super.libraryDependencies

Ostrich will provide stats via HTTP, so we need to define the port it will use in default.props:

#Enable and set port for Ostrich web access (JSON output)
admin_http_port=9990

Ostrich needs to be started when the web app boots up:

// Ostrich setup
val runtime = new RuntimeEnvironment(getClass)
val config = new Config
config("admin_http_port") = Props.getInt("admin_http_port") openOr 9990
ServiceTracker.startAdmin(config, runtime)

As far as configuration goes, that’s it!  Ostrich is now ready to collect data and provide stats.

Counters

The first type of data we’ll collect is the count of something.  Could be number of users registered, number of new blog posts, etc.  For this example we’ll count each time the HelloWorld.howdy snippet is rendered:

def howdy(in: NodeSeq): NodeSeq = {
  Stats.incr("howdy-renders")
  Helpers.bind("b", in, "time" -> date.map(d => Text(d.toString)))
}

Gauges

A gauge is just some value of something at a particular point in time, perhaps a measurement from a sensor or some calculated value.  In our example we’ll use WTFs/min:

import scala.math._
Stats.makeGauge("wtfs-per-min") { rint(random * 10) }

We set up this particular gauge in Boot.scala and just generate random data.  You just name a gauge and provide a function that always returns the current value.

Timings

Ostrich can also record how long it takes to execute certain blocks of code.  Simply wrap the code you want to time in a call to Stats.time.  For extra convenience, it will return whatever your code block returns.

In this example, we suspect our important number calculation is slowing down page loads, so we’ll time it:

def importantNumber(in: NodeSeq): NodeSeq = {
  val n = Stats.time("important-number-calculation") {
    import scala.math._
    Thread.sleep(round(2000*random + 1000))
    7
  }
  <span>{n}</span>
}

Stats

Now that we’re collecting all three types of data, let’s pull some stats from Ostrich.  After loading our home page at http://localhost:8080 several times, we can get the latest stats from http://localhost:9990/stats.

{"counters":{"howdy-renders":7},"timings":{"important-number-calculation":{"count":7,"standard_deviation":621,"p75":3405,"histogram":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,2,2,2,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"maximum":2878,"p9999":3405,"p90":3405,"p25":2015,"p99":3405,"average":2179,"minimum":1447,"p50":2619,"p999":3405}},"jvm":{"nonheap_committed":46530560,"heap_max":1908932608,"thread_peak_count":54,"heap_committed":120782848,"uptime":436119,"nonheap_max":224395264,"thread_daemon_count":12,"num_cpus":8,"thread_count":54,"nonheap_used":45256464,"start_time":1292277570344,"heap_used":9656904},"gauges":{"wtfs-per-min":5.0}}

By default, Ostrich returns stats in JSON format which is great for parsing for display in another app or viewing with JSONView.  However, for this blog post perhaps the plaintext version at http://localhost:9990/stats.txt is more readable:

counters:
  howdy-renders: 7
gauges:
  wtfs-per-min: 2.0
jvm:
  heap_committed: 120782848
  heap_max: 1908932608
  heap_used: 8911680
  nonheap_committed: 46530560
  nonheap_max: 224395264
  nonheap_used: 45252880
  num_cpus: 8
  start_time: 1292277570344
  thread_count: 54
  thread_daemon_count: 12
  thread_peak_count: 54
  uptime: 430468
timings:
  important-number-calculation: (average=2179, count=7, maximum=2878, minimum=1447, p25=2015, p50=2619, p75=3405, p90=3405, p99=3405, p999=3405, p9999=3405, standard_deviation=621)

We can see that the howdy snippet was rendered 7 times and we’re currently seeing 2 WTFs/min.  We also have collected 7 timings for the important number calculation and we see various stats like min/max/avg, etc.  Now we know precisely how much time is being spent calculating important numbers, and we can choose to optimize if needed.

While not as detailed or comprehensive as a profiling tool like VisualVM, Ostrich is a great, simple tool for collecting performance data in specific parts of your Scala app.  And integration with Lift really could not be easier.