feat: Performance monitors (#195)

Implements NetworkPerformance autoload, that provides custom monitors
for networking performance measurements.

Refs #173

addons/netfox.extras/plugin.cfg

@@ -3,5 +3,5 @@
 name="netfox.extras"
 description="Game-specific utilities for Netfox"
 author="Tamas Galffy"
-version="1.1.2"
+version="1.2.0"
 script="netfox-extras.gd"

addons/netfox.internals/plugin.cfg

@@ -3,5 +3,5 @@
 name="netfox.internals"
 description="Shared internals for netfox addons"
 author="Tamas Galffy"
-version="1.1.2"
+version="1.2.0"
 script="plugin.gd"

addons/netfox.noray/plugin.cfg

@@ -3,5 +3,5 @@
 name="netfox.noray"
 description="Bulletproof your connectivity with noray integration for netfox"
 author="Tamas Galffy"
-version="1.1.2"
+version="1.2.0"
 script="netfox-noray.gd"

addons/netfox/netfox.gd

@@ -90,6 +90,10 @@ const AUTOLOADS = [
 	{
 		"name": "NetworkEvents",
 		"path": ROOT + "/network-events.gd"
+	},
+	{
+		"name": "NetworkPerformance",
+		"path": ROOT + "/network-performance.gd"
 	}
 ]
 

addons/netfox/network-performance.gd

@@ -0,0 +1,99 @@
+extends Node
+
+const NETWORK_LOOP_DURATION_MONITOR: StringName = "netfox/Network loop duration (ms)"
+const ROLLBACK_LOOP_DURATION_MONITOR: StringName = "netfox/Rollback loop duration (ms)"
+const NETWORK_TICKS_MONITOR: StringName = "netfox/Network ticks simulated"
+const ROLLBACK_TICKS_MONITOR: StringName = "netfox/Rollback ticks simulated"
+const ROLLBACK_TICK_DURATION_MONITOR: StringName = "netfox/Rollback tick duration (ms)"
+
+var _network_loop_start: float = 0
+var _network_loop_duration: float = 0
+
+var _network_ticks: int = 0
+var _network_ticks_accum: int = 0
+
+var _rollback_loop_start: float = 0
+var _rollback_loop_duration: float = 0
+
+var _rollback_ticks: int = 0
+var _rollback_ticks_accum: int = 0
+
+static var _logger: _NetfoxLogger = _NetfoxLogger.for_netfox("NetworkPerformance")
+
+func is_enabled():
+	if OS.has_feature("netfox_noperf"):
+		return false
+
+	if OS.has_feature("netfox_perf"):
+		return true
+
+	# This returns true in the editor too
+	return OS.is_debug_build()
+
+## Get time spent in the last network tick loop, in millisec.
+## [br]
+## Note that this also includes time spent in the rollback tick loop.
+func get_network_loop_duration_ms() -> float:
+	return _network_loop_duration * 1000
+
+## Get the number of ticks simulated in the last network tick loop.
+func get_network_ticks() -> int:
+	return _network_ticks
+
+## Get time spent in the last rollback tick loop, in millisec.
+func get_rollback_loop_duration_ms() -> float:
+	return _rollback_loop_duration * 1000
+
+## Get the number of ticks resimulated in the last rollback tick loop.
+func get_rollback_ticks() -> int:
+	return _rollback_ticks
+
+## Get the average amount of time spent in a rollback tick during the last
+## rollback loop, in millisec.
+func get_rollback_tick_duration_ms() -> float:
+	return _rollback_loop_duration * 1000 / maxi(_rollback_ticks, 1)
+
+func _ready():
+	if not is_enabled():
+		_logger.debug("Network performance disabled")
+		return
+
+	_logger.debug("Network performance enabled, registering performance monitors")
+	Performance.add_custom_monitor(NETWORK_LOOP_DURATION_MONITOR, get_network_loop_duration_ms)
+	Performance.add_custom_monitor(ROLLBACK_LOOP_DURATION_MONITOR, get_rollback_loop_duration_ms)
+	Performance.add_custom_monitor(NETWORK_TICKS_MONITOR, get_network_ticks)
+	Performance.add_custom_monitor(ROLLBACK_TICKS_MONITOR, get_rollback_ticks)
+	Performance.add_custom_monitor(ROLLBACK_TICK_DURATION_MONITOR, get_rollback_tick_duration_ms)
+
+	NetworkTime.before_tick_loop.connect(_before_tick_loop)
+	NetworkTime.on_tick.connect(_on_network_tick)
+	NetworkTime.after_tick_loop.connect(_after_tick_loop)
+
+	NetworkRollback.before_loop.connect(_before_rollback_loop)
+	NetworkRollback.on_process_tick.connect(_on_rollback_tick)
+	NetworkRollback.after_loop.connect(_after_rollback_loop)
+
+func _before_tick_loop():
+	_network_loop_start = _time()
+	_network_ticks_accum = 0
+
+func _on_network_tick(_dt, _t):
+	_network_ticks_accum += 1
+
+func _after_tick_loop():
+	_network_loop_duration = _time() - _network_loop_start
+	_network_ticks = _network_ticks_accum
+
+func _before_rollback_loop():
+	_rollback_loop_start = _time()
+	_rollback_ticks_accum = 0
+
+func _on_rollback_tick(_t):
+	_rollback_ticks_accum += 1
+
+func _after_rollback_loop():
+	_rollback_loop_duration = _time() - _rollback_loop_start
+	_rollback_ticks = _rollback_ticks_accum
+
+func _time() -> float:
+	return Time.get_unix_time_from_system()

addons/netfox/plugin.cfg

@@ -3,5 +3,5 @@
 name="netfox"
 description="Shared internals for netfox addons"
 author="Tamas Galffy"
-version="1.1.2"
+version="1.2.0"
 script="netfox.gd"

docs/netfox/guides/network-performance.md

@@ -0,0 +1,69 @@
+# NetworkPerformance
+
+Provides [custom monitors] for measuring networking performance. Included as an
+autoload.
+
+## Enabling monitoring
+
+By default, network performance monitoring is only enabled in debug builds and
+when running from the editor.
+
+Use the `netfox_noperf` feature tag to force disable network performance
+monitors.
+
+Use the `netfox_perf` feature tag to force enable network performance monitors.
+
+These feature tags enable customization for each export preset.
+
+## Performance monitors
+
+### Network loop duration
+
+*Network loop duration* measures the time spent in the [network tick loop].
+Note that this includes time spent on the [rollback loop] as well.
+
+This value is updated once for every tick loop, it is not reset to zero after
+the loop has run. This means that you may get a non-zero reading, even if the
+tick loop is currently not running.
+
+### Rollback loop duration
+
+*Rollback loop duration* measures the time spent in the last [rollback loop].
+This includes all of its steps. 
+
+The value of this monitor may be zero, if no players have joined, no nodes use
+rollback, or rollback is disabled.
+
+### Network ticks simulated
+
+*Network ticks simulated* measures the number of ticks run in the last [network
+tick loop]. If the game runs at a higher FPS than the network tickrate, this
+value should be consistently one.
+
+Higher, stable values mean that the game itself runs slower than the network
+tickrate, and needs to catch up by running multiple ticks on each frame.
+
+### Rollback ticks simulated
+
+*Rollback ticks simulated* measures the number of rollback ticks run in the
+last [rollback loop]. Generally, this denotes the age of the oldest input *or*
+state received, depending on whether the game is running as a server or client.
+
+The measurement is strongly correlated to network latency - the higher the
+latency, the older the state and input packets will be upon arrival.
+
+The more rollback ticks need to be simulated, the more work the rollback tick
+has to do, which can negatively affect performance.
+
+### Rollback tick duration
+
+*Rollback tick duration* provides the average time spent simulating a single
+tick in the last [rollback loop].
+
+This can be useful to determine if the rollback tick duration comes from too
+many ticks being simulated, or the individual ticks being expensive to
+simulate ( or both ).
+
+[custom monitors]: https://docs.godotengine.org/en/latest/classes/class_performance.html#class-performance-method-add-custom-monitor
+[network tick loop]: ./network-time.md
+[rollback loop]: ./network-rollback.md

mkdocs.yml

@@ -17,6 +17,7 @@ nav:
       - 'netfox/guides/interpolators.md'
       - 'netfox/guides/property-paths.md'
       - 'netfox/guides/network-rollback.md'
+      - 'netfox/guides/network-performance.md'
     - Nodes:
       - 'netfox/nodes/tick-interpolator.md'
       - 'netfox/nodes/rollback-synchronizer.md'

project.godot

@@ -27,6 +27,7 @@ NetworkRollback="*res://addons/netfox/rollback/network-rollback.gd"
 NetworkEvents="*res://addons/netfox/network-events.gd"
 Noray="*res://addons/netfox.noray/noray.gd"
 PacketHandshake="*res://addons/netfox.noray/packet-handshake.gd"
+NetworkPerformance="*res://addons/netfox/network-performance.gd"
 
 [display]