Bug 956230: improve instrumentation of bugzilla's internals

22 files changed, 919 insertions, 102 deletions

diff --git a/Bugzilla.pm b/Bugzilla.pm
index 82a5e9490..233cc4323 100644
--- a/Bugzilla.pm
+++ b/Bugzilla.pm
@@ -55,6 +55,10 @@ use Bugzilla::Token;
 use Bugzilla::User;
 use Bugzilla::Util;
 
+use Bugzilla::Metrics::Collector;
+use Bugzilla::Metrics::Template;
+use Bugzilla::Metrics::Memcached;
+
 use File::Basename;
 use File::Spec::Functions;
 use DateTime::TimeZone;
@@ -127,6 +131,30 @@ sub init_page {
 
     my $script = basename($0);
 
+    # BMO - init metrics collection if required
+    if (i_am_cgi() && $script eq 'show_bug.cgi') {
+        # we need to measure loading the params, so default to on
+        Bugzilla->metrics_enabled(1);
+        Bugzilla->metrics($script);
+        # we can now hit params to check if we really should be enabled.
+        # note - we can't use anything which uses templates or the database, as
+        # that would initialise those modules with metrics enabled.
+        if (!Bugzilla->params->{metrics_enabled}) {
+            Bugzilla->metrics_enabled(0);
+        }
+        else {
+            # to avoid generating massive amounts of data, we're only interested in
+            # a small subset of users
+            my $user_id = Bugzilla->cgi->cookie('Bugzilla_login');
+            if (!$user_id
+                || !grep { $user_id == $_ }
+                    split(/\s*,\s*/, Bugzilla->params->{metrics_user_ids}))
+            {
+                Bugzilla->metrics_enabled(0);
+            }
+        }
+    }
+
     # Because of attachment_base, attachment.cgi handles this itself.
     if ($script ne 'attachment.cgi') {
         do_ssl_redirect_if_required();
@@ -195,7 +223,12 @@ sub init_page {
 #####################################################################
 
 sub template {
-    return $_[0]->request_cache->{template} ||= Bugzilla::Template->create();
+    # BMO - use metrics subclass if required
+    if (Bugzilla->metrics_enabled) {
+        return $_[0]->request_cache->{template} ||= Bugzilla::Metrics::Template->create();
+    } else {
+        return $_[0]->request_cache->{template} ||= Bugzilla::Template->create();
+    }
 }
 
 sub template_inner {
@@ -660,10 +693,31 @@ sub process_cache {
     return $_process_cache;
 }
 
+# BMO - Instrumentation
+
+sub metrics_enabled {
+    if (defined $_[1]) {
+        $_[0]->request_cache->{metrics_enabled} = $_[1];
+        delete $_[0]->request_cache->{metrics} unless $_[1];
+    }
+    else {
+        return $_[0]->request_cache->{metrics_enabled};
+    }
+}
+
+sub metrics {
+    return $_[0]->request_cache->{metrics} ||= Bugzilla::Metrics::Collector->new($_[1]);
+}
+
 # This is a memcached wrapper, which provides cross-process and cross-system
 # caching.
 sub memcached {
-    return $_[0]->process_cache->{memcached} ||= Bugzilla::Memcached->_new();
+    # BMO - use metrics subclass if required
+    if (Bugzilla->metrics_enabled) {
+        return $_[0]->request_cache->{memcached} ||= Bugzilla::Metrics::Memcached->_new();
+    } else {
+        return $_[0]->request_cache->{memcached} ||= Bugzilla::Memcached->_new();
+    }
 }
 
 # Private methods
@@ -671,6 +725,11 @@ sub memcached {
 # Per-process cleanup. Note that this is a plain subroutine, not a method,
 # so we don't have $class available.
 sub _cleanup {
+    # BMO - finalise and report on metrics
+    if (Bugzilla->metrics_enabled) {
+        Bugzilla->metrics->finish();
+    }
+
     my $main   = Bugzilla->request_cache->{dbh_main};
     my $shadow = Bugzilla->request_cache->{dbh_shadow};
     foreach my $dbh ($main, $shadow) {
diff --git a/Bugzilla/Config/Advanced.pm b/Bugzilla/Config/Advanced.pm
index 5e51fbecc..4b57df24d 100644
--- a/Bugzilla/Config/Advanced.pm
+++ b/Bugzilla/Config/Advanced.pm
@@ -75,6 +75,37 @@ use constant get_param_list => (
    type => 't',
    default => '',
   },
+
+  {
+   name => 'metrics_enabled',
+   type => 'b',
+   default => 0
+  },
+  {
+   name => 'metrics_user_ids',
+   type => 't',
+   default => '3881,5038,5898,13647,20209,251051,373476,409787'
+  },
+  {
+   name => 'metrics_elasticsearch_server',
+   type => 't',
+   default => '127.0.0.1:9200'
+  },
+  {
+   name => 'metrics_elasticsearch_index',
+   type => 't',
+   default => 'bmo-metrics'
+  },
+  {
+   name => 'metrics_elasticsearch_type',
+   type => 't',
+   default => 'timings'
+  },
+  {
+   name => 'metrics_elasticsearch_ttl',
+   type => 't',
+   default => '1210000000' # 14 days
+  },
 );
 
 1;
diff --git a/Bugzilla/DB.pm b/Bugzilla/DB.pm
index 61cd3eab8..183f619a5 100644
--- a/Bugzilla/DB.pm
+++ b/Bugzilla/DB.pm
@@ -43,6 +43,8 @@ use Bugzilla::Util;
 use Bugzilla::Error;
 use Bugzilla::DB::Schema;
 
+use Bugzilla::Metrics::Mysql;
+
 use List::Util qw(max);
 use Storable qw(dclone);
 
@@ -148,6 +150,12 @@ sub _connect {
                 . " localconfig: " . $@);
 
     # instantiate the correct DB specific module
+
+    # BMO - enable instrumentation of db calls
+    if (Bugzilla->metrics_enabled) {
+        $pkg_module = 'Bugzilla::Metrics::Mysql';
+    }
+
     my $dbh = $pkg_module->new($params);
 
     return $dbh;
diff --git a/Bugzilla/Install/Filesystem.pm b/Bugzilla/Install/Filesystem.pm
index 1abac0154..c8a951deb 100644
--- a/Bugzilla/Install/Filesystem.pm
+++ b/Bugzilla/Install/Filesystem.pm
@@ -160,6 +160,7 @@ sub FILESYSTEM {
         'jobqueue.pl'     => { perms => OWNER_EXECUTE },
         'migrate.pl'      => { perms => OWNER_EXECUTE },
         'sentry.pl'       => { perms => OWNER_EXECUTE },
+        'metrics.pl'      => { perms => OWNER_EXECUTE },
         'install-module.pl' => { perms => OWNER_EXECUTE },
 
         'Bugzilla.pm'   => { perms => CGI_READ },
diff --git a/Bugzilla/Install/Requirements.pm b/Bugzilla/Install/Requirements.pm
index 384df221e..1c9c91345 100644
--- a/Bugzilla/Install/Requirements.pm
+++ b/Bugzilla/Install/Requirements.pm
@@ -386,6 +386,13 @@ sub OPTIONAL_MODULES {
         version => '0',
         feature => ['memcached'],
     },
+
+    # BMO - metrics
+    {
+        package => 'ElasticSearch',
+        module  => 'ElasticSearch',
+        version => '0',
+    },
     );
 
     my $extra_modules = _get_extension_requirements('OPTIONAL_MODULES');
diff --git a/Bugzilla/Instrument.pm b/Bugzilla/Instrument.pm
deleted file mode 100644
index 4ab74ff8e..000000000
--- a/Bugzilla/Instrument.pm
+++ /dev/null
@@ -1,68 +0,0 @@
-# This Source Code Form is subject to the terms of the Mozilla Public
-# License, v. 2.0. If a copy of the MPL was not distributed with this
-# file, You can obtain one at http://mozilla.org/MPL/2.0/.
-#
-# This Source Code Form is "Incompatible With Secondary Licenses", as
-# defined by the Mozilla Public License, v. 2.0.
-
-package Bugzilla::Instrument;
-
-use strict;
-use warnings;
-
-use Time::HiRes qw(clock_gettime CLOCK_MONOTONIC);
-use Encode qw(encode_utf8);
-use Sys::Syslog qw(:DEFAULT);
-
-sub new {
-    my ($class, $label) = @_;
-    my $self = bless({ times => [], labels => [], values => [] }, $class);
-    $self->label($label);
-    $self->time('start_time');
-    return $self;
-}
-
-sub time {
-    my ($self, $name) = @_;
-    # for now $name isn't used
-    push @{ $self->{times} }, clock_gettime(CLOCK_MONOTONIC);
-}
-
-sub label {
-    my ($self, $value) = @_;
-    push @{ $self->{labels} }, $value;
-}
-
-sub value {
-    my ($self, $name, $value) = @_;
-    # for now $name isn't used
-    push @{ $self->{values} }, $value;
-}
-
-sub log {
-    my $self = shift;
-
-    my @times = @{ $self->{times} };
-    return unless scalar(@times) >= 2;
-    my @labels = @{ $self->{labels} };
-    my @values = @{ $self->{values} };
-
-    # calculate diffs
-    my @diffs = ($times[$#times] - $times[0]);
-    while (1) {
-        my $start = shift(@times);
-        last unless scalar(@times);
-        push @diffs, $times[0] - $start;
-    }
-
-    # build syslog string
-    my $format = '[timing]' . (' %s' x scalar(@labels)) . (' %.6f' x scalar(@diffs)) . (' %s' x scalar(@values));
-    my $entry = sprintf($format, @labels, @diffs, @values);
-
-    # and log
-    openlog('apache', 'cons,pid', 'local4');
-    syslog('notice', encode_utf8($entry));
-    closelog();
-}
-
-1;
diff --git a/Bugzilla/Metrics/Collector.pm b/Bugzilla/Metrics/Collector.pm
new file mode 100644
index 000000000..7b2fc3f1b
--- /dev/null
+++ b/Bugzilla/Metrics/Collector.pm
@@ -0,0 +1,160 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+package Bugzilla::Metrics::Collector;
+
+use strict;
+use warnings;
+
+# the reporter needs to be a constant and use'd here to ensure it's loaded at
+# compile time.
+use constant REPORTER => 'Bugzilla::Metrics::Reporter::ElasticSearch';
+use Bugzilla::Metrics::Reporter::ElasticSearch;
+
+# Debugging reporter
+#use constant REPORTER => 'Bugzilla::Metrics::Reporter::STDERR';
+#use Bugzilla::Metrics::Reporter::STDERR;
+
+use File::Basename;
+use Time::HiRes qw(gettimeofday clock_gettime CLOCK_MONOTONIC);
+
+sub new {
+    my ($class, $name) = @_;
+    my $self = {
+        root => undef,
+        head => undef,
+        time => scalar(gettimeofday()),
+    };
+    bless($self, $class);
+    $self->_start_timer({ type => 'main', name => $name });
+    return $self;
+}
+
+sub end {
+    my ($self, $timer) = @_;
+    my $is_head = $timer ? 0 : 1;
+    $timer ||= $self->{head};
+    $timer->{duration} += clock_gettime(CLOCK_MONOTONIC) - $timer->{start_time};
+    $self->{head} = $self->{head}->{parent} if $is_head;
+}
+
+sub DESTROY {
+    my ($self) = @_;
+    $self->finish() if $self->{head};
+}
+
+sub finish {
+    my ($self) = @_;
+    $self->end($self->{root});
+    delete $self->{head};
+
+    my $user = Bugzilla->user;
+    if ($ENV{MOD_PERL}) {
+        require Apache2::RequestUtil;
+        my $request = eval { Apache2::RequestUtil->request };
+        my $headers = $request ? $request->headers_in() : {};
+        $self->{env} = {
+            referer         => $headers->{Referer},
+            request_method  => $request->method,
+            request_uri     => basename($request->unparsed_uri),
+            script_name     => $request->uri,
+            user_agent      => $headers->{'User-Agent'},
+        };
+    }
+    else {
+        $self->{env} = {
+            referer         => $ENV{HTTP_REFERER},
+            request_method  => $ENV{REQUEST_METHOD},
+            request_uri     => $ENV{REQUEST_URI},
+            script_name     => basename($ENV{SCRIPT_NAME}),
+            user_agent      => $ENV{HTTP_USER_AGENT},
+        };
+    }
+    $self->{env}->{name}    = $self->{root}->{name};
+    $self->{env}->{time}    = $self->{time};
+    $self->{env}->{user_id} = $user->id;
+    $self->{env}->{login}   = $user->login if $user->id;
+
+    # remove passwords from request_uri
+    $self->{env}->{request_uri} =~ s/\b((?:bugzilla_)?password=)(?:[^&]+|.+$)/$1x/gi;
+
+    $self->report();
+}
+
+sub name {
+    my ($self, $value) = @_;
+    $self->{root}->{name} = $value if defined $value;
+    return $self->{root}->{name};
+}
+
+sub db_start {
+    my ($self) = @_;
+    my $timer = $self->_start_timer({ type => 'db' });
+
+    my @stack;
+    my $i = 0;
+    while (1) {
+        my @caller = caller($i);
+        last unless @caller;
+        last if substr($caller[1], -5, 5) eq '.tmpl';
+        push @stack, "$caller[1]:$caller[2]"
+            unless substr($caller[1], 0, 16) eq 'Bugzilla/Metrics';
+        $i++;
+    }
+    $timer->{stack} = \@stack;
+
+    return $timer;
+}
+
+sub template_start {
+    my ($self, $file) = @_;
+    $self->_start_timer({ type => 'tmpl', file => $file });
+}
+
+sub memcached_start {
+    my ($self, $key) = @_;
+    $self->_start_timer({ type => 'memcached', key => $key });
+}
+
+sub memcached_end {
+    my ($self, $hit) = @_;
+    $self->{head}->{result} = $hit ? 'hit' : 'miss';
+    $self->end();
+}
+
+sub resume {
+    my ($self, $timer) = @_;
+    $timer->{start_time} = clock_gettime(CLOCK_MONOTONIC);
+    return $timer;
+}
+
+sub _start_timer {
+    my ($self, $timer) = @_;
+    $timer->{start_time} = $timer->{first_time} = clock_gettime(CLOCK_MONOTONIC);
+    $timer->{duration} = 0;
+    $timer->{children}   = [];
+
+    if ($self->{head}) {
+        $timer->{parent} = $self->{head};
+        push @{ $self->{head}->{children} }, $timer;
+    }
+    else {
+        $timer->{parent} = undef;
+        $self->{root} = $timer;
+    }
+    $self->{head} = $timer;
+
+    return $timer;
+}
+
+sub report {
+    my ($self) = @_;
+    my $class = REPORTER;
+    $class->DETACH ? $class->background($self) : $class->foreground($self);
+}
+
+1;
diff --git a/Bugzilla/Metrics/Memcached.pm b/Bugzilla/Metrics/Memcached.pm
new file mode 100644
index 000000000..8dccdb323
--- /dev/null
+++ b/Bugzilla/Metrics/Memcached.pm
@@ -0,0 +1,23 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+package Bugzilla::Metrics::Memcached;
+
+use strict;
+use warnings;
+
+use parent 'Bugzilla::Memcached';
+
+sub _get {
+    my $self = shift;
+    Bugzilla->metrics->memcached_start($_[0]);
+    my $result = $self->SUPER::_get(@_);
+    Bugzilla->metrics->memcached_end($result);
+    return $result;
+}
+
+1;
diff --git a/Bugzilla/Metrics/Mysql.pm b/Bugzilla/Metrics/Mysql.pm
new file mode 100644
index 000000000..7719d1cac
--- /dev/null
+++ b/Bugzilla/Metrics/Mysql.pm
@@ -0,0 +1,148 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+package Bugzilla::Metrics::Mysql;
+
+use 5.10.1;
+use strict;
+use warnings;
+
+use parent 'Bugzilla::DB::Mysql';
+
+sub do {
+    my ($self, @args) = @_;
+    Bugzilla->metrics->db_start($args[0]);
+    my $result = $self->SUPER::do(@args);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+sub selectall_arrayref {
+    my ($self, @args) = @_;
+    Bugzilla->metrics->db_start($args[0]);
+    my $result = $self->SUPER::selectall_arrayref(@args);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+sub selectall_hashref {
+    my ($self, @args) = @_;
+    Bugzilla->metrics->db_start($args[0]);
+    my $result = $self->SUPER::selectall_hashref(@args);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+sub selectcol_arrayref {
+    my ($self, @args) = @_;
+    Bugzilla->metrics->db_start($args[0]);
+    my $result = $self->SUPER::selectcol_arrayref(@args);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+sub selectrow_array {
+    my ($self, @args) = @_;
+    Bugzilla->metrics->db_start($args[0]);
+    my @result = $self->SUPER::selectrow_array(@args);
+    Bugzilla->metrics->end();
+    return wantarray ? @result : $result[0];
+}
+
+sub selectrow_arrayref {
+    my ($self, @args) = @_;
+    Bugzilla->metrics->db_start($args[0]);
+    my $result = $self->SUPER::selectrow_arrayref(@args);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+sub selectrow_hashref {
+    my ($self, @args) = @_;
+    Bugzilla->metrics->db_start($args[0]);
+    my $result = $self->SUPER::selectrow_hashref(@args);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+sub commit {
+    my ($self, @args) = @_;
+    Bugzilla->metrics->db_start('COMMIT');
+    my $result = $self->SUPER::commit(@args);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+sub prepare {
+    my ($self, @args) = @_;
+    my $sth = $self->SUPER::prepare(@args);
+    bless($sth, 'Bugzilla::Metrics::st');
+    return $sth;
+}
+
+package Bugzilla::Metrics::st;
+
+use 5.10.1;
+use strict;
+use warnings;
+
+use base 'DBI::st';
+
+sub execute {
+    my ($self, @args) = @_;
+    $self->{private_timer} = Bugzilla->metrics->db_start();
+    my $result = $self->SUPER::execute(@args);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+sub fetchrow_array {
+    my ($self, @args) = @_;
+    my $timer = $self->{private_timer};
+    Bugzilla->metrics->resume($timer);
+    my @result = $self->SUPER::fetchrow_array(@args);
+    Bugzilla->metrics->end($timer);
+    return wantarray ? @result : $result[0];
+}
+
+sub fetchrow_arrayref {
+    my ($self, @args) = @_;
+    my $timer = $self->{private_timer};
+    Bugzilla->metrics->resume($timer);
+    my $result = $self->SUPER::fetchrow_arrayref(@args);
+    Bugzilla->metrics->end($timer);
+    return $result;
+}
+
+sub fetchrow_hashref {
+    my ($self, @args) = @_;
+    my $timer = $self->{private_timer};
+    Bugzilla->metrics->resume($timer);
+    my $result = $self->SUPER::fetchrow_hashref(@args);
+    Bugzilla->metrics->end($timer);
+    return $result;
+}
+
+sub fetchall_arrayref {
+    my ($self, @args) = @_;
+    my $timer = $self->{private_timer};
+    Bugzilla->metrics->resume($timer);
+    my $result = $self->SUPER::fetchall_arrayref(@args);
+    Bugzilla->metrics->end($timer);
+    return $result;
+}
+
+sub fetchall_hashref {
+    my ($self, @args) = @_;
+    my $timer = $self->{private_timer};
+    Bugzilla->metrics->resume($timer);
+    my $result = $self->SUPER::fetchall_hashref(@args);
+    Bugzilla->metrics->end($timer);
+    return $result;
+}
+
+1;
diff --git a/Bugzilla/Metrics/Reporter.pm b/Bugzilla/Metrics/Reporter.pm
new file mode 100644
index 000000000..42d2c3abc
--- /dev/null
+++ b/Bugzilla/Metrics/Reporter.pm
@@ -0,0 +1,101 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+package Bugzilla::Metrics::Reporter;
+
+use strict;
+use warnings;
+
+use Bugzilla::Constants;
+use File::Slurp;
+use File::Temp;
+use JSON;
+
+# most reporters should detach from the httpd process.
+# reporters which do not detach will block completion of the http response.
+use constant DETACH => 1;
+
+# class method to start the delivery script in the background
+sub background {
+    my ($class, $collector) = @_;
+
+    # we need to remove parent links to avoid looped structures, which
+    # encode_json chokes on
+    _walk_timers($collector->{root}, sub { delete $_[0]->{parent} });
+
+    # serialisation
+    my $json = encode_json({ env => $collector->{env}, times => $collector->{root} });
+
+    # write to temp filename
+    my $fh = File::Temp->new( UNLINK => 0 );
+    if (!$fh) {
+        warn "Failed to create temp file: $!\n";
+        return;
+    }
+    binmode($fh, ':utf8');
+    print $fh $json;
+    close($fh) or die "$fh : $!";
+    my $filename = $fh->filename;
+
+    # spawn delivery worker
+    my $command = bz_locations()->{'cgi_path'} . "/metrics.pl '$class' '$filename' &";
+    system($command);
+}
+
+# run the reporter immediately
+sub foreground {
+    my ($class, $collector) = @_;
+    my $reporter = $class->new({ hashref => { env => $collector->{env}, times => $collector->{root} } });
+    $reporter->report();
+}
+
+sub new {
+    my ($invocant, $args) = @_;
+    my $class = ref($invocant) || $invocant;
+
+    # load from either a json_filename or hashref
+    my $self;
+    if ($args->{json_filename}) {
+        $self = decode_json(read_file($args->{json_filename}, binmode => ':utf8'));
+        unlink($args->{json_filename});
+    }
+    else {
+        $self = $args->{hashref};
+    }
+    bless($self, $class);
+
+    # remove redundant data
+    $self->walk_timers(sub {
+        my ($timer) = @_;
+        $timer->{start_time} = delete $timer->{first_time};
+        delete $timer->{children}
+            if exists $timer->{children} && !scalar(@{ $timer->{children} });
+    });
+
+    return $self;
+}
+
+sub walk_timers {
+    my ($self, $callback) = @_;
+    _walk_timers($self->{times}, $callback, undef);
+}
+
+sub _walk_timers {
+    my ($timer, $callback, $parent) = @_;
+    $callback->($timer, $parent);
+    if (exists $timer->{children}) {
+        foreach my $child (@{ $timer->{children} }) {
+            _walk_timers($child, $callback, $timer);
+        }
+    }
+}
+
+sub report {
+    die "abstract method call";
+}
+
+1;
diff --git a/Bugzilla/Metrics/Reporter/ElasticSearch.pm b/Bugzilla/Metrics/Reporter/ElasticSearch.pm
new file mode 100644
index 000000000..4b424b5da
--- /dev/null
+++ b/Bugzilla/Metrics/Reporter/ElasticSearch.pm
@@ -0,0 +1,96 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+package Bugzilla::Metrics::Reporter::ElasticSearch;
+
+use strict;
+use warnings;
+
+use parent 'Bugzilla::Metrics::Reporter';
+
+use constant DETACH => 1;
+
+sub report {
+    my ($self) = @_;
+
+    # build path array and flatten
+    my @timers;
+    $self->walk_timers(sub {
+        my ($timer, $parent) = @_;
+        $timer->{id} = scalar(@timers);
+        if ($parent) {
+            if (exists $timer->{children}) {
+                if ($timer->{type} eq 'tmpl') {
+                    $timer->{node} = 'tmpl: ' . $timer->{file};
+                }
+                elsif ($timer->{type} eq 'db') {
+                    $timer->{node} = 'db';
+                }
+                else {
+                    $timer->{node} = '?';
+                }
+            }
+            $timer->{path} = [ @{ $parent->{path} }, $parent->{node} ];
+            $timer->{parent} = $parent->{id};
+        }
+        else {
+            $timer->{path} = [ ];
+            $timer->{node} = $timer->{name};
+        }
+        push @timers, $timer;
+    });
+
+    # calculate timer-only durations
+    $self->walk_timers(sub {
+        my ($timer) = @_;
+        my $child_duration = 0;
+        if (exists $timer->{children}) {
+            foreach my $child (@{ $timer->{children} }) {
+                $child_duration += $child->{duration};
+            }
+        }
+        $timer->{this_duration} = $timer->{duration} - $child_duration;
+    });
+
+    # massage each timer
+    my $start_time = $self->{times}->{start_time};
+    foreach my $timer (@timers) {
+        # remove node name and children
+        delete $timer->{node};
+        delete $timer->{children};
+
+        # show relative times
+        $timer->{start_time} = $timer->{start_time} - $start_time;
+        delete $timer->{end_time};
+
+        # show times in ms instead of fractional seconds
+        foreach my $field (qw( start_time duration this_duration )) {
+            $timer->{$field} = sprintf('%.4f', $timer->{$field} * 1000) * 1;
+        }
+    }
+
+    # remove private data from env
+    delete $self->{env}->{user_agent};
+    delete $self->{env}->{referer};
+
+    # throw at ES
+    require ElasticSearch;
+    ElasticSearch->new(
+        servers     => Bugzilla->params->{metrics_elasticsearch_server},
+        transport   => 'http',
+    )->index(
+        index   => Bugzilla->params->{metrics_elasticsearch_index},
+        type    => Bugzilla->params->{metrics_elasticsearch_type},
+        ttl     => Bugzilla->params->{metrics_elasticsearch_ttl},
+        data    => {
+            env     => $self->{env},
+            times   => \@timers,
+        },
+    );
+}
+
+1;
diff --git a/Bugzilla/Metrics/Reporter/STDERR.pm b/Bugzilla/Metrics/Reporter/STDERR.pm
new file mode 100644
index 000000000..f5bd38acb
--- /dev/null
+++ b/Bugzilla/Metrics/Reporter/STDERR.pm
@@ -0,0 +1,151 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+package Bugzilla::Metrics::Reporter::STDERR;
+
+use strict;
+use warnings;
+
+use parent 'Bugzilla::Metrics::Reporter';
+
+use Data::Dumper;
+
+use constant DETACH => 0;
+
+sub report {
+    my ($self) = @_;
+
+    # count totals
+    $self->{total} = $self->{times}->{duration};
+    $self->{tmpl_count} = $self->{db_count} = $self->{mem_count} = 0;
+    $self->{total_tmpl} = $self->{total_db} = $self->{mem_hits}  = 0;
+    $self->{mem_keys} = {};
+    $self->_tally($self->{times});
+
+    # calculate percentages
+    $self->{other} = $self->{total} - $self->{total_tmpl} - $self->{total_db};
+    if ($self->{total} * 1) {
+        $self->{perc_tmpl}  = $self->{total_tmpl} / $self->{total} * 100;
+        $self->{perc_db}    = $self->{total_db} / $self->{total} * 100;
+        $self->{perc_other} = $self->{other} / $self->{total} * 100;
+    } else {
+        $self->{perc_tmpl} = 0;
+        $self->{perc_db} = 0;
+        $self->{perc_other} = 0;
+    }
+    if ($self->{mem_count}) {
+        $self->{perc_mem} = $self->{mem_hits} / $self->{mem_count} * 100;
+    } else {
+        $self->{perm_mem} = 0;
+    }
+
+    # convert to ms and format
+    foreach my $key (qw( total total_tmpl total_db other )) {
+        $self->{$key} = sprintf("%.4f", $self->{$key} * 1000);
+    }
+    foreach my $key (qw( perc_tmpl perc_db perc_other perc_mem )) {
+        $self->{$key} = sprintf("%.1f", $self->{$key});
+    }
+
+    # massage each timer
+    my $start_time = $self->{times}->{start_time};
+    $self->walk_timers(sub {
+        my ($timer) = @_;
+        delete $timer->{parent};
+
+        # show relative times
+        $timer->{start_time} = $timer->{start_time} - $start_time;
+        delete $timer->{end_time};
+
+        # show times in ms instead of fractional seconds
+        foreach my $field (qw( start_time duration duration_this )) {
+            $timer->{$field} = sprintf('%.4f', $timer->{$field} * 1000) * 1
+                if exists $timer->{$field};
+        }
+    });
+
+    if (0) {
+        # dump timers to stderr
+        local $Data::Dumper::Indent = 1;
+        local $Data::Dumper::Terse = 1;
+        local $Data::Dumper::Sortkeys = sub {
+            my ($rh) = @_;
+            return [ sort { $b cmp $a } keys %$rh ];
+        };
+        print STDERR Dumper($self->{env});
+        print STDERR Dumper($self->{times});
+    }
+
+    # summary summary table too
+    print STDERR <<EOF;
+total time: $self->{total}
+ tmpl time: $self->{total_tmpl} ($self->{perc_tmpl}%) $self->{tmpl_count} hits
+   db time: $self->{total_db} ($self->{perc_db}%) $self->{db_count} hits
+other time: $self->{other} ($self->{perc_other}%)
+ memcached: $self->{perc_mem}% ($self->{mem_count} requests)
+EOF
+    my $tmpls = $self->{tmpl};
+    my $len = 0;
+    foreach my $file (keys %$tmpls) {
+        $len = length($file) if length($file) > $len;
+    }
+    foreach my $file (sort { $tmpls->{$b}->{count} <=> $tmpls->{$a}->{count} } keys %$tmpls) {
+        my $tmpl = $tmpls->{$file};
+        printf STDERR
+            "%${len}s: %2s hits %8.4f total %8.4f avg\n",
+            $file,
+            $tmpl->{count},
+            $tmpl->{duration} * 1000,
+            $tmpl->{duration} * 1000 / $tmpl->{count}
+        ;
+    }
+    my $keys = $self->{mem_keys};
+    $len = 0;
+    foreach my $key (keys %$keys) {
+        $len = length($key) if length($key) > $len;
+    }
+    foreach my $key (sort { $keys->{$a} <=> $keys->{$b} or $a cmp $b } keys %$keys) {
+        printf STDERR "%${len}s: %s\n", $key, $keys->{$key};
+    }
+}
+
+sub _tally {
+    my ($self, $timer) = @_;
+    if (exists $timer->{children}) {
+        foreach my $child (@{ $timer->{children} }) {
+            $self->_tally($child);
+        }
+    }
+
+    if ($timer->{type} eq 'db') {
+        $timer->{duration_this} = $timer->{duration};
+        $self->{total_db} += $timer->{duration};
+        $self->{db_count}++;
+
+    } elsif ($timer->{type} eq 'tmpl') {
+        my $child_duration = 0;
+        if (exists $timer->{children}) {
+            foreach my $child (@{ $timer->{children} }) {
+                $child_duration += $child->{duration};
+            }
+        }
+        $timer->{duration_this} = $timer->{duration} - $child_duration;
+
+        $self->{total_tmpl} += $timer->{duration} - $child_duration;
+        $self->{tmpl_count}++;
+        $self->{tmpl}->{$timer->{file}}->{count}++;
+        $self->{tmpl}->{$timer->{file}}->{duration} += $timer->{duration};
+
+    } elsif ($timer->{type} eq 'memcached') {
+        $timer->{duration_this} = $timer->{duration};
+        $self->{mem_count}++;
+        $self->{mem_keys}->{$timer->{key}}++;
+        $self->{mem_hits}++ if $timer->{result} eq 'hit';
+    }
+}
+
+1;
diff --git a/Bugzilla/Metrics/Template.pm b/Bugzilla/Metrics/Template.pm
new file mode 100644
index 000000000..a3b13f85d
--- /dev/null
+++ b/Bugzilla/Metrics/Template.pm
@@ -0,0 +1,23 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+package Bugzilla::Metrics::Template;
+
+use strict;
+use warnings;
+
+use parent 'Bugzilla::Template';
+
+sub process {
+    my $self = shift;
+    Bugzilla->metrics->template_start($_[0]);
+    my $result = $self->SUPER::process(@_);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+1;
diff --git a/Bugzilla/Metrics/Template/Context.pm b/Bugzilla/Metrics/Template/Context.pm
new file mode 100644
index 000000000..ae8470b3f
--- /dev/null
+++ b/Bugzilla/Metrics/Template/Context.pm
@@ -0,0 +1,29 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+package Bugzilla::Metrics::Template::Context;
+
+use strict;
+use warnings;
+
+use parent 'Bugzilla::Template::Context';
+
+sub process {
+    my $self = shift;
+
+    # we only want to measure files not template blocks
+    if (ref($_[0]) || substr($_[0], -5) ne '.tmpl') {
+        return $self->SUPER::process(@_);
+    }
+
+    Bugzilla->metrics->template_start($_[0]);
+    my $result = $self->SUPER::process(@_);
+    Bugzilla->metrics->end();
+    return $result;
+}
+
+1;
diff --git a/Bugzilla/Template.pm b/Bugzilla/Template.pm
index bf1254626..fdeda165c 100644
--- a/Bugzilla/Template.pm
+++ b/Bugzilla/Template.pm
@@ -982,7 +982,10 @@ sub create {
     $shared_providers->{$provider_key} ||= Template::Provider->new($config);
     $config->{LOAD_TEMPLATES} = [ $shared_providers->{$provider_key} ];
 
-    local $Template::Config::CONTEXT = 'Bugzilla::Template::Context';
+    # BMO - use metrics subclass
+    local $Template::Config::CONTEXT = Bugzilla->metrics_enabled()
+        ? 'Bugzilla::Metrics::Template::Context'
+        : 'Bugzilla::Template::Context';
 
     Bugzilla::Hook::process('template_before_create', { config => $config });
     my $template = $class->new($config) 
diff --git a/Bugzilla/WebService/Server.pm b/Bugzilla/WebService/Server.pm
index 9727dcbcb..00820358b 100644
--- a/Bugzilla/WebService/Server.pm
+++ b/Bugzilla/WebService/Server.pm
@@ -31,6 +31,11 @@ sub handle_login {
     # Throw error if the supplied class does not exist or the method is private
     ThrowCodeError('unknown_method', {method => $full_method}) if (!$class or $method =~ /^_/);
 
+    # BMO - use the class and method as the name, instead of the cgi filename
+    if (Bugzilla->metrics_enabled) {
+        Bugzilla->metrics->name("$class $method");
+    }
+
     eval "require $class";
     ThrowCodeError('unknown_method', {method => $full_method}) if $@;
     return if ($class->login_exempt($method) 
diff --git a/metrics.pl b/metrics.pl
new file mode 100644
index 000000000..5d955fd88
--- /dev/null
+++ b/metrics.pl
@@ -0,0 +1,47 @@
+#!/usr/bin/perl -w
+
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# This Source Code Form is "Incompatible With Secondary Licenses", as
+# defined by the Mozilla Public License, v. 2.0.
+
+use strict;
+use warnings;
+
+BEGIN {
+    delete $ENV{SERVER_SOFTWARE};
+}
+
+use FindBin qw($Bin);
+use lib $Bin;
+use lib "$Bin/lib";
+
+use Bugzilla;
+use Bugzilla::Constants;
+use File::Slurp;
+use POSIX qw(setsid nice);
+
+Bugzilla->metrics_enabled(0);
+Bugzilla->usage_mode(USAGE_MODE_CMDLINE);
+nice(19);
+
+# grab reporter class and filename
+exit(1) unless my $reporter_class = shift;
+exit(1) unless my $filename = shift;
+
+# create reporter object and report
+eval "use $reporter_class";
+
+# detach
+if ($reporter_class->DETACH) {
+    open(STDIN, '</dev/null');
+    open(STDOUT, '>/dev/null');
+    open(STDERR, '>/dev/null');
+    setsid();
+}
+
+# report
+exit(1) unless my $reporter = $reporter_class->new({ json_filename => $filename });
+$reporter->report();
diff --git a/page.cgi b/page.cgi
index a6a198d8b..f4e5a9f6b 100755
--- a/page.cgi
+++ b/page.cgi
@@ -78,6 +78,11 @@ if ($id) {
         ThrowCodeError("bad_page_cgi_id", { "page_id" => $id });
     }
 
+    # BMO - append template filename to metrics data
+    if (Bugzilla->metrics_enabled) {
+        Bugzilla->metrics->name("page.cgi $id");
+    }
+
     my %vars = ( 
       quicksearch_field_names => \&quicksearch_field_names,
     );
diff --git a/process_bug.cgi b/process_bug.cgi
index fef6bb499..20875fb29 100755
--- a/process_bug.cgi
+++ b/process_bug.cgi
@@ -58,7 +58,6 @@ use Bugzilla::Keyword;
 use Bugzilla::Flag;
 use Bugzilla::Status;
 use Bugzilla::Token;
-use Bugzilla::Instrument;
 
 use List::MoreUtils qw(firstidx);
 use Storable qw(dclone);
@@ -70,8 +69,6 @@ my $dbh = Bugzilla->dbh;
 my $template = Bugzilla->template;
 my $vars = {};
 
-my $timings = Bugzilla::Instrument->new('process_bug');
-
 ######################################################################
 # Subroutines
 ######################################################################
@@ -145,8 +142,6 @@ Bugzilla::User::match_field({
 
 print $cgi->header() unless Bugzilla->usage_mode == USAGE_MODE_EMAIL;
 
-$timings->time('load_bug');
-
 # Check for a mid-air collision. Currently this only works when updating
 # an individual bug.
 my $delta_ts = $cgi->param('delta_ts') || '';
@@ -211,8 +206,6 @@ else {
     check_token_data($token, 'buglist_mass_change', 'query.cgi');
 }
 
-$timings->time('mid_air');
-
 ######################################################################
 # End Data/Security Validation
 ######################################################################
@@ -401,14 +394,11 @@ if (defined $cgi->param('id')) {
     $first_bug->set_flags($flags, $new_flags);
 }
 
-$timings->time('update_time');
-
 ##############################
 # Do Actual Database Updates #
 ##############################
 foreach my $bug (@bug_objects) {
     my $changes = $bug->update();
-    $timings->time('db_time');
 
     if ($changes->{'bug_status'}) {
         my $new_status = $changes->{'bug_status'}->[1];
@@ -421,10 +411,6 @@ foreach my $bug (@bug_objects) {
     }
 
     my $recipient_count = $bug->send_changes($changes, $vars);
-    $timings->time('bugmail_time');
-    $timings->label('bug-' . $bug->id);
-    $timings->label('user-' . $user->id);
-    $timings->value('recipient_count', $recipient_count);
 }
 
 # Delete the session token used for the mass-change.
@@ -450,8 +436,6 @@ elsif ($action eq 'next_bug' or $action eq 'same_bug') {
         }
         $template->process("bug/show.html.tmpl", $vars)
           || ThrowTemplateError($template->error());
-        $timings->time('template_time');
-        $timings->log() if scalar(@bug_objects) == 1;
         exit;
     }
 } elsif ($action ne 'nothing') {
@@ -464,8 +448,6 @@ unless (Bugzilla->usage_mode == USAGE_MODE_EMAIL) {
         || ThrowTemplateError($template->error());
     $template->process("global/footer.html.tmpl", $vars)
         || ThrowTemplateError($template->error());
-    $timings->time('template_time');
-    $timings->log() if scalar(@bug_objects) == 1;
 }
 
 1;
diff --git a/sentry.pl b/sentry.pl
index b5b9c3f31..a053cc988 100755
--- a/sentry.pl
+++ b/sentry.pl
@@ -16,6 +16,10 @@
 use strict;
 use warnings;
 
+BEGIN {
+    delete $ENV{SERVER_SOFTWARE};
+}
+
 use FindBin qw($Bin);
 use lib $Bin;
 use lib "$Bin/lib";
diff --git a/show_bug.cgi b/show_bug.cgi
index 99679f7ad..c87ef1601 100755
--- a/show_bug.cgi
+++ b/show_bug.cgi
@@ -30,16 +30,12 @@ use Bugzilla::Error;
 use Bugzilla::User;
 use Bugzilla::Keyword;
 use Bugzilla::Bug;
-use Bugzilla::Instrument;
-
-my $timings = Bugzilla::Instrument->new('show_bug');
 
 my $cgi = Bugzilla->cgi;
 my $template = Bugzilla->template;
 my $vars = {};
 
 my $user = Bugzilla->login();
-$timings->time('login_time');
 
 my $format = $template->get_format("bug/show", scalar $cgi->param('format'),
                                    scalar $cgi->param('ctype'));
@@ -93,10 +89,8 @@ if ($single) {
         }
     }
 }
-$timings->time('load_bug_time');
 
 Bugzilla::Bug->preload(\@bugs);
-$timings->time('preload_time');
 
 $vars->{'bugs'} = \@bugs;
 $vars->{'marks'} = \%marks;
@@ -134,10 +128,4 @@ print $cgi->header($format->{'ctype'});
 
 $template->process($format->{'template'}, $vars)
   || ThrowTemplateError($template->error());
-$timings->time('template_time');
 
-if (scalar(@bugids) == 1) {
-    $timings->label('bug-' . $bugs[0]->id);
-    $timings->label('user-' . $user->id);
-    $timings->log();
-}
diff --git a/template/en/default/admin/params/advanced.html.tmpl b/template/en/default/admin/params/advanced.html.tmpl
index 5301ff2cf..a2103c652 100644
--- a/template/en/default/admin/params/advanced.html.tmpl
+++ b/template/en/default/admin/params/advanced.html.tmpl
@@ -85,5 +85,19 @@
   sentry_uri =>
     "When set, important errors and warnings will be sent to the"
     _ " specified Sentry server. Enter the full API KEY URL."
-    _ " eg <code>https://01234567890123456780123456780123:01234567890123456780123456780123@errormill.mozilla.org/10</code>.",
+    _ " eg <kbd>https://01234567890123456780123456780123:01234567890123456780123456780123@errormill.mozilla.org/10</kbd>.",
+
+  metrics_enabled =>
+    "Collect metrics for reporting to ElasticSearch",
+  metrics_user_ids =>
+    "Comma separated list of user_id's which trigger data collection and reporting."
+    _ " eg <kbd>3881,5038,5898,13647,20209,251051,373476,409787</kbd>.",
+  metrics_elasticsearch_server =>
+    "Metrics ElasticSearch server and port. eg <kbd>127.0.0.1:9200</kbd>",
+  metrics_elasticsearch_index =>
+    "Metrics ElasticSearch index. eg <kbd>bmo-metrics</kbd>",
+  metrics_elasticsearch_type =>
+    "Metrics ElasticSearch type. eg <kbd>timings</kbd>",
+  metrics_elasticsearch_ttl =>
+    "The time to live for data in the ElasticSearch cluster, in milliseconds. eg <kbd>1210000000</kbd>",
 } %]