blueslip: Add feature to time common operations.

This is relatively unobtrusive, and we don't send
anything to the server.

But any user can now enter blueslip.timings in the
console to see a map of how long things take in
milliseconds.  We only record one timing per
event label (i.e. the most recent).

It's pretty easy to test this by just clicking
around.  For 300 users/streams most things are
fast except for:

    - initialize_everything
    - manage streams (render_subscriptions)

Both do lots of nontrivial work, although
"manage streams" is a bit surprising, since
we're only measuring how long to build the
HTML from the templates (whereas the real
time is probably browser rendering costs).

frontend_tests/node_tests/general.js

@@ -97,6 +97,7 @@ const messages = {
 const noop = () => undefined;
 
 set_global('alert_words', {});
+set_global('blueslip', global.make_zblueslip());
 
 alert_words.process_message = noop;
 

frontend_tests/node_tests/list_render.js

@@ -9,6 +9,8 @@ set_global('Element', function () {
     return { };
 });
 
+set_global('blueslip', global.make_zblueslip());
+
 // We only need very simple jQuery wrappers for when the
 // "real" code wraps html or sets up click handlers.
 // We'll simulate most other objects ourselves.

frontend_tests/node_tests/stream_list.js

@@ -1,5 +1,6 @@
 set_global('document', 'document-stub');
 set_global('$', global.make_zjquery());
+set_global('blueslip', global.make_zblueslip());
 
 const Dict = zrequire('dict').Dict;
 const FoldDict = zrequire('fold_dict').FoldDict;

frontend_tests/node_tests/subs.js

@@ -8,6 +8,7 @@ zrequire('util');
 zrequire('stream_data');
 zrequire('search_util');
 set_global('page_params', {});
+set_global('blueslip', global.make_zblueslip());
 
 set_global('location', {
     hash: "#streams/1/announce",

frontend_tests/zjsunit/zblueslip.js

@@ -79,5 +79,9 @@ exports.make_zblueslip = function (opts) {
         return ex.message;
     };
 
+    lib.start_timing = () => {
+        return () => {};
+    };
+
     return lib;
 };

static/js/activity.js

@@ -205,9 +205,11 @@ exports.build_user_sidebar = function () {
 
     const user_ids = buddy_data.get_filtered_and_sorted_user_ids(filter_text);
 
+    const finish = blueslip.start_timing('buddy_list.populate');
     buddy_list.populate({
         keys: user_ids,
     });
+    finish();
 
     resize.resize_page_components();
 

static/js/blueslip.js

@@ -258,6 +258,18 @@ exports.fatal = function blueslip_fatal(msg, more_info) {
     throw new BlueslipError(msg, more_info);
 };
 
+exports.timings = new Map();
+
+exports.start_timing = function (label) {
+    const t1 = performance.now();
+
+    return function () {
+        const t2 = performance.now();
+        const elapsed = t2 - t1;
+        exports.timings.set(label, elapsed);
+    };
+};
+
 // Produces an easy-to-read preview on an HTML element.  Currently
 // only used for including in error report emails; be sure to discuss
 // with other developers before using it in a user-facing context

static/js/list_render.js

@@ -92,6 +92,7 @@ exports.create = function ($container, list, opts) {
 
             const slice = meta.filtered_list.slice(meta.offset, meta.offset + load_count);
 
+            const finish = blueslip.start_timing('list_render ' + opts.name);
             const html = _.reduce(slice, function (acc, item) {
                 let _item = opts.modifier(item);
 
@@ -119,6 +120,8 @@ exports.create = function ($container, list, opts) {
                 return acc + (_item || "");
             }, "");
 
+            finish();
+
             $container.append($(html));
             meta.offset += load_count;
 

static/js/pm_list.js

@@ -118,9 +118,11 @@ exports._build_private_messages_list = function () {
         display_messages.push(display_message);
     });
 
+    const finish = blueslip.start_timing('render pm list');
     const recipients_dom = render_sidebar_private_message_list({
         messages: display_messages,
     });
+    finish();
     return recipients_dom;
 };
 

static/js/stream_list.js

@@ -301,7 +301,9 @@ function set_stream_unread_count(stream_id, count) {
 }
 
 exports.update_streams_sidebar = function () {
+    const finish = blueslip.start_timing('build_stream_list');
     exports.build_stream_list();
+    finish();
     exports.stream_cursor.redraw();
 
     if (!narrow_state.active()) {

static/js/subs.js

@@ -381,10 +381,15 @@ function get_stream_id_buckets(stream_ids, query) {
 
 exports.populate_stream_settings_left_panel = function () {
     const sub_rows = stream_data.get_updated_unsorted_subs();
+
     const template_data = {
         subscriptions: sub_rows,
     };
+
+    const finish = blueslip.start_timing('render_subscriptions');
     const html = render_subscriptions(template_data);
+    finish();
+
     ui.get_content_element($('#subscriptions_table .streams-list')).html(html);
 };
 

static/js/ui_init.js

@@ -356,5 +356,7 @@ exports.initialize_everything = function () {
 };
 
 $(function () {
+    const finish = blueslip.start_timing('initialize_everything');
     exports.initialize_everything();
+    finish();
 });