From 9fdad181e093d8d277ec701093ff36d25ccb695c Mon Sep 17 00:00:00 2001 From: Martin Boonk Date: Mon, 28 Feb 2022 20:14:19 +0100 Subject: [PATCH] Adds performance logging --- apps/imageclock/app.js | 109 ++++++++++++++++++++++++++++++++--------- 1 file changed, 87 insertions(+), 22 deletions(-) diff --git a/apps/imageclock/app.js b/apps/imageclock/app.js index fcb41d3b4..46c323ece 100644 --- a/apps/imageclock/app.js +++ b/apps/imageclock/app.js @@ -1,7 +1,46 @@ var face = require("Storage").readJSON("imageclock.face.json"); var resources = require("Storage").readJSON("imageclock.resources.json"); +var performanceLog = {}; + +var startPerfLog = ()=>{}; +var endPerfLog = ()=>{}; +var printPerfLog = ()=>print("Deactivated"); + +if (true){ + startPerfLog = function(name){ + var time = getTime(); + if (!performanceLog.start) performanceLog.start={}; + performanceLog.start[name] = time; + }; + endPerfLog = function (name){ + var time = getTime(); + if (!performanceLog.last) performanceLog.last={}; + var duration = time - performanceLog.start[name]; + performanceLog.last[name] = duration; + if (!performanceLog.cum) performanceLog.cum={}; + if (!performanceLog.cum[name]) performanceLog.cum[name] = 0; + performanceLog.cum[name] += duration; + if (!performanceLog.count) performanceLog.count={}; + if (!performanceLog.count[name]) performanceLog.count[name] = 0; + performanceLog.count[name]++; + }; + + printPerfLog = function(){ + var result = ""; + var keys = []; + for (var c in performanceLog.cum){ + keys.push(c); + } + keys.sort(); + for (var k of keys){ + print(k, "last:", (performanceLog.last[k] * 1000).toFixed(0), "average:", (performanceLog.cum[k]/performanceLog.count[k]*1000).toFixed(0), "total:", (performanceLog.cum[k] * 1000).toFixed(0)); + } + }; +} + function prepareImg(resource){ + startPerfLog("prepareImg"); //print("prepareImg: ", resource); var result = cacheBuffers ? resource : { @@ -19,7 +58,7 @@ function prepareImg(resource){ //print("buffer from file"); result.buffer = E.toArrayBuffer(atob(require("Storage").read(resource.file))); result.file = undefined; - } else if (resource.compressed && (resource.dataOffset == undefined)){ + } else if (resource.compressed && (resource.dataOffset === undefined)){ //print("buffer from compressed"); result.buffer = require("heatshrink").decompress(atob(resource.compressed)); result.compressed = undefined; @@ -44,10 +83,12 @@ function prepareImg(resource){ result.paletteData = undefined; } + endPerfLog("prepareImg"); return result; } function getByPath(object, path, lastElem){ + startPerfLog("getByPath"); //print("getByPath", path,lastElem); var current = object; if (path.length) { @@ -61,6 +102,7 @@ function getByPath(object, path, lastElem){ //print("Found by lastElem", lastElem); current = current["" + lastElem]; } + endPerfLog("getByPath"); if (typeof current == "function"){ //print("current was function"); return undefined; @@ -73,6 +115,7 @@ function splitNumberToDigits(num){ } function drawNumber(element, offset){ + startPerfLog("drawNumber"); var number = numbers[element.Value](); var spacing = element.Spacing ? element.Spacing : 0; var unit = element.Unit; @@ -85,13 +128,13 @@ function drawNumber(element, offset){ //print("drawNumber: ", number, element, offset); if (number) number = number.toFixed(0); - if (!element.Refresh || element.Refresh == "Always" || (element.Refresh == "Change" && element.lastDrawnValue && element.lastDrawnValue != number)){ + if (checkRedraw(element,number)){ //var numberOffset = updateOffset(element, offset); var numberOffset = offset; var isNegative; var digits; - if (number == undefined){ + if (typeof number !== "number"){ isNegative = true; digits = []; numberOfDigits = 0; @@ -185,6 +228,8 @@ function drawNumber(element, offset){ drawElement({X:currentX,Y:firstDigitY}, numberOffset, element.ImagePath, getMultistate(element.Unit,"unknown")); } element.lastDrawnValue = number; + + endPerfLog("drawNumber"); } } @@ -194,6 +239,7 @@ function setColors(properties){ } function drawElement(pos, offset, path, lastElem){ + startPerfLog("drawElement"); //print("drawElement ",pos, offset, path, lastElem); //print("drawElement offset", offset, pos.X, pos.Y); var resource = getByPath(resources, path, lastElem); @@ -215,13 +261,16 @@ function drawElement(pos, offset, path, lastElem){ } //print("options", options); //print("Memory before drawing", process.memory(false)); + startPerfLog("drawElement_g.drawImage"); g.drawImage(image ,(imageOffset.X ? imageOffset.X : 0) + (pos.X ? pos.X : 0),(imageOffset.Y ? imageOffset.Y :0) + (pos.Y ? pos.Y : 0), options); + endPerfLog("drawElement_g.drawImage"); } else { //print("Could not create image from", resource); } } else { //print("Could not get resource from", path, lastElem); } + endPerfLog("drawElement"); } function checkRedraw(element, newValue){ @@ -255,15 +304,12 @@ function getMultistate(name, defaultValue){ } function drawScale(scale, offset){ + startPerfLog("drawScale"); //print("drawScale", scale, offset); var segments = scale.Segments; - var value = numbers[scale.Value](); - var maxValue = getValue(scale.MaxValue, 1); - var minValue = getValue(scale.MinValue, 0); var imageIndex = scale.ImageIndex !== undefined ? scale.ImageIndex : 0; - value = value/maxValue; - value -= minValue; + var value = scaledown(scale.Value, scale.MinValue, scale.MaxValue); //print("Value is ", value, "(", maxValue, ",", minValue, ")"); @@ -277,6 +323,7 @@ function drawScale(scale, offset){ } scale.lastDrawnValue = segmentsToDraw; } + endPerfLog("drawScale"); } function drawDigit(element, offset, digit){ @@ -284,11 +331,12 @@ function drawDigit(element, offset, digit){ } function drawImage(image, offset, name){ + startPerfLog("drawImage"); var imageOffset = updateColors(image, offset); if (image.ImagePath) { //print("drawImage", image, offset, name); if (image.Value && image.Steps){ - var steps = Math.floor(scaledown(getValue(image.Value), getValue(image.MinValue, 0), getValue(image.MaxValue, 1)) * (image.Steps - 1)); + var steps = Math.floor(scaledown(image.Value, image.MinValue, image.MaxValue) * (image.Steps - 1)); //print("Step", steps, "of", image.Steps); drawElement(image, imageOffset, image.ImagePath, "" + steps); } else if (image.ImageIndex !== undefined) { @@ -301,9 +349,11 @@ function drawImage(image, offset, name){ setColors(imageOffset); g.drawImage(prepareImg(file),image.X + imageOffset.X, image.Y + imageOffset.Y); } + endPerfLog("drawImage"); } function drawCodedImage(image, offset){ + startPerfLog("drawCodedImage"); var code = getValue(image.Value); //print("drawCodedImage", image, offset, code); @@ -329,6 +379,7 @@ function drawCodedImage(image, offset){ } image.lastDrawnValue = code; } + startPerfLog("drawCodedImage"); } function getWeatherCode(){ @@ -361,11 +412,13 @@ function getWeatherTemperature(){ } function updateOffset(element, offset){ + startPerfLog("updateOffset"); var newOffset = { X: offset.X ? offset.X : 0, Y: offset.Y ? offset.Y : 0 }; if (element && element.X) newOffset.X += element.X; if (element && element.Y) newOffset.Y += element.Y; newOffset = updateColors(element, newOffset); //print("Updated offset from ", offset, "to", newOffset); + endPerfLog("updateOffset"); return newOffset; } @@ -388,6 +441,7 @@ function scaledown(value, min, max){ } function rotate(center, coords, rotation) { + startPerfLog("rotate"); var value = scaledown(rotation.RotationValue, rotation.MinRotationValue, rotation.MaxRotationValue); value -= rotation.RotationOffset ? rotation.RotationOffset : 0; value *= 360; @@ -400,15 +454,19 @@ function rotate(center, coords, rotation) { sin = Math.sin(radians), x = (cos * (coords.X - center.X)) + (sin * (coords.Y - center.Y)) + center.X, y = (cos * (coords.Y - center.Y)) - (sin * (coords.X - center.X)) + center.Y; + + endPerfLog("rotate"); return {X:x,Y:y}; } function drawPoly(element, offset){ + startPerfLog("drawPoly"); var vertices = []; var primitiveOffset = offset.clone(); if (element.X) primitiveOffset.X += element.X; if (element.Y) primitiveOffset.Y += element.Y; + startPerfLog("drawPoly_transform"); for (var c of element.Vertices){ if (element.RotationValue){ var rotated = rotate({X:0,Y:0}, c, element); @@ -419,15 +477,22 @@ function drawPoly(element, offset){ vertices.push(c.Y + primitiveOffset.Y); } } + endPerfLog("drawPoly_transform"); if (element.ForegroundColor) g.setColor(element.ForegroundColor); if (element.Filled){ + startPerfLog("drawPoly_g.fillPoly"); g.fillPoly(vertices,true); + endPerfLog("drawPoly_g.fillPoly"); } if (element.BackgroundColor) g.setColor(element.BackgroundColor); + startPerfLog("drawPoly_g.drawPoly"); g.drawPoly(vertices,true); + endPerfLog("drawPoly_g.drawPoly"); + + startPerfLog("drawPoly"); } var numbers = {}; @@ -482,6 +547,7 @@ multistates.WeatherTemperatureUnit = () => { return getWeatherTemperature().unit multistates.StepsGoal = () => { return (numbers.Steps() >= stepsgoal) ? "on": "off"; }; function drawMultiState(element, offset){ + startPerfLog("drawMultiState"); //print("drawMultiState", element, offset); var value = multistates[element.Value](); if (checkRedraw(element, value)){ @@ -489,9 +555,11 @@ function drawMultiState(element, offset){ drawImage(element, offset, value); element.lastDrawnValue = value; } + endPerfLog("drawMultiState"); } function draw(element, offset){ + startPerfLog("draw_"+ path.join("_")); var initial = !element; if (initial){ element = face; @@ -500,7 +568,6 @@ function draw(element, offset){ if (!offset.Y) offset.Y = 0; g.clear(); } - var elementOffset = updateOffset(element, offset); setColors(elementOffset); @@ -508,10 +575,8 @@ function draw(element, offset){ for (var current in element){ //print("Handling ", current, " with offset ", elementOffset); - //print("Handling ", current); + startPerfLog("draw_handling_"+ path.join("_")+"_"+current); var currentElement = element[current]; - - //var start = Date.now(); try { switch(current){ case "X": @@ -549,12 +614,15 @@ function draw(element, offset){ draw(currentElement, elementOffset); //print("Done next level"); } + endPerfLog("draw_handling_"+ path.join("_")+"_"+current); //print("Drawing of", current, "in", (Date.now() - start).toFixed(0), "ms"); } catch (e){ print("Error during drawing of", current, "in", element, e, e.stack); } } - //print("Finished drawing loop in", Date.now() - start); + //print("Finished drawing loop"); + + endPerfLog("draw_"+ path.join("_")); } var pulse,alt,temp,press; @@ -574,8 +642,9 @@ function initialDraw(){ isDrawing = true; requestedDraws = 0; //print(new Date().toISOString(), "Drawing start"); - var start = Date.now(); + startPerfLog("initialDraw"); draw(undefined, zeroOffset); + endPerfLog("initialDraw"); //print(new Date().toISOString(), "Drawing done", (Date.now() - start).toFixed(0)); isDrawing = false; if (requestedDraws > 0){ @@ -588,30 +657,28 @@ function initialDraw(){ function handleHrm(e){ if (e.confidence > 70){ - var change = pulse != e.bpm pulse = e.bpm; if (!redrawEvents || redrawEvents.includes("HRM") && !Bangle.isLocked()){ //print("Redrawing on HRM"); - changeFromEvent |= change; + initialDraw(); } } } function handlePressure(e){ - var change = (alt != e.altitude) || (temp != e.temperature) || (press != e.pressure); alt = e.altitude; temp = e.temperature; press = e.pressure; if (!redrawEvents || redrawEvents.includes("pressure") && !Bangle.isLocked()){ //print("Redrawing on pressure"); - changeFromEvent |= change; + initialDraw(); } } function handleCharging(e){ if (!redrawEvents || redrawEvents.includes("charging") && !Bangle.isLocked()){ //print("Redrawing on charging"); - changeFromEvent = true; + initialDraw(); } } @@ -636,8 +703,6 @@ function setMatchedInterval(callable, time, intervalHandler){ var unlockedDrawInterval; var lockedDrawInterval; -var changeFromEvent = false; - var lockedRedraw = getByPath(face, ["Properties","Redraw","Locked"]) || 60000; var unlockedRedraw = getByPath(face, ["Properties","Redraw","Unlocked"]) || 1000; var defaultRedraw = getByPath(face, ["Properties","Redraw","Default"]) || "Always";