Refactored web startup to minimise risks of race conditions

Under specific circumstances it could happen that the passive login
response was overtaken by a response from an earlier still
unauthenticated request which would then effectively overwrite the
session cookie immediately and hence cause the browser to use its
login session against the server, but without displaying that to the
user. See #1881 for what is probably an issue caused by exactly this
kind of scenario.

Additionally a couple of requests needed to be done a second time
after login, just moments after having done them for an anonymous
user. See #1572 for a request to change this behaviour.

This patch changes the startup order of the web interface like this:

  1. connect to the websocket, postpone any events triggered by
     this (e.g. "fromHistoryData") until 3
  2. perform a passive login, postpone any events triggered by this
     (e.g. "onUserLoggedIn", "onUserLoggedOut") until 4
  3. trigger postponed events from 1
  4. trigger "onStartup" (triggers postponed events from 2)
  5. fetch settings
  6. bind view models etc

A connection close of the websocket will disable event processing on the
socket until it is marked as initialized again by the passive login
processing, which will also be triggered immediately on server connect.

That way under normal circumstances nothing should ever get triggered
in the registered view models that might generated requests to the
server API until a passive login has been done, a server session
initialized and if necessary a user properly authenticated.
This commit is contained in:
Gina Häußge 2017-06-29 15:42:19 +02:00
parent 7ab4d12548
commit b205e84d4b
7 changed files with 244 additions and 145 deletions

View file

@ -106,6 +106,7 @@
var onOpen = function() {
self.reconnecting = false;
self.reconnectTrial = 0;
self.onConnected();
};
var onClose = function(e) {
@ -117,6 +118,8 @@
return;
}
self.onDisconnected(e.code);
if (self.reconnectTrial < self.options.timeouts.length) {
var timeout = self.options.timeouts[self.reconnectTrial];
setTimeout(function() { self.reconnect() }, timeout * 1000);
@ -160,6 +163,8 @@
OctoPrintSocketClient.prototype.onReconnectAttempt = function(trial) {};
OctoPrintSocketClient.prototype.onReconnectFailed = function() {};
OctoPrintSocketClient.prototype.onConnected = function() {};
OctoPrintSocketClient.prototype.onDisconnected = function(code) {};
OctoPrintSocketClient.prototype.onRateTooLow = function(measured, minimum) {
this.increaseRate();

View file

@ -1,13 +1,17 @@
function DataUpdater(allViewModels) {
function DataUpdater(allViewModels, connectCallback, disconnectCallback) {
var self = this;
self.allViewModels = allViewModels;
self.connectCallback = connectCallback;
self.disconnectCallback = disconnectCallback;
self._pluginHash = undefined;
self._configHash = undefined;
self._connectedDeferred = undefined;
self._initializedDeferred = undefined;
self._throttleFactor = 1;
self._baseProcessingLimit = 500.0;
self._lastProcessingTimes = [];
@ -57,6 +61,13 @@ function DataUpdater(allViewModels) {
return self._connectedDeferred.promise();
};
self.initialized = function() {
if (self._initializedDeferred) {
self._initializedDeferred.resolve();
self._initializedDeferred = undefined;
}
};
self._onReconnectAttempt = function(trial) {
if (trial <= 0) {
// Only consider it a real disconnect if the trial number has exceeded our threshold.
@ -99,7 +110,27 @@ function DataUpdater(allViewModels) {
$("#offline_overlay_message").html(gettext("The server appears to be offline, at least I'm not getting any response from it. I <strong>could not reconnect automatically</strong>, but you may try a manual reconnect using the button below."));
};
self._onConnected = function(event) {
self._onDisconnected = function(code) {
if (self._initializedDeferred) {
self._initializedDeferred.reject();
}
self._initializedDeferred = undefined;
if (self.disconnectCallback) {
self.disconnectCallback();
}
};
self._onConnectMessage = function(event) {
if (self._initializedDeferred) {
self._initializedDeferred.reject();
}
self._initializedDeferred = $.Deferred();
if (self.connectCallback) {
self.connectCallback();
}
var data = event.data;
// update version information
@ -117,37 +148,40 @@ function DataUpdater(allViewModels) {
var oldConfigHash = self._configHash;
self._configHash = data["config_hash"];
// process safe mode
if (self._safeModePopup) self._safeModePopup.remove();
if (data["safe_mode"]) {
// safe mode is active, let's inform the user
log.info("Safe mode is active. Third party plugins are disabled and cannot be enabled.");
self._ifInitialized(function() {
// process safe mode
if (self._safeModePopup) self._safeModePopup.remove();
if (data["safe_mode"]) {
// safe mode is active, let's inform the user
log.info("Safe mode is active. Third party plugins are disabled and cannot be enabled.");
self._safeModePopup = new PNotify({
title: gettext("Safe mode is active"),
text: gettext("The server is currently running in safe mode. Third party plugins are disabled and cannot be enabled."),
hide: false
});
}
self._safeModePopup = new PNotify({
title: gettext("Safe mode is active"),
text: gettext("The server is currently running in safe mode. Third party plugins are disabled and cannot be enabled."),
hide: false
});
}
// if the offline overlay is still showing, now's a good time to
// hide it, plus reload the camera feed if it's currently displayed
if ($("#offline_overlay").is(":visible")) {
hideOfflineOverlay();
callViewModels(self.allViewModels, "onServerReconnect");
callViewModels(self.allViewModels, "onDataUpdaterReconnect");
} else {
callViewModels(self.allViewModels, "onServerConnect");
}
// if the offline overlay is still showing, now's a good time to
// hide it, plus reload the camera feed if it's currently displayed
if ($("#offline_overlay").is(":visible")) {
hideOfflineOverlay();
callViewModels(self.allViewModels, "onServerReconnect");
callViewModels(self.allViewModels, "onDataUpdaterReconnect");
} else {
callViewModels(self.allViewModels, "onServerConnect");
}
// if the version, the plugin hash or the config hash changed, we
// want the user to reload the UI since it might be stale now
var versionChanged = oldVersion != VERSION;
var pluginsChanged = oldPluginHash != undefined && oldPluginHash != self._pluginHash;
var configChanged = oldConfigHash != undefined && oldConfigHash != self._configHash;
if (versionChanged || pluginsChanged || configChanged) {
showReloadOverlay();
}
// if the version, the plugin hash or the config hash changed, we
// want the user to reload the UI since it might be stale now
var versionChanged = oldVersion !== VERSION;
var pluginsChanged = oldPluginHash !== undefined && oldPluginHash !== self._pluginHash;
var configChanged = oldConfigHash !== undefined && oldConfigHash !== self._configHash;
if (versionChanged || pluginsChanged || configChanged) {
showReloadOverlay();
}
});
log.info("Connected to the server");
@ -159,81 +193,89 @@ function DataUpdater(allViewModels) {
};
self._onHistoryData = function(event) {
callViewModels(self.allViewModels, "fromHistoryData", [event.data]);
};
self._onCurrentData = function(event) {
callViewModels(self.allViewModels, "fromCurrentData", [event.data]);
};
self._onSlicingProgress = function(event) {
$("#gcode_upload_progress").find(".bar").text(_.sprintf(gettext("Slicing ... (%(percentage)d%%)"), {percentage: Math.round(event.data["progress"])}));
var data = event.data;
callViewModels(self.allViewModels, "onSlicingProgress", [
data["slicer"],
data["model_path"],
data["machinecode_path"],
data["progress"]
]);
};
self._onEvent = function(event) {
var gcodeUploadProgress = $("#gcode_upload_progress");
var gcodeUploadProgressBar = $(".bar", gcodeUploadProgress);
var type = event.data["type"];
var payload = event.data["payload"];
var html = "";
log.debug("Got event " + type + " with payload: " + JSON.stringify(payload));
if (type == "PrintCancelled") {
if (payload.firmwareError) {
new PNotify({
title: gettext("Unhandled communication error"),
text: _.sprintf(gettext("There was an unhandled error while talking to the printer. Due to that the ongoing print job was cancelled. Error: %(firmwareError)s"), payload),
type: "error",
hide: false
});
}
} else if (type == "Error") {
if (payload.error && payload.error.indexOf("autodetect") == -1) { // ignore "failed to autodetect"
new PNotify({
title: gettext("Unhandled communication error"),
text: _.sprintf(gettext("The was an unhandled error while talking to the printer. Due to that OctoPrint disconnected. Error: %(error)s"), payload),
type: "error",
hide: false
});
}
}
var legacyEventHandlers = {
"UpdatedFiles": "onUpdatedFiles",
"MetadataStatisticsUpdated": "onMetadataStatisticsUpdated",
"MetadataAnalysisFinished": "onMetadataAnalysisFinished",
"SlicingDone": "onSlicingDone",
"SlicingCancelled": "onSlicingCancelled",
"SlicingFailed": "onSlicingFailed"
};
_.each(self.allViewModels, function(viewModel) {
if (viewModel.hasOwnProperty("onEvent" + type)) {
viewModel["onEvent" + type](payload);
} else if (legacyEventHandlers.hasOwnProperty(type) && viewModel.hasOwnProperty(legacyEventHandlers[type])) {
// there might still be code that uses the old callbacks, make sure those still get called
// but log a warning
log.warn("View model " + viewModel.name + " is using legacy event handler " + legacyEventHandlers[type] + ", new handler is called " + legacyEventHandlers[type]);
viewModel[legacyEventHandlers[type]](payload);
}
self._ifInitialized(function() {
callViewModels(self.allViewModels, "fromHistoryData", [event.data]);
});
};
self._onCurrentData = function(event) {
self._ifInitialized(function() {
callViewModels(self.allViewModels, "fromCurrentData", [event.data]);
});
};
self._onSlicingProgress = function(event) {
self._ifInitialized(function() {
$("#gcode_upload_progress").find(".bar").text(_.sprintf(gettext("Slicing ... (%(percentage)d%%)"), {percentage: Math.round(event.data["progress"])}));
var data = event.data;
callViewModels(self.allViewModels, "onSlicingProgress", [
data["slicer"],
data["model_path"],
data["machinecode_path"],
data["progress"]
]);
});
};
self._onEvent = function(event) {
self._ifInitialized(function() {
var type = event.data["type"];
var payload = event.data["payload"];
log.debug("Got event " + type + " with payload: " + JSON.stringify(payload));
if (type == "PrintCancelled") {
if (payload.firmwareError) {
new PNotify({
title: gettext("Unhandled communication error"),
text: _.sprintf(gettext("There was an unhandled error while talking to the printer. Due to that the ongoing print job was cancelled. Error: %(firmwareError)s"), payload),
type: "error",
hide: false
});
}
} else if (type == "Error") {
if (payload.error && payload.error.indexOf("autodetect") == -1) { // ignore "failed to autodetect"
new PNotify({
title: gettext("Unhandled communication error"),
text: _.sprintf(gettext("The was an unhandled error while talking to the printer. Due to that OctoPrint disconnected. Error: %(error)s"), payload),
type: "error",
hide: false
});
}
}
var legacyEventHandlers = {
"UpdatedFiles": "onUpdatedFiles",
"MetadataStatisticsUpdated": "onMetadataStatisticsUpdated",
"MetadataAnalysisFinished": "onMetadataAnalysisFinished",
"SlicingDone": "onSlicingDone",
"SlicingCancelled": "onSlicingCancelled",
"SlicingFailed": "onSlicingFailed"
};
_.each(self.allViewModels, function(viewModel) {
if (viewModel.hasOwnProperty("onEvent" + type)) {
viewModel["onEvent" + type](payload);
} else if (legacyEventHandlers.hasOwnProperty(type) && viewModel.hasOwnProperty(legacyEventHandlers[type])) {
// there might still be code that uses the old callbacks, make sure those still get called
// but log a warning
log.warn("View model " + viewModel.name + " is using legacy event handler " + legacyEventHandlers[type] + ", new handler is called " + legacyEventHandlers[type]);
viewModel[legacyEventHandlers[type]](payload);
}
});
})
};
self._onTimelapse = function(event) {
callViewModels(self.allViewModels, "fromTimelapseData", [event.data]);
self._ifInitialized(function() {
callViewModels(self.allViewModels, "fromTimelapseData", [event.data]);
})
};
self._onPluginMessage = function(event) {
callViewModels(self.allViewModels, "onDataUpdaterPluginMessage", [event.data.plugin, event.data.data]);
self._ifInitialized(function() {
callViewModels(self.allViewModels, "onDataUpdaterPluginMessage", [event.data.plugin, event.data.data]);
})
};
self._onIncreaseRate = function(measurement, minimum) {
@ -246,12 +288,21 @@ function DataUpdater(allViewModels) {
OctoPrint.socket.decreaseRate();
};
self._ifInitialized = function(callback) {
if (self._initializedDeferred) {
self._initializedDeferred.done(callback);
} else {
callback();
}
};
OctoPrint.socket.onDisconnected = self._onDisconnected;
OctoPrint.socket.onReconnectAttempt = self._onReconnectAttempt;
OctoPrint.socket.onReconnectFailed = self._onReconnectFailed;
OctoPrint.socket.onRateTooHigh = self._onDecreaseRate;
OctoPrint.socket.onRateTooLow = self._onIncreaseRate;
OctoPrint.socket
.onMessage("connected", self._onConnected)
.onMessage("connected", self._onConnectMessage)
.onMessage("history", self._onHistoryData)
.onMessage("current", self._onCurrentData)
.onMessage("slicingProgress", self._onSlicingProgress)

View file

@ -552,7 +552,15 @@ $(function() {
// reload overlay
$("#reloadui_overlay_reload").click(function() { location.reload(); });
//~~ view model binding
//~~ final initialization - passive login, settings fetch, view model binding
if (!_.has(viewModelMap, "settingsViewModel")) {
throw new Error("settingsViewModel is missing, can't run UI");
}
if (!_.has(viewModelMap, "loginStateViewModel")) {
throw new Error("loginStateViewModel is missing, can't run UI");
}
var bindViewModels = function() {
log.info("Going to bind " + allViewModelData.length + " view models...");
@ -643,34 +651,55 @@ $(function() {
log.info("Application startup complete");
};
if (!_.has(viewModelMap, "settingsViewModel")) {
throw new Error("settingsViewModel is missing, can't run UI")
}
var fetchSettings = function() {
log.info("Finalizing application startup");
//~~ Starting up the app
callViewModels(allViewModels, "onStartup");
viewModelMap["settingsViewModel"].requestData()
.done(function() {
// There appears to be an odd race condition either in JQuery's AJAX implementation or
// the browser's implementation of XHR, causing a second GET request from inside the
// completion handler of the very same request to never get its completion handler called
// if ETag headers are present on the response (the status code of the request does NOT
// seem to matter here, only that the ETag header is present).
//
// Minimal example with which I was able to reproduce this behaviour can be found
// at https://gist.github.com/foosel/b2ddb9ebd71b0b63a749444651bfce3f
//
// Decoupling all consecutive calls from this done event handler hence is an easy way
// to avoid this problem. A zero timeout should do the trick nicely.
window.setTimeout(bindViewModels, 0);
});
};
log.info("Initial application setup done, connecting to server...");
var dataUpdater = new DataUpdater(allViewModels);
var onServerConnect = function() {
// Always perform a passive login on server (re)connect. No need for
// onServerConnect/onServerReconnect with this in place.
viewModelMap["loginStateViewModel"].requestData()
.done(function() {
// Only mark our data updater as initialized once we've done our initial
// passive login request.
//
// This is to ensure that we have no concurrent requests overriding each other's
// session during app intialization, and has the additional benefit of reducing the
// number of required requests since we don't have re-request data that might have
// changed if we turn out to be logged in.
dataUpdater.initialized();
});
};
var dataUpdater = new DataUpdater(allViewModels, onServerConnect);
dataUpdater.connect()
.done(function() {
log.info("Finalizing application startup");
//~~ Starting up the app
callViewModels(allViewModels, "onStartup");
viewModelMap["settingsViewModel"].requestData()
.done(function() {
// There appears to be an odd race condition either in JQuery's AJAX implementation or
// the browser's implementation of XHR, causing a second GET request from inside the
// completion handler of the very same request to never get its completion handler called
// if ETag headers are present on the response (the status code of the request does NOT
// seem to matter here, only that the ETag header is present).
//
// Minimal example with which I was able to reproduce this behaviour can be found
// at https://gist.github.com/foosel/b2ddb9ebd71b0b63a749444651bfce3f
//
// Decoupling all consecutive calls from this done event handler hence is an easy way
// to avoid this problem. A zero timeout should do the trick nicely.
window.setTimeout(bindViewModels, 0);
});
// onServerConnect will have been called just before this.
//
// Decoupled settings fetch, for the reasons see above's lengthy description
// on a weird JQuery AJAX issue with ETag headers and promise handling.
window.setTimeout(fetchSettings, 0);
});
}
);

View file

@ -257,7 +257,7 @@ $(function() {
self._configureLayerSlider(layerSliderElement);
self._configureLayerCommandSlider(commandSliderElement);
self.settings.requestData()
self.settings.firstRequest
.done(function() {
var initResult = GCODE.ui.init({
container: "#gcode_canvas",

View file

@ -12,6 +12,7 @@ $(function() {
self.isUser = ko.observable(false);
self.allViewModels = undefined;
self.startupDeferred = $.Deferred();
self.currentUser = ko.observable(undefined);
@ -36,28 +37,40 @@ $(function() {
});
self.reloadUser = function() {
if (self.currentUser() == undefined) {
if (self.currentUser() === undefined) {
return;
}
OctoPrint.users.get(self.currentUser().name)
return OctoPrint.users.get(self.currentUser().name)
.done(self.updateCurrentUserData);
};
self.requestData = function() {
OctoPrint.browser.passiveLogin()
return OctoPrint.browser.passiveLogin()
.done(self.fromResponse);
};
self.fromResponse = function(response) {
if (response && response.name) {
self.loggedIn(true);
self.updateCurrentUserData(response);
callViewModels(self.allViewModels, "onUserLoggedIn", [response]);
var process = function() {
if (response && response.name) {
self.loggedIn(true);
self.updateCurrentUserData(response);
callViewModels(self.allViewModels, "onUserLoggedIn", [response]);
log.info("User " + response.name + " logged in")
} else {
self.loggedIn(false);
self.resetCurrentUserData();
callViewModels(self.allViewModels, "onUserLoggedOut");
log.info("User logged out");
}
};
if (self.startupDeferred !== undefined) {
// Make sure we only fire our "onUserLogged(In|Out)" message when the application
// has started up.
self.startupDeferred.done(process);
} else {
self.loggedIn(false);
self.resetCurrentUserData();
callViewModels(self.allViewModels, "onUserLoggedOut");
process();
}
};
@ -101,7 +114,7 @@ $(function() {
};
self.logout = function() {
OctoPrint.browser.logout()
return OctoPrint.browser.logout()
.done(function(response) {
new PNotify({title: gettext("Logout successful"), text: gettext("You are now logged out"), type: "success"});
self.fromResponse(response);
@ -124,12 +137,10 @@ $(function() {
self.allViewModels = allViewModels;
};
self.onStartupComplete = self.onServerConnect = self.onServerReconnect = function() {
if (self.allViewModels == undefined) return;
self.requestData();
};
self.onStartup = function() {
self.startupDeferred.resolve();
self.startupDeferred = undefined;
self.elementUsernameInput = $("#login_user");
self.elementPasswordInput = $("#login_pass");
self.elementLoginButton = $("#login_button");

View file

@ -7,6 +7,11 @@ $(function() {
self.printerProfiles = parameters[2];
self.about = parameters[3];
// use this promise to do certain things once the SettingsViewModel has processed
// its first request
var firstRequest = $.Deferred();
self.firstRequest = firstRequest.promise();
self.allViewModels = [];
self.receiving = ko.observable(false);
@ -763,6 +768,8 @@ $(function() {
};
mapToObservables(serverChangedData, specialMappings, clientChangedData);
firstRequest.resolve();
};
self.saveData = function (data, successCallback, setAsSending) {

View file

@ -51,10 +51,6 @@ $(function() {
return self.isDirty() && !self.isPrinting() && self.loginState.isUser();
});
self.isOperational.subscribe(function() {
self.requestData();
});
self.timelapseType.subscribe(function() {
self.isDirty(true);
});