travis-ci/travis-ci — pull request #691 by svenfuchs (2012-08-30 22:17:50+00:00)
Title: ApiController instrumentation

@roidrage @joshk @rkh

I believe this change adds missing instrumentation to the ApiController. I also added per-controller metrics to the `ActionControllerMetricsLogSubscriber`.

After deploying this to staging and hitting a single url (http://staging.travis-ci.org/builds/381152.json) I got these metriks in the logs.

Does that look correct?

```
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=active_record.reads type=timer count=6 one_minute_rate=0.6161005428391109 five_minute_rate=1.050207982851537 fifteen_minute_rate=1.1478344869236348 mean_rate=0.12599046828133134 min=0.0038909999999999995 max=36.113265999999996 mean=10.489942333333333 stddev=189.73098353548303 median=4.699484 95th_percentile=36.113265999999996
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=active_record.build.load type=timer count=1 one_minute_rate=0.10268342380651843 five_minute_rate=0.17503466380858954 fifteen_minute_rate=0.1913057478206058 mean_rate=0.020998948594445285 min=36.113265999999996 max=36.113265999999996 mean=36.113265999999996 stddev=0.0 median=36.113265999999996 95th_percentile=36.113265999999996
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=active_record.commit.load type=timer count=1 one_minute_rate=0.10268342380651843 five_minute_rate=0.17503466380858954 fifteen_minute_rate=0.1913057478206058 mean_rate=0.021092851211379996 min=1.842364 max=1.842364 mean=1.842364 stddev=0.0 median=1.842364 95th_percentile=1.842364
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=active_record.job::test.load type=timer count=1 one_minute_rate=0.10268342380651843 five_minute_rate=0.17503466380858954 fifteen_minute_rate=0.1913057478206058 mean_rate=0.02121257451808921 min=7.381177 max=7.381177 mean=7.381177 stddev=0.0 median=7.381177 95th_percentile=7.381177
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=active_record.cache type=timer count=1 one_minute_rate=0.10268342380651843 five_minute_rate=0.17503466380858954 fifteen_minute_rate=0.1913057478206058 mean_rate=0.02124340089548306 min=0.0038909999999999995 max=0.0038909999999999995 mean=0.0038909999999999995 stddev=0.0 median=0.0038909999999999995 95th_percentile=0.0038909999999999995
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=active_record.artifact::log.load type=timer count=1 one_minute_rate=0.10268342380651843 five_minute_rate=0.17503466380858954 fifteen_minute_rate=0.1913057478206058 mean_rate=0.021337448556735784 min=2.0177910000000003 max=2.0177910000000003 mean=2.0177910000000003 stddev=0.0 median=2.0177910000000003 95th_percentile=2.0177910000000003
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=active_record.request.load type=timer count=1 one_minute_rate=0.10268342380651843 five_minute_rate=0.17503466380858954 fifteen_minute_rate=0.1913057478206058 mean_rate=0.0214227992302207 min=15.581164999999999 max=15.581164999999999 mean=15.581164999999999 stddev=0.0 median=15.581164999999999 95th_percentile=15.581164999999999
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=action_controller.requests type=timer count=1 one_minute_rate=0.10268342380651843 five_minute_rate=0.17503466380858954 fifteen_minute_rate=0.1913057478206058 mean_rate=0.021458913468187624 min=1489.608339 max=1489.608339 mean=1489.608339 stddev=0.0 median=1489.608339 95th_percentile=1489.608339
2012-08-30T22:12:00+00:00 app[web.1]: metriks: time=1346364720 name=action_controller.requests.v1.builds type=timer count=1 one_minute_rate=0.10268342380651843 five_minute_rate=0.17503466380858954 fifteen_minute_rate=0.1913057478206058 mean_rate=0.021458906631829977 min=1489.608339 max=1489.608339 mean=1489.608339 stddev=0.0 median=1489.608339 95th_percentile=1489.608339
```