Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactor: Conditional log message evaluation #335

Merged
merged 5 commits into from
Nov 20, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion addons/netfox.extras/plugin.cfg
Original file line number Diff line number Diff line change
Expand Up @@ -3,5 +3,5 @@
name="netfox.extras"
description="Game-specific utilities for Netfox"
author="Tamas Galffy"
version="1.13.0"
version="1.13.1"
script="netfox-extras.gd"
Original file line number Diff line number Diff line change
Expand Up @@ -53,7 +53,7 @@ func transition(new_state_name: StringName) -> void:
return

if not _available_states.has(new_state_name):
_logger.warning("Attempted to transition from state '%s' into unknown state '%s'" % [state, new_state_name])
_logger.warning("Attempted to transition from state '%s' into unknown state '%s'", [state, new_state_name])
return

var new_state: RewindableState = _available_states[new_state_name]
Expand Down Expand Up @@ -112,7 +112,7 @@ func _set_state(new_state: StringName) -> void:
return

if not _available_states.has(new_state):
_logger.warning("Attempted to jump to unknown state: %s" % [new_state])
_logger.warning("Attempted to jump to unknown state: %s", [new_state])
return

_state_object = _available_states[new_state]
10 changes: 5 additions & 5 deletions addons/netfox.extras/weapon/network-weapon.gd
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@ func fire() -> Node:
else:
_accept_projectile.rpc(id, NetworkTime.tick, data)

_logger.debug("Calling after fire hook for %s" % [projectile.name])
_logger.debug("Calling after fire hook for %s", [projectile.name])
_after_fire(projectile)

return projectile
Expand Down Expand Up @@ -128,7 +128,7 @@ func _before_tick_loop():
if is_instance_valid(projectile):
_reconcile(projectile, local_data, response_data)
else:
_logger.warning("Projectile %s vanished by the time of reconciliation!" % [projectile_id])
_logger.warning("Projectile %s vanished by the time of reconciliation!", [projectile_id])

_reconcile_buffer.clear()

Expand All @@ -149,7 +149,7 @@ func _request_projectile(id: String, tick: int, request_data: Dictionary):
# Reject if sender can't use this input
if not _can_peer_use(sender) or not _can_fire():
_decline_projectile.rpc_id(sender, id)
_logger.error("Projectile %s rejected! Peer %s can't use this weapon now" % [id, sender])
_logger.error("Projectile %s rejected! Peer %s can't use this weapon now", [id, sender])
return

# Validate incoming data
Expand All @@ -159,7 +159,7 @@ func _request_projectile(id: String, tick: int, request_data: Dictionary):
if not _is_reconcilable(projectile, request_data, local_data):
projectile.queue_free()
_decline_projectile.rpc_id(sender, id)
_logger.error("Projectile %s rejected! Can't reconcile states: [%s, %s]" % [id, request_data, local_data])
_logger.error("Projectile %s rejected! Can't reconcile states: [%s, %s]", [id, request_data, local_data])
return

_save_projectile(projectile, id, local_data)
Expand All @@ -168,7 +168,7 @@ func _request_projectile(id: String, tick: int, request_data: Dictionary):

@rpc("authority", "reliable", "call_local")
func _accept_projectile(id: String, tick: int, response_data: Dictionary):
_logger.info("[%s] Accepting projectile %s from %s" % [multiplayer.get_unique_id(), id, multiplayer.get_remote_sender_id()])
_logger.info("Accepting projectile %s from %s", [id, multiplayer.get_remote_sender_id()])
if multiplayer.get_unique_id() == multiplayer.get_remote_sender_id():
# Projectile is local, nothing to do
return
Expand Down
8 changes: 4 additions & 4 deletions addons/netfox.extras/window-tiler.gd
Original file line number Diff line number Diff line change
Expand Up @@ -20,11 +20,11 @@ func _ready() -> void:
if not ProjectSettings.get_setting("netfox/extras/auto_tile_windows", false):
return

_logger.debug("Tiling with sid: %s, uid: %s" % [_sid, _uid])
_logger.debug("Tiling with sid: %s, uid: %s", [_sid, _uid])

var err = _make_lock(_sid, _uid)
if err != Error.OK:
_logger.warning("Failed to create lock for tiling, reason: %s" % [error_string(err)])
_logger.warning("Failed to create lock for tiling, reason: %s", [error_string(err)])
return

# Search for locks, stop once no new locks are found
Expand All @@ -42,7 +42,7 @@ func _ready() -> void:
var tile_count = locks.size()
var idx = locks.find(_uid)

_logger.debug("Tiling as idx %d / %d - %s in %s" % [idx, tile_count, _uid, locks])
_logger.debug("Tiling as idx %d / %d - %s in %s", [idx, tile_count, _uid, locks])
_tile_window(idx, tile_count)

func _make_lock(sid: String, uid: String) -> Error:
Expand Down Expand Up @@ -73,7 +73,7 @@ func _cleanup():
if dir:
for f in dir.get_files():
if f.begins_with(_prefix) and _get_sid(f) != _sid:
_logger.trace("Cleaned up lock: %s" % [f])
_logger.trace("Cleaned up lock: %s", [f])
dir.remove(OS.get_cache_dir() + "/" + f)

func _get_sid(filename: String) -> String:
Expand Down
33 changes: 19 additions & 14 deletions addons/netfox.internals/logger.gd
Original file line number Diff line number Diff line change
Expand Up @@ -70,36 +70,41 @@ func _check_log_level(level: int) -> bool:

return true

func _format_text(text: String, level: int) -> String:
func _format_text(text: String, values: Array, level: int) -> String:
level = clampi(level, LOG_MIN, LOG_MAX)
var peer_id := NetworkEvents.multiplayer.get_unique_id()
var tick := NetworkTime.tick

return "[%s][@%s][#%s][%s::%s] %s" % [level_prefixes[level], tick, peer_id, module, name, text]
var prefix := "[%s][@%s][#%s][%s::%s] " % [level_prefixes[level], tick, peer_id, module, name]

if values.is_empty():
return prefix + text
else:
return prefix + (text % values)

func _log_text(text: String, level: int):
func _log_text(text: String, values: Array, level: int):
if _check_log_level(level):
print(_format_text(text, level))
print(_format_text(text, values, level))

func trace(text: String):
_log_text(text, LOG_TRACE)
func trace(text: String, values: Array = []):
_log_text(text, values, LOG_TRACE)

func debug(text: String):
_log_text(text, LOG_DEBUG)
func debug(text: String, values: Array = []):
_log_text(text, values, LOG_DEBUG)

func info(text: String):
_log_text(text, LOG_INFO)
func info(text: String, values: Array = []):
_log_text(text, values, LOG_INFO)

func warning(text: String):
func warning(text: String, values: Array = []):
if _check_log_level(LOG_WARN):
var formatted_text = _format_text(text, LOG_WARN)
var formatted_text = _format_text(text, values, LOG_WARN)
push_warning(formatted_text)
# Print so it shows up in the Output panel too
print(formatted_text)

func error(text: String):
func error(text: String, values: Array = []):
if _check_log_level(LOG_ERROR):
var formatted_text = _format_text(text, LOG_ERROR)
var formatted_text = _format_text(text, values, LOG_ERROR)
push_error(formatted_text)
# Print so it shows up in the Output panel too
print(formatted_text)
2 changes: 1 addition & 1 deletion addons/netfox.internals/plugin.cfg
Original file line number Diff line number Diff line change
Expand Up @@ -3,5 +3,5 @@
name="netfox.internals"
description="Shared internals for netfox addons"
author="Tamas Galffy"
version="1.13.0"
version="1.13.1"
script="plugin.gd"
22 changes: 11 additions & 11 deletions addons/netfox.noray/noray.gd
Original file line number Diff line number Diff line change
Expand Up @@ -68,10 +68,10 @@ func connect_to_host(address: String, port: int = 8890) -> Error:
if is_connected_to_host():
disconnect_from_host()

_logger.info("Trying to connect to noray at %s:%s" % [address, port])
_logger.info("Trying to connect to noray at %s:%s", [address, port])

address = IP.resolve_hostname(address, IP.TYPE_IPV4)
_logger.debug("Resolved noray host to %s" % address)
_logger.debug("Resolved noray host to %s", [address])

var err = _peer.connect_to_host(address, port)
if err != Error.OK:
Expand All @@ -86,11 +86,11 @@ func connect_to_host(address: String, port: int = 8890) -> Error:

if _peer.get_status() == _peer.STATUS_CONNECTED:
_address = address
_logger.info("Connected to noray at %s:%s" % [address, port])
_logger.info("Connected to noray at %s:%s", [address, port])
on_connect_to_host.emit()
return OK
else:
_logger.error("Connection failed to noray at %s:%s, connection status %s" % [address, port, _peer.get_status()])
_logger.error("Connection failed to noray at %s:%s, connection status %s", [address, port, _peer.get_status()])
disconnect_from_host()
return ERR_CONNECTION_ERROR

Expand Down Expand Up @@ -123,7 +123,7 @@ func register_remote(registrar_port: int = 8809, timeout: float = 8, interval: f
udp.bind(0)
udp.set_dest_address(_address, registrar_port)

_logger.debug("Bound UDP to port %s" % [udp.get_local_port()])
_logger.debug("Bound UDP to port %s", [udp.get_local_port()])

var packet = pid.to_utf8_buffer()

Expand All @@ -134,7 +134,7 @@ func register_remote(registrar_port: int = 8809, timeout: float = 8, interval: f
var recv = udp.get_packet().get_string_from_utf8()
if recv == "OK":
_local_port = udp.get_local_port()
_logger.info("Registered local port %s to remote" % [_local_port])
_logger.info("Registered local port %s to remote", [_local_port])
result = OK
timeout = 0 # Break outer loop
break
Expand Down Expand Up @@ -184,21 +184,21 @@ func _handle_commands(command: String, data: String):
if command == "set-oid":
_oid = data
on_oid.emit(oid)
_logger.debug("Saved OID: %s" % oid)
_logger.debug("Saved OID: %s", [oid])
elif command == "set-pid":
_pid = data
on_pid.emit(pid)
_logger.debug("Saved PID: %s" % pid)
_logger.debug("Saved PID: %s", [pid])
elif command == "connect":
var parts = data.split(":")
var host = parts[0]
var port = parts[1].to_int()
_logger.debug("Received connect command to %s:%s" % [host, port])
_logger.debug("Received connect command to %s:%s", [host, port])
on_connect_nat.emit(host, port)
elif command == "connect-relay":
var host = _address
var port = data.to_int()
_logger.debug("Received connect relay command to %s:%s" % [host, port])
_logger.debug("Received connect relay command to %s:%s", [host, port])
on_connect_relay.emit(host, port)
else:
_logger.trace("Received command %s %s" % [command, data])
_logger.trace("Received command %s %s", [command, data])
2 changes: 1 addition & 1 deletion addons/netfox.noray/plugin.cfg
Original file line number Diff line number Diff line change
Expand Up @@ -3,5 +3,5 @@
name="netfox.noray"
description="Bulletproof your connectivity with noray integration for netfox"
author="Tamas Galffy"
version="1.13.0"
version="1.13.1"
script="netfox-noray.gd"
14 changes: 7 additions & 7 deletions addons/netfox/network-time-synchronizer.gd
Original file line number Diff line number Diff line change
Expand Up @@ -152,7 +152,7 @@ func get_time() -> float:
return _clock.get_time()

func _loop():
_logger.info("Time sync loop started! Initial timestamp: %ss" % [_clock.get_time()])
_logger.info("Time sync loop started! Initial timestamp: %ss", [_clock.get_time()])
on_initial_sync.emit()

while _active:
Expand All @@ -175,7 +175,7 @@ func _discipline_clock():
return a.get_rtt() < b.get_rtt()
)

_logger.trace("Using sorted samples: \n%s" % [
_logger.trace("Using sorted samples: \n%s", [
"\n".join(sorted_samples.map(func(it: NetworkClockSample): return "\t" + it.to_string() + " (%.4fs)" % [get_time() - it.ping_sent]))
])

Expand Down Expand Up @@ -207,13 +207,13 @@ func _discipline_clock():

_offset = 0.

_logger.warning("Offset %ss is above panic threshold %ss! Resetting clock" % [offset, panic_threshold])
_logger.warning("Offset %ss is above panic threshold %ss! Resetting clock", [offset, panic_threshold])
on_panic.emit(offset)
else:
# Nudge clock towards estimated time
var nudge := offset / adjust_steps
_clock.adjust(nudge)
_logger.trace("Adjusted clock by %.2fms, offset: %.2fms, new time: %.4fss" % [nudge * 1000., offset * 1000., _clock.get_time()])
_logger.trace("Adjusted clock by %.2fms, offset: %.2fms, new time: %.4fss", [nudge * 1000., offset * 1000., _clock.get_time()])

_offset = offset - nudge

Expand All @@ -237,7 +237,7 @@ func _send_pong(idx: int, ping_received: float, pong_sent: float):
sample.pong_sent = pong_sent
sample.pong_received = pong_received

_logger.trace("Received sample: %s" % [sample])
_logger.trace("Received sample: %s", [sample])

# Once a sample is done, remove from in-flight samples and move to sample buffer
_awaiting_samples.erase(idx)
Expand All @@ -248,11 +248,11 @@ func _send_pong(idx: int, ping_received: float, pong_sent: float):

@rpc("any_peer", "call_remote", "reliable")
func _request_timestamp():
_logger.debug("Requested initial timestamp @ %.4fs raw time" % [_clock.get_raw_time()])
_logger.debug("Requested initial timestamp @ %.4fs raw time", [_clock.get_raw_time()])
_set_timestamp.rpc_id(multiplayer.get_remote_sender_id(), _clock.get_time())

@rpc("any_peer", "call_remote", "reliable")
func _set_timestamp(timestamp: float):
_logger.debug("Received initial timestamp @ %.4fs raw time" % [_clock.get_raw_time()])
_logger.debug("Received initial timestamp @ %.4fs raw time", [_clock.get_raw_time()])
_clock.set_time(timestamp)
_loop()
6 changes: 3 additions & 3 deletions addons/netfox/network-time.gd
Original file line number Diff line number Diff line change
Expand Up @@ -459,7 +459,7 @@ func _loop():
# Game stalled for a while, probably paused, don't run extra ticks
# to catch up
_was_paused = true
_logger.debug("Game stalled for %.4fs, assuming it was a pause" % [clock_step_raw])
_logger.debug("Game stalled for %.4fs, assuming it was a pause", [clock_step_raw])

# Handle pause
if _was_paused:
Expand Down Expand Up @@ -505,9 +505,9 @@ func _is_active() -> bool:
func _submit_sync_success():
var peer_id = multiplayer.get_remote_sender_id()

_logger.trace("Received time sync success from #%s, synced peers: %s" % [peer_id, _synced_peers.keys()])
_logger.trace("Received time sync success from #%s, synced peers: %s", [peer_id, _synced_peers.keys()])

if not _synced_peers.has(peer_id):
_synced_peers[peer_id] = true
after_client_sync.emit(peer_id)
_logger.debug("Peer #%s is now on time!" % [peer_id])
_logger.debug("Peer #%s is now on time!", [peer_id])
2 changes: 1 addition & 1 deletion addons/netfox/plugin.cfg
Original file line number Diff line number Diff line change
Expand Up @@ -3,5 +3,5 @@
name="netfox"
description="Shared internals for netfox addons"
author="Tamas Galffy"
version="1.13.0"
version="1.13.1"
script="netfox.gd"
2 changes: 1 addition & 1 deletion addons/netfox/properties/property-cache.gd
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ func get_entry(path: String) -> PropertyEntry:
if not _cache.has(path):
var parsed = PropertyEntry.parse(root, path)
if not parsed.is_valid():
_logger.warning("Invalid property path: %s" % path)
_logger.warning("Invalid property path: %s", [path])
_cache[path] = parsed
return _cache[path]

Expand Down
2 changes: 1 addition & 1 deletion addons/netfox/rollback/network-rollback.gd
Original file line number Diff line number Diff line change
Expand Up @@ -158,7 +158,7 @@ func _rollback():
# Limit number of rollback ticks
if to - from > history_limit:
_logger.warning(
"Trying to run rollback for ticks %d to %d, past the history limit of %d" %
"Trying to run rollback for ticks %d to %d, past the history limit of %d",
[from, to, history_limit]
)
from = NetworkTime.tick - history_limit
Expand Down
Loading