Added adaptive rate limiting to client

The client now tries to detect if it's fast enough to process the
state updates usually send every 500ms, and if not notifies the
server to throttle the rate (e.g. to 1/1s, 1/1.5s etc).

Additionally, since the terminal tab of the client turned out to
be quite CPU intense when line number calculation, filtering etc
is enabled, the terminal tab now also falls back into a bit less
fancy mode if it detects its being processed too slow and optionally
even disables logging completely during printing (where a lot
of log messages need to be processed in a minimum amount of
time).

That way the UI should stay responsive even on very low powered
clients (e.g. chromium on a Pi), while printing.
This commit is contained in:
Gina Häußge 2016-01-27 12:04:17 +01:00
parent bcd7bb4d20
commit 36ae6dd6b9
8 changed files with 232 additions and 30 deletions

View file

@ -12,7 +12,7 @@ Push updates
.. contents::
To enable real time information exchange between client and server, OctoPrint uses
To enable real time information exchange between client and server, OctoPrint uses
`SockJS <https://github.com/sockjs/sockjs-protocol>`_ to push
status updates, temperature changes etc to connected web interface instances.
@ -43,6 +43,24 @@ Clients must ignore any unknown messages.
The data model of the attached payloads is described further below.
OctoPrint's SockJS socket also accepts one command from the client to the server,
the ``throttle`` command. Usually, OctoPrint will push the general state update
in the ``current`` message twice per second. For some clients that might still
be too fast, so they can signal a different factor to OctoPrint utilizing the
``throttle`` message. OctoPrint expects a single integer here which represents
the multiplier for the base rate limit of one message every 500ms. A value of
1 hence will produce the default behaviour of getting every update. A value of
2 will set the rate limit to maximally one message every 1s, 3 to maximally one
message every 1.5s and so on.
Example for a ``throttle`` client-server-message:
.. sourcecode:: javascript
{
"throttle": 2
}
.. _sec-api-push-datamodel:
Datamodel

View file

@ -39,6 +39,10 @@ class PrinterStateConnection(sockjs.tornado.SockJSConnection, octoprint.printer.
self._remoteAddress = None
self._throttleFactor = 1
self._lastCurrent = 0
self._baseRateLimit = 0.5
def _getRemoteAddress(self, info):
forwardedFor = info.headers.get("X-Forwarded-For")
if forwardedFor is not None:
@ -90,9 +94,31 @@ class PrinterStateConnection(sockjs.tornado.SockJSConnection, octoprint.printer.
self._eventManager.unsubscribe(event, self._onEvent)
def on_message(self, message):
pass
try:
import json
message = json.loads(message)
except:
self._logger.warn("Invalid JSON received from client {}, ignoring: {!r}".format(self._remoteAddress, message))
return
if "throttle" in message:
try:
throttle = int(message["throttle"])
if throttle < 1:
raise ValueError()
except ValueError:
self._logger.warn("Got invalid throttle factor from client {}, ignoring: {!r}".format(self._remoteAddress, message["throttle"]))
else:
self._throttleFactor = throttle
self._logger.debug("Set throttle factor for client {} to {}".format(self._remoteAddress, self._throttleFactor))
def on_printer_send_current_data(self, data):
# make sure we rate limit the updates according to our throttle factor
now = time.time()
if now < self._lastCurrent + self._baseRateLimit * self._throttleFactor:
return
self._lastCurrent = now
# add current temperature, log and message backlogs to sent data
with self._temperatureBacklogMutex:
temperatures = self._temperatureBacklog

File diff suppressed because one or more lines are too long

View file

@ -11,6 +11,11 @@ function DataUpdater(allViewModels) {
self._pluginHash = undefined;
self._throttleFactor = 1;
self._baseProcessingLimit = 500.0;
self._lastProcessingTimes = [];
self._lastProcessingTimesSize = 20;
self.connect = function() {
var options = {};
if (SOCKJS_DEBUG) {
@ -29,6 +34,30 @@ function DataUpdater(allViewModels) {
self.connect();
};
self.increaseThrottle = function() {
self.setThrottle(self._throttleFactor + 1);
};
self.decreaseThrottle = function() {
if (self._throttleFactor <= 1) {
return;
}
self.setThrottle(self._throttleFactor - 1);
};
self.setThrottle = function(throttle) {
self._throttleFactor = throttle;
self._send("throttle", self._throttleFactor);
log.debug("DataUpdater: New SockJS throttle factor:", self._throttleFactor, " new processing limit:", self._baseProcessingLimit * self._throttleFactor);
};
self._send = function(message, data) {
var payload = {};
payload[message] = data;
self._socket.send(JSON.stringify(payload));
};
self._onconnect = function() {
self._autoReconnecting = false;
self._autoReconnectTrial = 0;
@ -110,6 +139,7 @@ function DataUpdater(allViewModels) {
var gcodeUploadProgress = $("#gcode_upload_progress");
var gcodeUploadProgressBar = $(".bar", gcodeUploadProgress);
var start = new Date().getTime();
switch (prop) {
case "connected": {
// update the current UI API key and send it with any request
@ -152,6 +182,8 @@ function DataUpdater(allViewModels) {
showReloadOverlay();
}
self.setThrottle(1);
break;
}
case "history": {
@ -296,6 +328,27 @@ function DataUpdater(allViewModels) {
})
}
}
var end = new Date().getTime();
var difference = end - start;
while (self._lastProcessingTimes.length >= self._lastProcessingTimesSize) {
self._lastProcessingTimes.shift();
}
self._lastProcessingTimes.push(difference);
var processingLimit = self._throttleFactor * self._baseProcessingLimit;
if (difference > processingLimit) {
self.increaseThrottle();
log.debug("We are slow (" + difference + " > " + processingLimit + "), reducing refresh rate");
} else if (self._throttleFactor > 1) {
var maxProcessingTime = Math.max.apply(null, self._lastProcessingTimes);
var lowerProcessingLimit = (self._throttleFactor - 1) * self._baseProcessingLimit;
if (maxProcessingTime < lowerProcessingLimit) {
self.decreaseThrottle();
log.debug("We are fast (" + maxProcessingTime + " < " + lowerProcessingLimit + "), increasing refresh rate");
}
}
}
};

View file

@ -363,6 +363,30 @@ $(function() {
}
};
// Originally from Knockstrap
// https://github.com/faulknercs/Knockstrap/blob/master/src/bindings/toggleBinding.js
// License: MIT
ko.bindingHandlers.toggle = {
init: function (element, valueAccessor) {
var value = valueAccessor();
if (!ko.isObservable(value)) {
throw new Error('toggle binding should be used only with observable values');
}
$(element).on('click', function (event) {
event.preventDefault();
var previousValue = ko.utils.unwrapObservable(value);
value(!previousValue);
});
},
update: function (element, valueAccessor) {
ko.utils.toggleDomNodeCssClass(element, 'active', ko.utils.unwrapObservable(valueAccessor()));
}
};
//~~ some additional hooks and initializations
// make sure modals max out at the window height

View file

@ -5,9 +5,18 @@ $(function() {
self.loginState = parameters[0];
self.settings = parameters[1];
// TODO remove with release of 1.3.0 and switch to OctoPrint.coreui usage
self.tabTracking = parameters[2];
self.tabActive = false;
self.log = ko.observableArray([]);
self.log.extend({ throttle: 500 });
self.plainLogLines = ko.observableArray([]);
self.plainLogLines.extend({ throttle: 500 });
self.buffer = ko.observable(300);
self.upperLimit = ko.observable(3000);
self.upperLimit = ko.observable(1499);
self.command = ko.observable(undefined);
@ -27,7 +36,26 @@ $(function() {
self.cmdHistory = [];
self.cmdHistoryIdx = -1;
self.enableFancyFunctionality = ko.observable(true);
self.disableTerminalLogDuringPrinting = ko.observable(false);
self.acceptableTime = 500;
self.acceptableUnfancyTime = 300;
self.forceFancyFunctionality = ko.observable(false);
self.forceTerminalLogDuringPrinting = ko.observable(false);
self.fancyFunctionality = ko.computed(function() {
return self.enableFancyFunctionality() || self.forceFancyFunctionality();
});
self.terminalLogDuringPrinting = ko.computed(function() {
return !self.disableTerminalLogDuringPrinting() || self.forceTerminalLogDuringPrinting();
});
self.displayedLines = ko.computed(function() {
if (!self.enableFancyFunctionality()) {
return self.log();
}
var regex = self.filterRegex();
var lineVisible = function(entry) {
return regex == undefined || !entry.line.match(regex);
@ -49,7 +77,18 @@ $(function() {
return result;
});
self.plainLogOutput = ko.computed(function() {
if (self.fancyFunctionality()) {
return;
}
return self.plainLogLines().join("\n");
});
self.lineCount = ko.computed(function() {
if (!self.fancyFunctionality()) {
return;
}
var regex = self.filterRegex();
var lineVisible = function(entry) {
return regex == undefined || !entry.line.match(regex);
@ -88,7 +127,23 @@ $(function() {
self.fromCurrentData = function(data) {
self._processStateData(data.state);
var start = new Date().getTime();
self._processCurrentLogData(data.logs);
var end = new Date().getTime();
var difference = end - start;
if (self.enableFancyFunctionality()) {
if (difference > self.acceptableTime) {
self.enableFancyFunctionality(false);
log.warn("Terminal: Detected slow client (needed " + difference + "ms for processing new log data), disabling fancy terminal functionality");
}
} else {
if (!self.disableTerminalLogDuringPrinting() && difference > self.acceptableUnfancyTime) {
self.disableTerminalLogDuringPrinting(true);
log.warn("Terminal: Detected very slow client (needed " + difference + "ms for processing new log data), completely disabling terminal output during printing");
}
}
};
self.fromHistoryData = function(data) {
@ -99,27 +154,48 @@ $(function() {
self._processCurrentLogData = function(data) {
var length = self.log().length;
if (length >= self.upperLimit()) {
var cutoff = "--- too many lines to buffer, cut off ---";
var last = self.log()[length-1];
if (!last || last.type != "cut" || last.line != cutoff) {
self.log(self.log().concat(self._toInternalFormat(cutoff, "cut")));
return;
}
if (!self.terminalLogDuringPrinting() && self.isPrinting()) {
var last = self.plainLogLines()[self.plainLogLines().length - 1];
var disabled = "--- client too slow, log output disabled while printing ---";
if (last != disabled) {
self.plainLogLines.push(disabled);
}
return;
}
var newLog = self.log().concat(_.map(data, function(line) { return self._toInternalFormat(line) }));
var newData = (data.length + length > self.upperLimit())
? data.slice(0, self.upperLimit() - length)
: data;
if (!newData) {
return;
}
if (!self.fancyFunctionality()) {
// lite version of the terminal - text output only
self.plainLogLines(self.plainLogLines().concat(newData).slice(-self.buffer()));
self.updateOutput();
return;
}
var newLog = self.log().concat(_.map(newData, function(line) { return self._toInternalFormat(line) }));
if (newData.length != data.length) {
var cutoff = "--- too many lines to buffer, cut off ---";
newLog.push(self._toInternalFormat(cutoff, "cut"));
}
if (self.autoscrollEnabled()) {
// we only keep the last <buffer> entries
newLog = newLog.slice(-self.buffer());
} else if (newLog.length > self.upperLimit()) {
// we only keep the first <upperLimit> entries
newLog = newLog.slice(0, self.upperLimit());
}
self.log(newLog);
self.updateOutput();
};
self._processHistoryLogData = function(data) {
self.plainLogLines(data);
self.log(_.map(data, function(line) { return self._toInternalFormat(line) }));
self.updateOutput();
};
@ -152,7 +228,7 @@ $(function() {
};
self.updateOutput = function() {
if (self.autoscrollEnabled()) {
if (self.tabActive && self.tabTracking.browserTabVisible && self.autoscrollEnabled()) {
self.scrollToEnd();
}
};
@ -162,14 +238,14 @@ $(function() {
};
self.selectAll = function() {
var container = $("#terminal-output");
var container = self.fancyFunctionality() ? $("#terminal-output") : $("#terminal-output-lowfi");
if (container.length) {
container.selectText();
}
};
self.scrollToEnd = function() {
var container = $("#terminal-output");
var container = self.fancyFunctionality() ? $("#terminal-output") : $("#terminal-output-lowfi");
if (container.length) {
container.scrollTop(container[0].scrollHeight);
}
@ -247,19 +323,15 @@ $(function() {
};
self.onAfterTabChange = function(current, previous) {
if (current != "#term") {
return;
}
if (self.autoscrollEnabled()) {
self.scrollToEnd();
}
self.tabActive = current == "#term";
self.updateOutput();
};
}
OCTOPRINT_VIEWMODELS.push([
TerminalViewModel,
["loginStateViewModel", "settingsViewModel"],
["loginStateViewModel", "settingsViewModel", "tabTracking"],
"#term"
]);
});

View file

@ -679,7 +679,7 @@ ul.dropdown-menu li a {
#term {
.terminal {
#terminal-output {
#terminal-output, #terminal-output-lowfi {
min-height: 340px;
margin-bottom: 5px;
}

View file

@ -1,12 +1,14 @@
<div class="terminal">
<pre id="terminal-output" class="pre-scrollable" data-bind="foreach: displayedLines"><span data-bind="text: line, css: {muted: type == 'filtered' || type == 'cut'}"></span><br></pre>
<small class="pull-left"><button class="btn btn-mini" data-bind="click: toggleAutoscroll, css: {active: autoscrollEnabled}">{{ _('Autoscroll') }}</button> <span data-bind="text: lineCount"></span></small>
<small class="pull-right"><a href="#" data-bind="click: scrollToEnd">{{ _("Scroll to end") }}</a>&nbsp;|&nbsp;<a href="#" data-bind="click: selectAll">{{ _("Select all") }}</a></small>
<pre id="terminal-output" class="pre-scrollable" data-bind="foreach: displayedLines, visible: fancyFunctionality()"><span data-bind="text: line, css: {muted: type == 'filtered' || type == 'cut'}"></span><br></pre>
<pre id="terminal-output-lowfi" style="display: none" class="pre-scrollable" data-bind="text: plainLogOutput, visible: !fancyFunctionality()"></pre>
<small class="pull-left" data-bind="visible: fancyFunctionality()"><button class="btn btn-mini" data-bind="click: toggleAutoscroll, css: {active: autoscrollEnabled}">{{ _('Autoscroll') }}</button> <span data-bind="text: lineCount, visible: enableFancyFunctionality"></span></small>
<small class="pull-right" data-bind="visible: fancyFunctionality()"><a href="#" data-bind="click: scrollToEnd">{{ _("Scroll to end") }}</a>&nbsp;|&nbsp;<a href="#" data-bind="click: selectAll">{{ _("Select all") }}</a></small>
<small class="pull-left muted" data-bind="visible: !fancyFunctionality()" style="display: none">{{ _('For performance reasons only a limited amount of terminal functionality is enabled right now.') }}</small>
</div>
<div class="row-fluid">
<div class="span6" id="termin-filterpanel">
<div data-bind="foreach: filters">
<div class="span6" id="terminal-filterpanel">
<div data-bind="foreach: filters, visible: fancyFunctionality()">
<label class="checkbox">
<input type="checkbox" data-bind="attr: { value: regex }, checked: $parent.activeFilters"> <span data-bind="text: name"></span>
</label>
@ -24,8 +26,15 @@
<div>
<div><small><a href="#" class="muted" onclick="$(this).children().toggleClass('icon-caret-right icon-caret-down').parent().parent().parent().next().slideToggle('fast')"><i class="icon-caret-right"></i> {{ _('Advanced options') }}</a></small></div>
<div class="hide">
<button class="btn btn-block" type="button" data-bind="click: fakeAck, enable: isOperational() && loginState.isUser()">{{ _("Fake Acknowledgement") }}</button>
<small class="muted">{{ _("If acknowledgements (\"ok\"s) sent by the firmware get lost due to issues with the serial communication to your printer, OctoPrint's communication with it can become stuck. If that happens, this can help. Please be advised that such occurences hint at general communication issues with your printer which will probably negatively influence your printing results and which you should therefore try to resolve!") }}</small>
<p class="row-fluid">
<button class="btn btn-primary btn-block" type="button" data-bind="click: fakeAck, enable: isOperational() && loginState.isUser()">{{ _("Fake Acknowledgement") }}</button>
<small class="muted">{{ _("If acknowledgements (\"ok\"s) sent by the firmware get lost due to issues with the serial communication to your printer, OctoPrint's communication with it can become stuck. If that happens, this can help. Please be advised that such occurences hint at general communication issues with your printer which will probably negatively influence your printing results and which you should therefore try to resolve!") }}</small>
</p>
<p class="row-fluid">
<button class="btn btn-danger span6" type="button" data-bind="toggle: forceFancyFunctionality">{{ _('Force fancy functionality') }}</button>
<button class="btn btn-danger span6" type="button" data-bind="toggle: forceTerminalLogDuringPrinting">{{ _('Force terminal output during printing') }}</button>
<small class="muted">{{ _("Some functionality of the terminal will be disabled if OctoPrint detects that your browser is too slow for that. You may force it back on here, but be aware that this might make your browser unresponsive.") }}</small>
</p>
</div>
</div>