Merge f032e73 into 5baba17

lib/Component.lua

@@ -6,10 +6,16 @@
 
 local Reconciler = require(script.Parent.Reconciler)
 local Core = require(script.Parent.Core)
+local GlobalConfig = require(script.Parent.GlobalConfig)
+local Instrumentation = require(script.Parent.Instrumentation)
+
 local invalidSetStateMessages = require(script.Parent.invalidSetStateMessages)
 
 local Component = {}
 
+-- Locally cache tick so we can minimize impact of calling it for instrumentation
+local tick = tick
+
 Component.__index = Component
 
 local function mergeState(currentState, partialState)
@@ -180,7 +186,20 @@ end
 ]]
 function Component:_update(newProps, newState)
 	self._setStateBlockedReason = "shouldUpdate"
-	local doUpdate = self:shouldUpdate(newProps or self.props, newState or self.state)
+
+	local doUpdate
+	if GlobalConfig.getValue("componentInstrumentation") then
+		-- Start timing
+		local time = tick()
+		doUpdate = self:shouldUpdate(newProps or self.props, newState or self.state)
+		-- Finish timing
+		time = tick() - time
+		-- Log result
+		Instrumentation.logShouldUpdate(self._handle, doUpdate, time)
+	else
+		doUpdate = self:shouldUpdate(newProps or self.props, newState or self.state)
+	end
+
 	self._setStateBlockedReason = nil
 
 	if doUpdate then
@@ -228,7 +247,20 @@ function Component:_forceUpdate(newProps, newState)
 	end
 
 	self._setStateBlockedReason = "render"
-	local newChildElement = self:render()
+
+	local newChildElement
+	if GlobalConfig.getValue("componentInstrumentation") then
+		-- Start timing
+		local time = tick()
+		newChildElement = self:render()
+		-- End timing
+		time = tick() - time
+		-- Log result
+		Instrumentation.logRenderTime(self._handle, time)
+	else
+		newChildElement = self:render()
+	end
+
 	self._setStateBlockedReason = nil
 
 	self._setStateBlockedReason = "reconcile"
@@ -262,7 +294,20 @@ function Component:_reify(handle)
 	self._handle = handle
 
 	self._setStateBlockedReason = "render"
-	local virtualTree = self:render()
+
+	local virtualTree
+	if GlobalConfig.getValue("componentInstrumentation") then
+		-- Start timing
+		local time = tick()
+		virtualTree = self:render()
+		-- End timing
+		time = tick() - time
+		-- Log result
+		Instrumentation.logRenderTime(self._handle, time)
+	else
+		virtualTree = self:render()
+	end
+
 	self._setStateBlockedReason = nil
 
 	if virtualTree then

lib/Config.lua

@@ -16,6 +16,8 @@
 local defaultConfig = {
 	-- Enables storage of `debug.traceback()` values on elements for debugging.
 	["elementTracing"] = false,
+	-- Enables instrumentation of shouldUpdate
+	["componentInstrumentation"] = false,
 }
 
 -- Build a list of valid configuration values up for debug messages.

lib/Instrumentation.lua

@@ -0,0 +1,98 @@
+local Instrumentation = {}
+
+local componentStats = {}
+-- Tracks a number of stats, including:
+	-- Recorded stats:
+		-- Render count by component
+		-- Update request count by component
+		-- Actual update count by component
+		-- shouldUpdate returned true count by component
+		-- Time taken to run shouldUpdate
+		-- Time taken to render by component
+	-- Derivable stats (for profiling manually or with a future tool):
+		-- Average render time by component
+		-- Percent of total render time by component
+		-- Percent of time shouldUpdate returns true
+		-- Average shouldUpdate time by component
+		-- Percent of total shouldUpdate time by component
+
+--[[
+	Determines name of component from the given instance handle and returns a
+	stat object from the componentStats table, generating a new one if needed
+]]
+local function getStatEntry(handle)
+	local name
+	if handle and handle._element and handle._element.component then
+		name = tostring(handle._element.component)
+	else
+		warn("Component name not valid for " .. tostring(handle._key))
+		return nil
+	end
+	local entry = componentStats[name]
+	if not entry then
+		entry = {
+			-- update requests
+			updateReqCount = 0,
+			-- actual updates
+			didUpdateCount = 0,
+			-- time spent in shouldUpdate
+			shouldUpdateTime = 0,
+			-- number of renders
+			renderCount = 0,
+			-- total render time spent
+			renderTime = 0,
+		}
+		componentStats[name] = entry
+	end
+
+	return entry
+end
+
+--[[
+	Logs the time taken and resulting value of a Component's shouldUpdate function
+]]
+function Instrumentation.logShouldUpdate(handle, updateNeeded, shouldUpdateTime)
+	-- Grab or create associated entry in stats table
+	local statEntry = getStatEntry(handle)
+	if statEntry then
+		-- Increment the total number of times update was invoked
+		statEntry.updateReqCount = statEntry.updateReqCount + 1
+
+		-- Increment (when applicable) total number of times shouldUpdate returned true
+		statEntry.didUpdateCount = statEntry.didUpdateCount + (updateNeeded and 1 or 0)
+
+		-- Add time spent checking if an update is needed (in millis) to total time
+		statEntry.shouldUpdateTime = statEntry.shouldUpdateTime + shouldUpdateTime * 1000
+	end
+end
+
+--[[
+	Logs the time taken value of a Component's render function
+]]
+function Instrumentation.logRenderTime(handle, renderTime)
+	-- Grab or create associated entry in stats table
+	local statEntry = getStatEntry(handle)
+	if statEntry then
+		-- Increment total render count
+		statEntry.renderCount = statEntry.renderCount + 1
+
+		-- Add render time (in millis) to total rendering time
+		statEntry.renderTime = statEntry.renderTime + renderTime * 1000
+	end
+end
+
+--[[
+	Clears all the stats collected thus far. Useful for testing and for profiling in the future
+]]
+function Instrumentation.clearCollectedStats()
+	componentStats = {}
+end
+
+--[[
+	Returns all the stats collected thus far. Useful for testing and for profiling in the future
+]]
+function Instrumentation.getCollectedStats()
+	return componentStats
+end
+
+return Instrumentation

lib/Instrumentation.spec.lua

@@ -0,0 +1,99 @@
+return function()
+	local Component = require(script.Parent.PureComponent)
+	local Core = require(script.Parent.Core)
+	local GlobalConfig = require(script.Parent.GlobalConfig)
+	local Instrumentation = require(script.Parent.Instrumentation)
+	local Reconciler = require(script.Parent.Reconciler)
+
+	it("should count and time renders when enabled", function()
+		GlobalConfig.set({
+			["componentInstrumentation"] = true,
+		})
+		local triggerUpdate
+
+		local TestComponent = Component:extend("TestComponent")
+		function TestComponent:init()
+			self.state = {
+				value = 0
+			}
+		end
+
+		function TestComponent:render()
+			return nil
+		end
+
+		function TestComponent:didMount()
+			triggerUpdate = function()
+				self:setState({
+					value = self.state.value + 1
+				})
+			end
+		end
+
+		local instance = Reconciler.reify(Core.createElement(TestComponent))
+
+		local stats = Instrumentation.getCollectedStats()
+		expect(stats.TestComponent).to.be.ok()
+		expect(stats.TestComponent.renderCount).to.equal(1)
+		expect(stats.TestComponent.renderTime).never.to.equal(0)
+
+		triggerUpdate()
+		expect(stats.TestComponent.renderCount).to.equal(2)
+
+		Reconciler.teardown(instance)
+		Instrumentation.clearCollectedStats()
+		GlobalConfig.reset()
+	end)
+
+	it("should count and time shouldUpdate calls when enabled", function()
+		GlobalConfig.set({
+			["componentInstrumentation"] = true,
+		})
+		local triggerUpdate
+		local willDoUpdate = false
+
+		local TestComponent = Component:extend("TestComponent")
+
+		function TestComponent:init()
+			self.state = {
+				value = 0,
+			}
+		end
+
+		function TestComponent:shouldUpdate()
+			return willDoUpdate
+		end
+
+		function TestComponent:didMount()
+			triggerUpdate = function()
+				self:setState({
+					value = self.state.value + 1,
+				})
+			end
+		end
+
+		function TestComponent:render() end
+
+		local instance = Reconciler.reify(Core.createElement(TestComponent))
+
+		local stats = Instrumentation.getCollectedStats()
+
+		willDoUpdate = true
+		triggerUpdate()
+
+		expect(stats.TestComponent).to.be.ok()
+		expect(stats.TestComponent.updateReqCount).to.equal(1)
+		expect(stats.TestComponent.didUpdateCount).to.equal(1)
+
+		willDoUpdate = false
+		triggerUpdate()
+
+		expect(stats.TestComponent.updateReqCount).to.equal(2)
+		expect(stats.TestComponent.didUpdateCount).to.equal(1)
+		expect(stats.TestComponent.shouldUpdateTime).never.to.equal(0)
+
+		Reconciler.teardown(instance)
+		Instrumentation.clearCollectedStats()
+		GlobalConfig.reset()
+	end)
+end

lib/init.lua

@@ -7,6 +7,7 @@ local Core = require(script.Core)
 local Event = require(script.Event)
 local Change = require(script.Change)
 local GlobalConfig = require(script.GlobalConfig)
+local Instrumentation = require(script.Instrumentation)
 local PureComponent = require(script.PureComponent)
 local Reconciler = require(script.Reconciler)
 
@@ -46,4 +47,11 @@ apply(Roact, {
 	getGlobalConfigValue = GlobalConfig.getValue,
 })
 
+apply(Roact, {
+	Instrumentation = {
+		getCollectedStats = Instrumentation.getCollectedStats,
+		clearCollectedStats = Instrumentation.clearCollectedStats,
+	}
+})
+
 return Roact