Mirror
/
zulip
mirror of https://github.com/zulip/zulip.git
1
0
Fork 0
Code Issues Projects Releases Wiki Activity

sending messages: Extract sent_messages.js. 

This commit extract send_messages.js to clean up code related
to the following things:

    * sending data to /json/report_send_time
    * restarting the event loop if events don't arrive on time

The code related to /json/report changes the following ways:

    * We track the state almost completely in the new
      send_messages.js module, with other modules just
      making one-line calls.

    * We no longer send "displayed" times to the servers, since
      we were kind of lying about them anyway.

    * We now explicitly track the state of each single sent
      message in its own object.

    * We now look up data related to the messages by local_id,
      instead of message_id.  The problem with message_id was
      that is was mutable.  Now we use local_id, and we extend
      the local_id concept to messages that don't get rendered
      client side.  We no longer need to react to the
      'message_id_changed' event to change our hash key.

    * The code used to live in many places:
        * various big chunks were scattered among compose.js,
          and those were all moved or reduced to one-line
          calls into the new module
        * echo.js continues to make basically one-line calls,
          but it no longer calls compose.report_as_received(),
          nor does it set the "start" time.
        * message_util.js used to report received events, but
          only when they finally got drawn in the home view;
          this code is gone now

The code related to restarting the event loop if events don't arrive
changes as follows:

    * The timer now gets set up from within
      send_messages.message_state.report_server_ack,
      where we can easily inspect the current state of the
      possibly-still-in-flight message.

    * The code to confirm that an event was received happens now
      in server_events.js, rather than later, so that we don't
      falsely blame the event loop  for a downstream bug.  (Plus
      it's easier to just do it one place.)

This change removes a fair amount of code from our node tests.  Some
of the removal is good stuff related to us completing killing off
unnecessary code.  Other removals are more expediency-driven, and
we should make another sweep at ramping up our coverage on compose.js,
with possibly a little more mocking of the new `send_messages` code
layer, since it's now abstracted better.

There is also some minor cleanup to echo.resend_message() in this
commit.

See #5968 for a detailed breakdown of the changes.
This commit is contained in:
Steve Howell 2017-07-30 06:56:46 -04:00 committed by Tim Abbott
parent 30361f50f8
commit 3f06f28ad7
9 changed files with 261 additions and 207 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
.eslintrc.json
View File

@ -57,6 +57,7 @@
"typing_events": false,
"typing_data": false,
"typing_status": false,
"sent_messages": false,
"compose": false,
"compose_actions": false,
"compose_state": false,

112
frontend_tests/node_tests/compose.js
View File

@ -34,6 +34,11 @@ set_global('stream_edit', {});
set_global('markdown', {});
set_global('loading', {});
set_global('sent_messages', {
start_tracking_message: noop,
report_server_ack: noop,
});
// Setting these up so that we can test that links to uploads within messages are
// automatically converted to server relative links.
global.document.location.protocol = 'https:';
@ -261,72 +266,23 @@ people.add(bob);
$("#send-status").show();
$("#compose-send-button").attr('disabled', 'disabled');
$("#sending-indicator").show();
var set_timeout_called = false;
global.patch_builtin('setTimeout', function (func, delay) {
assert.equal(delay, 5000);
func();
set_timeout_called = true;
});
var server_events_triggered;
global.server_events = {
restart_get_events: function () {
server_events_triggered = true;
},
};
var reify_message_id_checked;
echo.reify_message_id = function (local_id, message_id) {
assert.equal(local_id, 1001);
assert.equal(message_id, 12);
reify_message_id_checked = true;
};
var test_date = 'Wed Jun 28 2017 22:12:48 GMT+0000 (UTC)';
compose.send_message_success(1001, 12, new Date(test_date), false);
compose.send_message_success(1001, 12, false);
assert.equal($("#new_message_content").val(), '');
assert($("#new_message_content").is_focused());
assert(!$("#send-status").visible());
assert.equal($("#compose-send-button").prop('disabled'), false);
assert(!$("#sending-indicator").visible());
assert.equal(_.keys(compose.send_times_data).length, 1);
assert.equal(compose.send_times_data[12].start.getTime(), new Date(test_date).getTime());
assert(!compose.send_times_data[12].locally_echoed);
assert(reify_message_id_checked);
assert(server_events_triggered);
assert(set_timeout_called);
}());
(function test_mark_rendered_content_disparity() {
compose.mark_rendered_content_disparity(13, true);
assert.deepEqual(compose.send_times_data[13], { rendered_content_disparity: true });
}());
(function test_report_as_received() {
var msg = {
id: 12,
sent_by_me: true,
};
var set_timeout_called = false;
global.patch_builtin('setTimeout', function (func, delay) {
assert.equal(delay, 0);
func();
set_timeout_called = true;
});
compose.send_times_data[12].locally_echoed = true;
channel.post = function (payload) {
assert.equal(payload.url, '/json/report_send_time');
assert.equal(typeof(payload.data.time), 'string');
assert(payload.data.locally_echoed);
assert(!payload.data.rendered_content_disparity);
};
compose.report_as_received(msg);
assert.equal(typeof(compose.send_times_data[12].received), 'object');
assert.equal(typeof(compose.send_times_data[12].displayed), 'object');
assert(set_timeout_called);
delete compose.send_times_data[13];
msg.id = 13;
compose.report_as_received(msg);
assert.equal(typeof(compose.send_times_data[13].received), 'object');
assert.equal(typeof(compose.send_times_data[13].displayed), 'object');
}());
(function test_send_message() {
@ -337,7 +293,6 @@ people.add(bob);
stub_state.local_id_counter = 0;
stub_state.send_msg_ajax_post_called = 0;
stub_state.get_events_running_called = 0;
stub_state.server_events_triggered = 0;
stub_state.reify_message_id_checked = 0;
return stub_state;
}
@ -346,9 +301,6 @@ people.add(bob);
func();
});
global.server_events = {
restart_get_events: function () {
stub_state.server_events_triggered += 1;
},
assert_get_events_running: function () {
stub_state.get_events_running_called += 1;
},
@ -392,7 +344,7 @@ people.add(bob);
assert.equal(typeof(message_id), 'number');
stub_state.reify_message_id_checked += 1;
};
compose.send_times_data = {};
// Setting message content with a host server link and we will assert
// later that this has been converted to a relative link.
$("#new_message_content").val('[foobar]' +
@ -409,10 +361,8 @@ people.add(bob);
get_events_running_called: 1,
reify_message_id_checked: 1,
send_msg_ajax_post_called: 1,
server_events_triggered: 1,
};
assert.deepEqual(stub_state, state);
assert.equal(_.keys(compose.send_times_data).length, 1);
assert.equal($("#new_message_content").val(), '');
assert($("#new_message_content").is_focused());
assert(!$("#send-status").visible());
@ -444,10 +394,8 @@ people.add(bob);
get_events_running_called: 1,
reify_message_id_checked: 0,
send_msg_ajax_post_called: 1,
server_events_triggered: 0,
};
assert.deepEqual(stub_state, state);
assert.equal(_.keys(compose.send_times_data).length, 1);
assert(server_error_triggered);
assert(reload_initiate_triggered);
}());
@ -485,10 +433,8 @@ people.add(bob);
get_events_running_called: 1,
reify_message_id_checked: 0,
send_msg_ajax_post_called: 1,
server_events_triggered: 0,
};
assert.deepEqual(stub_state, state);
assert.equal(_.keys(compose.send_times_data).length, 1);
assert(server_error_triggered);
assert(!reload_initiate_triggered);
assert(xhr_error_msg_checked);
@ -511,6 +457,10 @@ people.add(bob);
return;
};
sent_messages.get_new_local_id = function () {
return 'loc-55';
};
compose.send_message();
var state = {
@ -518,10 +468,8 @@ people.add(bob);
get_events_running_called: 1,
reify_message_id_checked: 0,
send_msg_ajax_post_called: 1,
server_events_triggered: 0,
};
assert.deepEqual(stub_state, state);
assert.equal(_.keys(compose.send_times_data).length, 1);
assert(server_error_triggered);
assert(!reload_initiate_triggered);
assert(xhr_error_msg_checked);
@ -792,9 +740,10 @@ function test_with_mock_socket(test_params) {
// socket_user_agent field will be added.
var request = {foo: 'bar'};
// Our success function gets passed all the way through to
// socket.send, so we can just use a stub to test that.
var success = 'success-function-stub';
var success_func_checked = false;
var success = function () {
success_func_checked = true;
};
// Our error function gets wrapped, so we set up a real
// function to test the wrapping mechanism.
@ -818,8 +767,8 @@ function test_with_mock_socket(test_params) {
socket_user_agent: 'unittest_transmit_message',
});
// Our success function never gets wrapped.
assert.equal(send_args.success, success);
send_args.success({});
assert(success_func_checked);
// Our error function does get wrapped, so we test by
// using socket.send's error callback, which should
@ -1258,25 +1207,6 @@ function test_with_mock_socket(test_params) {
assert($("#markdown_preview").visible());
}());
(function test_message_id_changed_document() {
var handler = $(document).get_on_handler('message_id_changed');
compose.send_times_data = {
1031: {
data: 'Test data!',
},
};
event.old_id = 1031;
event.new_id = 1045;
handler(event);
var send_times_data = {
1045: {
data: 'Test data!',
},
};
assert.deepEqual(compose.send_times_data, send_times_data);
}());
}());
(function test_upload_started() {

130
static/js/compose.js
View File

@ -179,20 +179,6 @@ function send_message_ajax(request, success, error) {
});
}
function report_send_time(send_time, receive_time, display_time, locally_echoed, rendered_changed) {
var data = {time: send_time.toString(),
received: receive_time.toString(),
displayed: display_time.toString(),
locally_echoed: locally_echoed};
if (locally_echoed) {
data.rendered_content_disparity = rendered_changed;
}
channel.post({
url: '/json/report_send_time',
data: data,
});
}
var socket;
if (page_params.use_websockets) {
socket = new Socket("/sockjs");
@ -211,61 +197,6 @@ function send_message_socket(request, success, error) {
});
}
exports.send_times_data = {};
function maybe_report_send_times(message_id) {
var data = exports.send_times_data[message_id];
if (data.send_finished === undefined || data.received === undefined ||
data.displayed === undefined) {
// We report the data once we have both the send and receive times
return;
}
report_send_time(data.send_finished - data.start,
data.received - data.start,
data.displayed - data.start,
data.locally_echoed,
data.rendered_content_disparity || false);
}
function mark_end_to_end_receive_time(message_id) {
if (exports.send_times_data[message_id] === undefined) {
exports.send_times_data[message_id] = {};
}
exports.send_times_data[message_id].received = new Date();
maybe_report_send_times(message_id);
}
function mark_end_to_end_display_time(message_id) {
exports.send_times_data[message_id].displayed = new Date();
maybe_report_send_times(message_id);
}
exports.mark_rendered_content_disparity = function (message_id, changed) {
if (exports.send_times_data[message_id] === undefined) {
exports.send_times_data[message_id] = {};
}
exports.send_times_data[message_id].rendered_content_disparity = changed;
};
exports.report_as_received = function report_as_received(message) {
if (message.sent_by_me) {
mark_end_to_end_receive_time(message.id);
setTimeout(function () {
mark_end_to_end_display_time(message.id);
}, 0);
}
};
function process_send_time(message_id, start_time, locally_echoed) {
var send_finished = new Date();
if (exports.send_times_data[message_id] === undefined) {
exports.send_times_data[message_id] = {};
}
exports.send_times_data[message_id].start = start_time;
exports.send_times_data[message_id].send_finished = send_finished;
exports.send_times_data[message_id].locally_echoed = locally_echoed;
maybe_report_send_times(message_id);
}
function clear_compose_box() {
$("#new_message_content").val('').focus();
drafts.delete_draft_after_send();
@ -276,25 +207,25 @@ function clear_compose_box() {
resize.resize_bottom_whitespace();
}
exports.send_message_success = function (local_id, message_id, start_time, locally_echoed) {
exports.send_message_success = function (local_id, message_id, locally_echoed) {
if (!locally_echoed) {
clear_compose_box();
}
process_send_time(message_id, start_time, locally_echoed);
echo.reify_message_id(local_id, message_id);
setTimeout(function () {
if (exports.send_times_data[message_id].received === undefined) {
blueslip.log("Restarting get_events due to delayed receipt of sent message " + message_id);
server_events.restart_get_events();
}
}, 5000);
};
exports.transmit_message = function (request, success, error) {
delete exports.send_times_data[request.id];
exports.transmit_message = function (request, on_success, error) {
function success(data) {
// Call back to our callers to do things like closing the compose
// box and turning off spinners and reifying locally echoed messages.
on_success(data);
// Once everything is done, get ready to report times to the server.
sent_messages.report_server_ack(request.local_id);
}
if (page_params.use_websockets) {
send_message_socket(request, success, error);
} else {
@ -313,27 +244,41 @@ exports.send_message = function send_message(request) {
request.to = JSON.stringify([request.to]);
}
var start_time = new Date();
var local_id;
var locally_echoed;
local_id = echo.try_deliver_locally(request);
if (local_id !== undefined) {
// We delivered this message locally
request.local_id = local_id;
if (local_id) {
// We are rendering this message locally with an id
// like 92l99.01 that corresponds to a reasonable
// approximation of the id we'll get from the server
// in terms of sorting messages.
locally_echoed = true;
} else {
// We are not rendering this message locally, but we
// track the message's life cycle with an id like
// loc-1, loc-2, loc-3,etc.
locally_echoed = false;
local_id = sent_messages.get_new_local_id();
}
var locally_echoed = local_id !== undefined;
request.local_id = local_id;
sent_messages.start_tracking_message({
local_id: local_id,
locally_echoed: locally_echoed,
});
request.locally_echoed = locally_echoed;
function success(data) {
exports.send_message_success(local_id, data.id, start_time, locally_echoed);
exports.send_message_success(local_id, data.id, locally_echoed);
}
function error(response) {
// If we're not local echo'ing messages, or if this message was not
// locally echoed, show error in compose box
if (!request.locally_echoed) {
if (!locally_echoed) {
compose_error(response, $('#new_message_content'));
return;
}
@ -893,15 +838,6 @@ exports.initialize = function () {
compose_actions.start("stream", {});
}
}
$(document).on('message_id_changed', function (event) {
if (exports.send_times_data[event.old_id] !== undefined) {
var value = exports.send_times_data[event.old_id];
delete exports.send_times_data[event.old_id];
exports.send_times_data[event.new_id] =
_.extend({}, exports.send_times_data[event.old_id], value);
}
});
};
return exports;

28
static/js/echo.js
View File

@ -9,26 +9,34 @@ function resend_message(message, row) {
message.content = message.raw_content;
var retry_spinner = row.find('.refresh-failed-message');
retry_spinner.toggleClass('rotating', true);
// Always re-set queue_id if we've gotten a new one
// since the time when the message object was initially created
message.queue_id = page_params.queue_id;
var start_time = new Date();
compose.transmit_message(message, function success(data) {
retry_spinner.toggleClass('rotating', false);
var local_id = message.local_id;
function on_success(data) {
var message_id = data.id;
var locally_echoed = true;
retry_spinner.toggleClass('rotating', false);
compose.send_message_success(message.local_id, message_id, start_time, true);
compose.send_message_success(local_id, message_id, locally_echoed);
// Resend succeeded, so mark as no longer failed
message_store.get(message_id).failed_request = false;
ui.show_failed_message_success(message_id);
}, function error(response) {
exports.message_send_error(message.local_id, response);
}
function on_error(response) {
exports.message_send_error(local_id, response);
retry_spinner.toggleClass('rotating', false);
blueslip.log("Manual resend of message failed");
});
}
sent_messages.start_resend(local_id);
compose.transmit_message(message, on_success, on_error);
}
function truncate_precision(float) {
@ -205,18 +213,18 @@ exports.process_from_server = function process_from_server(messages) {
var msgs_to_rerender = [];
messages = _.filter(messages, function (message) {
// In case we get the sent message before we get the send ACK, reify here
exports.reify_message_id(message.local_id, message.id);
var client_message = waiting_for_ack[message.local_id];
if (client_message !== undefined) {
exports.reify_message_id(message.local_id, message.id);
if (client_message.content !== message.content) {
client_message.content = message.content;
updated = true;
compose.mark_rendered_content_disparity(message.id, true);
sent_messages.mark_disparity(message.local_id);
}
msgs_to_rerender.push(client_message);
locally_processed_ids.push(client_message.id);
compose.report_as_received(client_message);
delete waiting_for_ack[client_message.id];
return false;
}

8
static/js/message_util.js
View File

@ -19,14 +19,6 @@ exports.add_messages = function add_messages(messages, msg_list, opts) {
$('#first_run_message').remove();
msg_list.add_messages(messages, opts);
if (msg_list === home_msg_list && opts.messages_are_new) {
_.each(messages, function (message) {
if (message.local_id === undefined) {
compose.report_as_received(message);
}
});
}
};

184
static/js/sent_messages.js Normal file
View File

@ -0,0 +1,184 @@
var sent_messages = (function () {
var exports = {};
exports.messages = {};
exports.reset_id_state = function () {
exports.next_local_id = 0;
};
exports.get_new_local_id = function () {
exports.next_local_id += 1;
var local_id = exports.next_local_id;
return 'loc-' + local_id.toString();
};
function report_send_time(send_time, receive_time,
locally_echoed, rendered_changed) {
var data = {
time: send_time.toString(),
received: receive_time.toString(),
locally_echoed: locally_echoed,
};
if (locally_echoed) {
data.rendered_content_disparity = rendered_changed;
}
channel.post({
url: '/json/report_send_time',
data: data,
});
}
exports.start_tracking_message = function (opts) {
var local_id = opts.local_id;
if (!opts.local_id) {
blueslip.error('You must supply a local_id');
return;
}
if (exports.messages[local_id] !== undefined) {
blueslip.error('We are re-using a local_id');
return;
}
var state = exports.message_state(opts);
exports.messages[local_id] = state;
};
exports.message_state = function (opts) {
var self = {};
self.data = {};
self.data.start = new Date();
self.data.local_id = opts.local_id;
self.data.locally_echoed = opts.locally_echoed;
self.data.received = undefined;
self.data.send_finished = undefined;
self.data.rendered_content_disparity = false;
self.start_resend = function () {
self.data.start = new Date();
self.data.received = undefined;
self.data.send_finished = undefined;
self.data.rendered_content_disparity = false;
};
self.maybe_restart_event_loop = function () {
if (self.data.received) {
// We got our event, no need to do anything
return;
}
blueslip.log("Restarting get_events due to " +
"delayed receipt of sent message " +
self.data.local_id);
server_events.restart_get_events();
};
self.maybe_report_send_times = function () {
if (!self.ready()) {
return;
}
var data = self.data;
report_send_time(data.send_finished - data.start,
data.received - data.start,
data.locally_echoed,
data.rendered_content_disparity);
};
self.report_event_received = function () {
self.data.received = new Date();
self.maybe_report_send_times();
};
self.mark_disparity = function () {
self.data.rendered_content_disparity = true;
};
self.report_server_ack = function () {
self.data.send_finished = new Date();
self.maybe_report_send_times();
// We only start our timer for events coming in here,
// since it's plausible the server rejected our message,
// or took a while to process it, but there is nothing
// wrong with our event loop.
if (!self.data.received) {
setTimeout(self.maybe_restart_event_loop, 5000);
}
};
self.ready = function () {
return (self.data.send_finished !== undefined) &&
(self.data.received !== undefined);
};
return self;
};
exports.get_message_state = function (local_id) {
var state = exports.messages[local_id];
if (!state) {
blueslip.warn('Unknown local_id: ' + local_id);
}
return state;
};
exports.mark_disparity = function (local_id) {
var state = exports.get_message_state(local_id);
if (!state) {
return;
}
state.mark_disparity();
};
exports.report_event_received = function (local_id) {
var state = exports.get_message_state(local_id);
if (!state) {
return;
}
state.report_event_received();
};
exports.start_resend = function (local_id) {
var state = exports.get_message_state(local_id);
if (!state) {
return;
}
state.start_resend();
};
exports.report_server_ack = function (local_id) {
var state = exports.get_message_state(local_id);
if (!state) {
return;
}
state.report_server_ack();
};
exports.initialize = function () {
exports.reset_id_state();
};
return exports;
}());
if (typeof module !== 'undefined') {
module.exports = sent_messages;
}

3
static/js/server_events.js
View File

@ -68,8 +68,9 @@ function get_events_success(events) {
case 'message':
var msg = event.message;
msg.flags = event.flags;
if (event.local_message_id !== undefined) {
if (event.local_message_id) {
msg.local_id = event.local_message_id;
sent_messages.report_event_received(event.local_message_id);
}
messages.push(msg);
break;

1
static/js/ui_init.js
View File

@ -267,6 +267,7 @@ $(function () {
pm_list.initialize();
stream_list.initialize();
drafts.initialize();
sent_messages.initialize();
compose.initialize();
});

1
zproject/settings.py
View File

@ -873,6 +873,7 @@ JS_SPECS = {
'js/markdown.js',
'js/echo.js',
'js/socket.js',
'js/sent_messages.js',
'js/compose_state.js',
'js/compose_actions.js',
'js/compose.js',