diff --git a/Containers/container.gd b/Containers/container.gd index aa6322b..3ba3aa7 100644 --- a/Containers/container.gd +++ b/Containers/container.gd @@ -29,13 +29,13 @@ func _ready() -> void: func _on_body_entered(body: Node3D) -> void: if not NetworkManager.owns_world(): return - print("Container enabled: ", enabled) + SweetLogger.debug("enabled: {0}", [enabled], "container.gd", "_on_body_entered") if not enabled: - print("Container disabled in _on_body_entered body") + SweetLogger.debug("disabled in _on_body_entered body", [], "container.gd", "_on_body_entered") return if not body.is_in_group(target_group): return - print("Container _on_body_entered body: ", body) + SweetLogger.debug("body: {0}", [body], "container.gd", "_on_body_entered") # If one of us is in a station @@ -46,14 +46,14 @@ func _on_body_entered(body: Node3D) -> void: # If enough space, add item var food_item = body.get_node("FoodItem") - print("Container in station found %s of type %s: %s" % [target_group, FoodItem.Type.keys()[food_item.type], body.name]) + SweetLogger.debug("in station found {0} of type {1}: {2}", [target_group, FoodItem.Type.keys()[food_item.type], body.name], "container.gd", "_on_body_entered") var meal_count := contained_items.filter(func(f): return f.type == FoodItem.Type.MEAL).size() var side_count := contained_items.filter(func(f): return f.type == FoodItem.Type.SIDE).size() if food_item.type == FoodItem.Type.MEAL and meal_count < meal_positions.size(): - print("Container adding meal") + SweetLogger.debug("adding meal", [], "container.gd", "_on_body_entered") _add_item(body) if food_item.type == FoodItem.Type.SIDE and side_count < side_positions.size(): - print("Container adding side") + SweetLogger.debug("adding side", [], "container.gd", "_on_body_entered") _add_item(body) @@ -93,7 +93,7 @@ func _add_item(item: Node3D) -> void: NetworkManager.despawn_item(item) # In case the container is on a table that needs to register this addition, # ask all table in scene to absorb any new items. - print("Container group call absorb_items()") + SweetLogger.debug("group call absorb_items()", [], "container.gd", "_add_item") get_tree().call_group("table", "absorb_items") diff --git a/Net/net_pickable.gd b/Net/net_pickable.gd index 114e831..5323def 100644 --- a/Net/net_pickable.gd +++ b/Net/net_pickable.gd @@ -51,9 +51,7 @@ func _set_net_held_by(value: int) -> void: var old := net_held_by net_held_by = value if old != value and NetworkManager.is_online(): - print("%s net_held_by: %d -> %d (local state: %s, authority=%d)" % [ - _pickable.name, old, value, _holder_desc(), get_multiplayer_authority() - ]) + SweetLogger.debug("{0} net_held_by: {1} -> {2} (local state: {3}, authority={4})", [_pickable.name, old, value, _holder_desc(), get_multiplayer_authority()], "net_pickable.gd", "_set_net_held_by") apply_held_state() @@ -84,12 +82,7 @@ func apply_held_state() -> void: or _pickable.collision_mask != _pickable.original_collision_mask if changed: if NetworkManager.is_online(): - print( - "%s: reclaiming ownership, restoring freeze_mode %d->%d collision_mask %d->%d" % [ - _pickable.name, _pickable.freeze_mode, _original_freeze_mode, - _pickable.collision_mask, _pickable.original_collision_mask - ] - ) + SweetLogger.debug("{0}: reclaiming ownership, restoring freeze_mode {1}->{2} collision_mask {3}->{4}", [_pickable.name, _pickable.freeze_mode, _original_freeze_mode, _pickable.collision_mask, _pickable.original_collision_mask], "net_pickable.gd", "apply_held_state") _pickable.freeze_mode = _original_freeze_mode _pickable.collision_mask = _pickable.original_collision_mask # Unlike freeze/collision (which XRToolsPickable manages itself while @@ -104,9 +97,7 @@ func apply_held_state() -> void: # driver that then fell out of the station. if _pickable.enabled != _original_enabled: if NetworkManager.is_online(): - print("%s: reclaiming ownership, restoring enabled %s->%s" % [ - _pickable.name, _pickable.enabled, _original_enabled - ]) + SweetLogger.debug("{0}: reclaiming ownership, restoring enabled {1}->{2}", [_pickable.name, _pickable.enabled, _original_enabled], "net_pickable.gd", "apply_held_state") _pickable.enabled = _original_enabled return # A net_held_by/position sync update can race ahead of the @@ -119,21 +110,13 @@ func apply_held_state() -> void: # Log once per grab, not once per tick. if NetworkManager.is_online() and not _grab_race_logged: _grab_race_logged = true - print( - "%s: ignoring non-authority sync (net_held_by=%d) — still actively held by our own hand (grab-race guard)" % [ - _pickable.name, net_held_by - ] - ) + SweetLogger.debug("{0}: ignoring non-authority sync (net_held_by={1}) — still actively held by our own hand (grab-race guard)", [_pickable.name, net_held_by], "net_pickable.gd", "apply_held_state") return _grab_race_logged = false # Someone else owns it: stop simulating locally, just follow the sync. if _pickable.is_picked_up(): if NetworkManager.is_online(): - print( - "%s: was held by %s on this peer, but authority now says peer %d owns it — force-dropping" % [ - _pickable.name, _holder_desc(), net_held_by - ] - ) + SweetLogger.debug("{0}: was held by {1} on this peer, but authority now says peer {2} owns it — force-dropping", [_pickable.name, _holder_desc(), net_held_by], "net_pickable.gd", "apply_held_state") _pickable.drop() # Bail out when we're already in the follow-the-sync state. Without this the # writes below (and the line logged with them) repeated every tick for every @@ -165,10 +148,10 @@ func _on_picked_up(_p) -> void: # addon's own "grab out of a snap zone" shortcut mid-cascade) — not a # player-initiated hand grab, so no authority request from here. if NetworkManager.is_online(): - print("%s picked up by %s (not a hand) — no authority request" % [_pickable.name, _holder_desc()]) + SweetLogger.debug("{0} picked up by {1} (not a hand) — no authority request", [_pickable.name, _holder_desc()], "net_pickable.gd", "_on_picked_up") return if NetworkManager.is_online(): - print("%s grabbed by hand (authority was peer %d), requesting authority" % [_pickable.name, net_held_by]) + SweetLogger.debug("{0} grabbed by hand (authority was peer {1}), requesting authority", [_pickable.name, net_held_by], "net_pickable.gd", "_on_picked_up") NetworkManager.request_item_authority_from(_pickable.get_path()) @@ -177,12 +160,10 @@ func _on_dropped(_p) -> void: # apply_held_state() losing authority (see above) must not re-report. if not is_multiplayer_authority(): if NetworkManager.is_online(): - print("%s dropped locally, but we aren't its authority (peer %d is) — not reporting" % [_pickable.name, net_held_by]) + SweetLogger.debug("{0} dropped locally, but we aren't its authority (peer {1} is) — not reporting", [_pickable.name, net_held_by], "net_pickable.gd", "_on_dropped") return if NetworkManager.is_online(): - print("%s dropped, reporting release to server (lin=%s ang=%s)" % [ - _pickable.name, _pickable.linear_velocity, _pickable.angular_velocity - ]) + SweetLogger.debug("{0} dropped, reporting release to server (lin={1} ang={2})", [_pickable.name, _pickable.linear_velocity, _pickable.angular_velocity], "net_pickable.gd", "_on_dropped") # Send our own final transform too: we were the authority until now, and the # server's copy may not have received our last position sync yet. NetworkManager.release_item_authority_from( diff --git a/Net/network_manager.gd b/Net/network_manager.gd index 30ad272..3501995 100644 --- a/Net/network_manager.gd +++ b/Net/network_manager.gd @@ -522,7 +522,7 @@ func _on_player_absent(peer_id: int) -> void: # --- Command-line driven test bootstrap ----------------------------------- func _handle_cmdline() -> void: - print("Networkmanager _handle_cmdline()") + SweetLogger.info("Networkmanager _handle_cmdline()", [], "network_manager.gd", "_handle_cmdline") var args := OS.get_cmdline_args() if args.has("--server"): log_line("cmdline: --server") @@ -554,7 +554,7 @@ func log_line(s: String) -> void: if p != null and p.get_connection_status() == MultiplayerPeer.CONNECTION_CONNECTED: id = multiplayer.get_unique_id() var line := "[NET %d] %s" % [id, s] - print(line) + SweetLogger.info(line, [], "network_manager.gd", "log_line") if _log_file: _log_file.store_line(line) _log_file.flush() diff --git a/Prefabs/build_mode_controller.gd b/Prefabs/build_mode_controller.gd index d199194..38fc985 100644 --- a/Prefabs/build_mode_controller.gd +++ b/Prefabs/build_mode_controller.gd @@ -7,7 +7,7 @@ func _ready() -> void: func _on_game_state_changed(new_state: GameManager.GameState) -> void: - print("BuildModeController: game_state_changed to %s" % GameManager.GameState.keys()[new_state]) + SweetLogger.info("game_state_changed to {0}", [GameManager.GameState.keys()[new_state]], "build_mode_controller.gd", "_on_game_state_changed") if new_state == GameManager.GameState.BUILDING: despawn_unheld_pickables() @@ -25,7 +25,7 @@ func despawn_unheld_pickables(): NetworkManager.despawn_item(pickable) continue if not held_by.is_in_group("persistent_inventory"): - print("BuildModeController despawn_unheld_pickables held_by: %s, pickable: %s " % [held_by, pickable]) + SweetLogger.debug("despawn_unheld_pickables held_by: {0}, pickable: {1}", [held_by, pickable], "build_mode_controller.gd", "despawn_unheld_pickables") NetworkManager.despawn_item(pickable) diff --git a/Prefabs/combinable_item.gd b/Prefabs/combinable_item.gd index c2b8823..c98974a 100644 --- a/Prefabs/combinable_item.gd +++ b/Prefabs/combinable_item.gd @@ -10,7 +10,7 @@ var _food_item: FoodItem func _ready() -> void: - print("CombinableItem _ready(): ", _pickable.name) + SweetLogger.debug("_ready(): {0}", [_pickable.name], "combinable_item.gd", "_ready") _food_item = get_parent().get_node_or_null("FoodItem") as FoodItem if not _food_item: push_error("CombinableItem is missing FoodItem reference. must be a sibling of a FoodItem on ", get_parent().name, ".") @@ -52,24 +52,24 @@ func _on_body_entered(body: Node3D) -> void: if not NetworkManager.owns_world(): return if _combining or body == _pickable: - print("CombinableItem _on_body_entered: other is our own pickable") + SweetLogger.debug("other is our own pickable", [], "combinable_item.gd", "_on_body_entered") return var other := Helper.find_food_item(body) if not other: - print("CombinableItem _on_body_entered: other is not a foodItem") + SweetLogger.debug("other is not a foodItem", [], "combinable_item.gd", "_on_body_entered") return var result: PackedScene = RecipeManager.get_combination_result(_food_item.id, other.id) if not result: - print("CombinableItem _on_body_entered: There is no recipe for %s + %s" % [_food_item.id, other.id]) + SweetLogger.debug("There is no recipe for {0} + {1}", [_food_item.id, other.id], "combinable_item.gd", "_on_body_entered") return _combine(body, result) # Instantiate the result of combination and free the two ingredient items func _combine(other_body: Node3D, result: PackedScene) -> void: - print("CombinableItem _combine: combining %s + %s into %s" % [_food_item.id, Helper.find_food_item(other_body).id, result.resource_path]) + SweetLogger.debug("combining {0} + {1} into {2}", [_food_item.id, Helper.find_food_item(other_body).id, result.resource_path], "combinable_item.gd", "_combine") # Get Snapzone var snap_zone := _pickable.get_picked_up_by() diff --git a/Prefabs/despawning_item.gd b/Prefabs/despawning_item.gd index c24100c..ba1289b 100644 --- a/Prefabs/despawning_item.gd +++ b/Prefabs/despawning_item.gd @@ -41,7 +41,7 @@ func _process(delta: float) -> void: # Count down to zero and despawn _time_left -= delta if _time_left <= 0: - print("DespawningItem despawning!" , get_parent()) + SweetLogger.debug("despawning {0}", [get_parent()], "despawning_item.gd", "_process") NetworkManager.despawn_item(get_parent()) # Stop counting: despawn_item() only queues the free, so without this we # keep re-reporting the same item every frame until it actually goes. diff --git a/Prefabs/kitchen_instantiator.gd b/Prefabs/kitchen_instantiator.gd index c97c141..fceeca3 100644 --- a/Prefabs/kitchen_instantiator.gd +++ b/Prefabs/kitchen_instantiator.gd @@ -9,10 +9,10 @@ func _ready() -> void: if not kitchen_scene: push_error("StationSpawner missing kitchen_scene") - print("Kitchen init") + SweetLogger.debug("initializing", [], "kitchen_instantiator.gd", "_ready") if NetworkManager.owns_world(): - print("Kitchen init is_server") + SweetLogger.debug("initializing on server", [], "kitchen_instantiator.gd", "_ready") # Later we will do procedural generation here. # For now we just load a scene. NetworkManager.call_deferred("spawn_item", kitchen_scene.resource_path, transform) diff --git a/Scenes/day_controller.gd b/Scenes/day_controller.gd index c48d7a7..20e6e6a 100644 --- a/Scenes/day_controller.gd +++ b/Scenes/day_controller.gd @@ -30,14 +30,14 @@ func _reset_values() -> void: func start_next_day() -> void: - print("DayController: start_next_day") + SweetLogger.info("starting next day", [], "day_controller.gd", "start_next_day") _reset_values() GameManager.set_customers_per_day(GameManager.customers_per_day + GameManager.customers_count_increase_per_day) GameManager.set_day_number(GameManager.day_number + 1) func finish_current_day() -> void: - print("DayController: finish_current_day") + SweetLogger.info("finishing current day", [], "day_controller.gd", "finish_current_day") _reset_values() @@ -50,9 +50,9 @@ func _process(delta: float) -> void: #print("DayController: customers_at_this_time: ", customers_at_this_time) if customers_spawned < customers_at_this_time: customers_spawned += 1 - print("DayController: spawning customer") + SweetLogger.debug("spawning customer", [], "day_controller.gd", "_process") Signals.request_customer_spawn.emit() # If day complete if GameManager.customers_per_day == customers_served and customers_spawned == GameManager.customers_per_day: - print("DayController: Day complete") + SweetLogger.info("day complete", [], "day_controller.gd", "_process") finish_current_day() diff --git a/Scenes/queue_controller.gd b/Scenes/queue_controller.gd index 3af115f..5fe1d66 100644 --- a/Scenes/queue_controller.gd +++ b/Scenes/queue_controller.gd @@ -32,7 +32,7 @@ func spawn_customer() -> void: func _rebuild_table_list() -> void: _tables.clear() _tables.append_array(get_tree().get_nodes_in_group("table")) - print("QueueController _rebuild_table_list complete: ", _tables) + SweetLogger.debug("_rebuild_table_list complete: {0}", [_tables], "queue_controller.gd", "_rebuild_table_list") func _try_to_assign_customers() -> void: diff --git a/Scenes/tile_map_layer.gd b/Scenes/tile_map_layer.gd index 7f9d3cd..d2ac5d9 100644 --- a/Scenes/tile_map_layer.gd +++ b/Scenes/tile_map_layer.gd @@ -114,14 +114,14 @@ func get_next(size, walls): var offset = [-1,-1] walls.shuffle() - print(size) + SweetLogger.debug("get_next size: {0}", [size], "tile_map_layer.gd", "get_next") for wall in walls: - print(wall) + SweetLogger.debug("get_next wall: {0}", [wall], "tile_map_layer.gd", "get_next") if wall["der"][1] == 0: - print("horisontal") + SweetLogger.debug("get_next horizontal wall", [], "tile_map_layer.gd", "get_next") if size[0]wall["pos"][0]+wall["len"]-3:offset[0] = wall["len"]-(3+size[0]) elif size[0]<=wall["len"]-3: - print("3 less needs to be on a corner") + SweetLogger.debug("TileMapLayer get_next 3 less needs to be on a corner", [], "tile_map_layer.gd", "get_next") if wall["der"][0] == 1:offset[1] = wall["pos"][1] else: offset[1] = wall["pos"][1]-size[1] if randi_range(0, 1):offset[0]=wall["pos"][0]+wall["len"]-size[0] else:offset[0] = wall["pos"][0] else: - print("virtical") + SweetLogger.debug("get_next vertical wall", [], "tile_map_layer.gd", "get_next") if size[1]wall["len"]-3:offset[1] = wall["len"]-(3+size[1]) elif size[1]<=wall["len"]-3: - print("3 less needs to be on a corner") + SweetLogger.debug("TileMapLayer get_next 3 less needs to be on a corner", [], "tile_map_layer.gd", "get_next") if wall["der"][1] == 1:offset[0] = wall["pos"][0] else: offset[0] = wall["pos"][0]-size[0] - print(offset) + SweetLogger.debug("get_next offset: {0}", [offset], "tile_map_layer.gd", "get_next") if randi() % 2:offset[1]=wall["pos"][1]+wall["len"]-size[1] else:offset[1] = wall["pos"][1] @@ -165,7 +165,7 @@ func get_next(size, walls): func draw_room(Size, offset=Vector2i(0, 0)): var walls = [] offset = Vector2i(offset[0], offset[1]) - print("draw: ", Size, " offset: ", offset) + SweetLogger.debug("draw_room size: {0} offset: {1}", [Size, offset], "tile_map_layer.gd", "draw_room") for i in range(Size[0]): tile_map.set_cell(Vector2i(i+offset[0],offset[1]), 0, Vector2i(1,1)) diff --git a/Stations/counter.gd b/Stations/counter.gd index 8c24c76..c2c963b 100644 --- a/Stations/counter.gd +++ b/Stations/counter.gd @@ -47,7 +47,7 @@ func _set_result(value: String) -> void: if not process_result.is_empty(): knife.visible = true knife.enabled = true - print("Counter: chopping recipe set: ", process_result) + SweetLogger.debug("chopping recipe set: {0}", [process_result], "counter.gd", "_set_result") else: _hide_all_tools() @@ -71,7 +71,7 @@ func _refresh_progress_bar() -> void: # Add work from gesture area (knife hits). This increments the chopping progress. func add_work(work: float) -> void: - print("Counter add_work: ", work) + SweetLogger.debug("add_work: {0}", [work], "counter.gd", "add_work") # Only the world owner should drive the authoritative state. Guarding is # handled by higher-level NetworkManager logic elsewhere, mirror hob's # convert_held_to_item which checks ownership before spawning. @@ -82,16 +82,16 @@ func add_work(work: float) -> void: audio.play() # If we've reached the required time, convert the held item if process_result != "" and process_result_work > 0 and work_progress >= process_result_work: - print("Counter: chopping complete, converting item to: ", process_result) + SweetLogger.debug("chopping complete, converting item to: {0}", [process_result], "counter.gd", "add_work") work_progress = 0 convert_held_to_item(process_result) func _on_gesture_area_body_entered(body: Node3D) -> void: - print("Counter: gesture area entered: ", body) + SweetLogger.debug("gesture area entered: {0}", [body], "counter.gd", "_on_gesture_area_body_entered") if body.is_in_group("chopping_tool"): if process_result == "": - print("Counter: knife entered but nothing to chop") + SweetLogger.debug("knife entered but nothing to chop", [], "counter.gd", "_on_gesture_area_body_entered") return var speed := 0.0 @@ -101,31 +101,31 @@ func _on_gesture_area_body_entered(body: Node3D) -> void: speed = body.velocity.length() if speed < chop_min_speed: - print("Counter: knife too slow for chopping: ", speed) + SweetLogger.debug("knife too slow for chopping: {0}", [speed], "counter.gd", "_on_gesture_area_body_entered") return add_work(chop_work_steps) func _on_object_picked_up(_item: Variant) -> void: - print("Counter: object picked up: ", _item) + SweetLogger.debug("object picked up: {0}", [_item], "counter.gd", "_on_object_picked_up") var food_item = Helper.find_food_item(_item) if not food_item: - print("Counter: held object is not a FoodItem") + SweetLogger.debug("held object is not a FoodItem", [], "counter.gd", "_on_object_picked_up") return var result = RecipeManager.get_chopping_result(food_item.id) if not result: - print("Counter: held a FoodItem that is not choppable, id: %s process_result: %s" % [food_item.id, result]) + SweetLogger.debug("held a FoodItem that is not choppable, id: {0} process_result: {1}", [food_item.id, result], "counter.gd", "_on_object_picked_up") return process_result = result process_result_work = RecipeManager.get_chopping_work(food_item.id) - print("Counter: set process_result ", process_result, " work: ", process_result_work) + SweetLogger.debug("set process_result {0} work: {1}", [process_result, process_result_work], "counter.gd", "_on_object_picked_up") func _on_object_dropped(_item: Variant) -> void: - print("Counter: object drop ") + SweetLogger.debug("object drop", [], "counter.gd", "_on_object_dropped") work_progress = 0 process_result = "" process_result_work = 0 @@ -135,7 +135,7 @@ func _on_object_dropped(_item: Variant) -> void: func convert_held_to_item(_item: String) -> void: if not NetworkManager.owns_world(): return - print("Counter converting ", _item) + SweetLogger.debug("converting {0}", [_item], "counter.gd", "convert_held_to_item") var old_pickable = snap_zone.picked_up_object if not old_pickable: @@ -145,7 +145,7 @@ func convert_held_to_item(_item: String) -> void: var original_transform = old_pickable.global_transform var new_scene_instance = NetworkManager.spawn_item(RecipeManager.get_item_scene(_item).resource_path, original_transform) - print("Counter freeing old_pickable ", old_pickable) + SweetLogger.debug("freeing old_pickable {0}", [old_pickable], "counter.gd", "convert_held_to_item") snap_zone.drop_object() NetworkManager.despawn_item(old_pickable) snap_zone.pick_up_object(new_scene_instance) diff --git a/Stations/dirt_station.gd b/Stations/dirt_station.gd index 1606464..066782e 100644 --- a/Stations/dirt_station.gd +++ b/Stations/dirt_station.gd @@ -11,7 +11,7 @@ func _makeDirty(item) -> void: return var plate: PlateController = item.get_node_or_null("PlateController") as PlateController if not plate: - print("Dirt Station: held object is not a Plate") + SweetLogger.debug("held object is not a Plate", [], "dirt_station.gd", "_makeDirty") return if not plate.is_dirty: plate.is_dirty = true diff --git a/Stations/hob.gd b/Stations/hob.gd index ac2b93a..b3e96c4 100644 --- a/Stations/hob.gd +++ b/Stations/hob.gd @@ -67,26 +67,26 @@ func _refresh_display() -> void: progress_bar.override_fill_color(Color.RED if cooking_result == "charcoal" else Color.GREEN) func _on_object_picked_up(_item) -> void: - print("Hob: object picked up: ", _item) + SweetLogger.debug("object picked up: {0}", [_item], "hob.gd", "_on_object_picked_up") # Find the CookableItem in held object var _food_item = _item.get_node_or_null("FoodItem") as FoodItem if not _food_item: - print("Hob: held object is not a FoodItem") + SweetLogger.debug("held object is not a FoodItem", [], "hob.gd", "_on_object_picked_up") return var result = RecipeManager.get_cooking_result(_food_item.id) if not result: - print("Hob: held a FoodItem that is not cookable, id: %s result: %s" % [_food_item.id, result]) + SweetLogger.debug("held a FoodItem that is not cookable, id: {0} result: {1}", [_food_item.id, result], "hob.gd", "_on_object_picked_up") return cooking_result = result cooking_result_time = RecipeManager.get_cooking_time(_food_item.id) - print("Hob: set cooking_result ", cooking_result) + SweetLogger.debug("set cooking_result {0}", [cooking_result], "hob.gd", "_on_object_picked_up") # The setters above already refresh the display and start the flames. func _on_object_dropped(_item) -> void: - print("Hob: object drop ") + SweetLogger.debug("object drop", [], "hob.gd", "_on_object_dropped") time_cooked = 0 cooking_result = "" cooking_result_time = 0 @@ -95,7 +95,7 @@ func _on_object_dropped(_item) -> void: func convert_held_to_item(_item: String) -> void: if not NetworkManager.owns_world(): return - print("Hob converting ", _item) + SweetLogger.debug("converting {0}", [_item], "hob.gd", "convert_held_to_item") var old_pickable = snap_zone.picked_up_object if not old_pickable: @@ -108,7 +108,7 @@ func convert_held_to_item(_item: String) -> void: var new_scene_instance = NetworkManager.spawn_item(RecipeManager.get_item_scene(_item).resource_path, original_transform) # Drop and free the old item and pick up the new one - print("Hob freeing old_pickable ", old_pickable) + SweetLogger.debug("freeing old_pickable {0}", [old_pickable], "hob.gd", "convert_held_to_item") snap_zone.drop_object() NetworkManager.despawn_item(old_pickable) snap_zone.pick_up_object(new_scene_instance) diff --git a/Stations/item_dispenser.gd b/Stations/item_dispenser.gd index de32487..3590786 100644 --- a/Stations/item_dispenser.gd +++ b/Stations/item_dispenser.gd @@ -21,6 +21,6 @@ func _process(_delta: float) -> void: #return # if not snap_zone.picked_up_object: - print("Item dispenser is missing item, spawning new item") + SweetLogger.debug("missing item, spawning new item", [], "item_dispenser.gd", "_process") var new_item = NetworkManager.spawn_item(item_scene.resource_path, snap_zone.global_transform) snap_zone.pick_up_object(new_item) diff --git a/Stations/sink.gd b/Stations/sink.gd index f796d01..39e4b4a 100644 --- a/Stations/sink.gd +++ b/Stations/sink.gd @@ -59,7 +59,7 @@ func _refresh_progress_bar() -> void: func _on_object_picked_up(_item) -> void: - print("Sink: object picked up: ", _item) + SweetLogger.debug("object picked up: {0}", [_item], "sink.gd", "_on_object_picked_up") plate = _item.get_node_or_null("PlateController") as PlateController if plate: # The setter starts the effects and shows the bar, here and on clients. @@ -67,7 +67,7 @@ func _on_object_picked_up(_item) -> void: func _on_object_dropped(_item) -> void: - print("Sink: object drop ") + SweetLogger.debug("object drop", [], "sink.gd", "_on_object_dropped") _reset_sink() @@ -81,14 +81,14 @@ func complete_washing(): return plate.is_dirty = false _reset_sink() - print("Sink washing complete!") + SweetLogger.debug("washing complete!", [], "sink.gd", "complete_washing") func _process(delta: float) -> void: if is_washing: time_washed += wash_speed * delta _refresh_progress_bar() - print("Sink washing plate: ", time_washed) + SweetLogger.debug("washing plate: {0}", [time_washed], "sink.gd", "_process") if time_washed >= plate_wash_time: complete_washing() diff --git a/Stations/station_movement.gd b/Stations/station_movement.gd index 669aab7..2dac4bf 100644 --- a/Stations/station_movement.gd +++ b/Stations/station_movement.gd @@ -21,7 +21,7 @@ const GHOST_COLOR_INVALID: Color = Color(1, 0, 0, 0.35) func set_move_handle_enabled(enabled: bool) -> void: - print("StationMovement set_move_handle_enabled: ", enabled) + SweetLogger.debug("set_move_handle_enabled: {0}", [enabled], "station_movement.gd", "set_move_handle_enabled") move_handle.visible = enabled move_handle.enabled = enabled if enabled: @@ -32,7 +32,7 @@ func _on_game_state_changed(new_state: GameManager.GameState) -> void: set_move_handle_enabled(new_state == GameManager.GameState.BUILDING) func _on_station_bought(_instance: Node3D): - print("StationMovement _on_station_bought") + SweetLogger.info("_on_station_bought") if GameManager.game_state == GameManager.GameState.BUILDING: set_move_handle_enabled(true) @@ -93,9 +93,9 @@ func _set_ghost_color(color: Color) -> void: func _handle_pickup(_by: Node) -> void: - print("StationMovement handle pickup") + SweetLogger.info("handle pickup") if move_handle.get_picked_up_by() is XRToolsSnapZone: - print("StationMovement handle pickup by snap zone, dropping and resetting position") + SweetLogger.info("handle pickup by snap zone, dropping and resetting position") move_handle.drop() move_handle.global_position = station.global_position + Vector3(0, original_handle_y_pos, 0) move_handle.rotation = station.rotation @@ -115,7 +115,7 @@ func _handle_pickup(_by: Node) -> void: func _handle_drop(_by: Node) -> void: - print("StationMovement handle drop") + SweetLogger.info("handle drop") moving = false move_ghost.visible = false station.visible = true @@ -129,11 +129,11 @@ func _handle_drop(_by: Node) -> void: if is_valid: station.global_transform = move_ghost.global_transform move_handle.global_transform = move_ghost.global_transform.translated(Vector3(0, original_handle_y_pos, 0)) - print("StationMovement handle drop (local apply), station authority: ", station.get_multiplayer_authority(), " move_handle authority: ", move_handle.get_multiplayer_authority()) + SweetLogger.debug("handle drop (local apply), station authority: {0} move_handle authority: {1}", [station.get_multiplayer_authority(), move_handle.get_multiplayer_authority()], "station_movement.gd", "_handle_drop") else: station.global_transform = original_station_transform move_handle.global_transform = original_station_transform.translated(Vector3(0, original_handle_y_pos, 0)) - print("StationMovement handle drop (local reject), restoring original position") + SweetLogger.debug("handle drop (local reject), restoring original position", [], "station_movement.gd", "_handle_drop") func _process(_delta: float) -> void: if not moving: @@ -161,7 +161,7 @@ func _process(_delta: float) -> void: func _is_move_position_valid() -> bool: for body in move_ghost.get_overlapping_bodies(): - print("Overlapping body: ", body) + SweetLogger.debug("Overlapping body: {0}", [body], "station_movement.gd", "_is_move_position_valid") if body == move_handle: continue if body == station: @@ -193,7 +193,7 @@ func server_handle_drop(new_transform: Transform3D, client_thinks_valid: bool): server_update_move_ghost_transform.rpc(original_trans) server_update_handle_transform.rpc(original_trans.translated(Vector3(0, original_handle_y_pos, 0))) server_update_visibility.rpc(false, true) - print("StationMovement server_handle_drop: transform rejected (invalid)") + SweetLogger.debug("server_handle_drop: transform rejected (invalid)", [], "station_movement.gd", "server_handle_drop") return server_update_station_transform.rpc(new_transform) @@ -201,32 +201,32 @@ func server_handle_drop(new_transform: Transform3D, client_thinks_valid: bool): server_update_handle_transform.rpc(new_transform.translated(Vector3(0, original_handle_y_pos, 0))) server_update_visibility.rpc(false, true) - print("StationMovement server_handle_drop: transform applied") + SweetLogger.debug("server_handle_drop: transform applied", [], "station_movement.gd", "server_handle_drop") @rpc("any_peer", "call_local", "reliable") # Server updates clients func server_update_station_transform(new_transform: Transform3D) -> void: - print("StationMovement server_update_station_transform") + SweetLogger.debug("server_update_station_transform", [], "station_movement.gd", "server_update_station_transform") station.global_transform = new_transform original_station_transform = new_transform @rpc("any_peer", "call_local", "reliable") # Server updates clients func server_update_handle_transform(new_transform: Transform3D) -> void: - print("StationMovement server_update_handle_transform") + SweetLogger.debug("server_update_handle_transform", [], "station_movement.gd", "server_update_handle_transform") move_handle.global_transform = new_transform @rpc("any_peer", "call_local", "reliable") func server_update_visibility(ghost_visible: bool, station_visible: bool) -> void: - print("StationMovement server_update_visibility") + SweetLogger.debug("server_update_visibility", [], "station_movement.gd", "server_update_visibility") move_ghost.visible = ghost_visible station.visible = station_visible @rpc("any_peer", "call_local", "unreliable") func server_update_move_ghost_transform(new_transform: Transform3D, new_color: Color = Color.YELLOW) -> void: - print("StationMovement server_update_move_ghost_transform") + SweetLogger.debug("server_update_move_ghost_transform", [], "station_movement.gd", "server_update_move_ghost_transform") move_ghost.global_transform = new_transform _set_ghost_color(new_color) diff --git a/Stations/table.gd b/Stations/table.gd index c895300..6139914 100644 --- a/Stations/table.gd +++ b/Stations/table.gd @@ -47,7 +47,7 @@ var _players_count: int = 0 func place_order() -> void: - print("Table place_order()") + SweetLogger.debug("place_order()", [], "table.gd", "place_order") var new_orders: Array[String] = _unsatisfied_orders.duplicate() # for _i in range(0, randi_range(1, 2)): # new_orders.append(GameManager.get_random_meal()) @@ -59,7 +59,7 @@ func place_order() -> void: func absorb_items(): - print("Table: absorb_items()") + SweetLogger.debug("absorb_items()", [], "table.gd", "absorb_items") for snap_zone_node in snap_zones: var held_object = snap_zone_node.picked_up_object if not held_object: @@ -69,7 +69,7 @@ func absorb_items(): func satisfyAllOrders() -> void: - print("Table: satisfyAllOrders()") + SweetLogger.debug("satisfyAllOrders()", [], "table.gd", "satisfyAllOrders") _unsatisfied_orders.clear() _original_orders.clear() clearAllFood() @@ -77,7 +77,7 @@ func satisfyAllOrders() -> void: func clearAllFood() -> void: - print("Table: clearAllFood()") + SweetLogger.debug("clearAllFood()", [], "table.gd", "clearAllFood") for zone in snap_zones: var held_object = zone.picked_up_object if not held_object: @@ -98,7 +98,7 @@ func clearAllFood() -> void: # Group called from Queue when trying to assign customers to tables func try_consume_customer() -> bool: if _state == TableState.EMPTY: - print("Table try_consume_customer, consumed a customer") + SweetLogger.debug("try_consume_customer, consumed a customer", [], "table.gd", "try_consume_customer") _state_end(TableState.EMPTY) return true return false @@ -137,14 +137,14 @@ func _ready() -> void: func _on_object_picked_up(_item) -> void: - print("Table: object picked up: ", _item) + SweetLogger.debug("object picked up: {0}", [_item], "table.gd", "_on_object_picked_up") if _state == TableState.EATING: return _absorb_item_if_correct(_item) func _on_object_dropped(_item) -> void: - print("Table: object dropped, item: ", _item) + SweetLogger.debug("object dropped, item: {0}", [_item], "table.gd", "_on_object_dropped") # If then player picks up a food_item (side) the table has already registerd, unregister var food_item: FoodItem = Helper.find_food_item(_item) if food_item and food_item.type == FoodItem.Type.SIDE: @@ -161,12 +161,12 @@ func _on_object_dropped(_item) -> void: # There is no on_stay signal, we have to track player with bool func _on_player_enter(_body): _players_count += 1 - print("Table _on_player_enter() pleryers_count: ", _players_count) + SweetLogger.debug("_on_player_enter() players_count: {0}", [_players_count], "table.gd", "_on_player_enter") func _on_player_exit(_body): _players_count -= 1 - print("Table _on_player_exit() pleryers_count: ", _players_count) + SweetLogger.debug("_on_player_exit() players_count: {0}", [_players_count], "table.gd", "_on_player_exit") func _place_order_if_player(): @@ -183,20 +183,20 @@ func _place_order_if_player(): func _get_plate_controller_from_item(_item: Node) -> PlateController: if not _item: - print("_item is null") + SweetLogger.debug("_item is null", [], "table.gd", "_get_plate_controller_from_item") return null for child in _item.get_children(): if child is PlateController: - print("found child") + SweetLogger.debug("found child", [], "table.gd", "_get_plate_controller_from_item") return child - print("no match") + SweetLogger.debug("no match", [], "table.gd", "_get_plate_controller_from_item") return null func _absorb_item_if_correct(_item: Node) -> void: - print("Table _absorb_item_if_correct, item: ", _item) + SweetLogger.debug("_absorb_item_if_correct, item: {0}", [_item], "table.gd", "_absorb_item_if_correct") if not _item: return if not (_state == TableState.WAITING_PRIMARY or _state == TableState.WAITING_FRIEND): @@ -204,14 +204,14 @@ func _absorb_item_if_correct(_item: Node) -> void: # Plate: Get plate controller in child of _item (hopefully a plate XRpickable) var plate_controller = _get_plate_controller_from_item(_item) - print("Table _absorb_item_if_correct plate_controller ref: ", plate_controller) + SweetLogger.debug("_absorb_item_if_correct plate_controller ref: {0}", [plate_controller], "table.gd", "_absorb_item_if_correct") _item.print_tree_pretty() if plate_controller: # Absorm items from the plate we want for food_item: FoodItem in plate_controller.container.contained_items: # TOOD: handle registering the meal again when a side is added to the plate if food_item.id in _unsatisfied_orders and not food_item.is_absorbed: - print("Table: _absorb_item_if_correct held a plate with FoodItem that is in unsatisfied orders, removing it") + SweetLogger.debug("_absorb_item_if_correct held a plate with FoodItem that is in unsatisfied orders, removing it", [], "table.gd", "_absorb_item_if_correct") (plate_controller.get_parent() as XRToolsPickable).get_picked_up_by().enabled = false # Lock meal that is deliverd _unsatisfied_orders.erase(food_item.id) food_item.is_absorbed = true @@ -221,17 +221,17 @@ func _absorb_item_if_correct(_item: Node) -> void: # Side pickable item, no container var food_item: FoodItem = Helper.find_food_item(_item) if food_item and food_item.type == FoodItem.Type.SIDE: - print("Table: _absorb_item_if_correct held a side that is in unsatisfied orders, removing it") + SweetLogger.debug("_absorb_item_if_correct held a side that is in unsatisfied orders, removing it", [], "table.gd", "_absorb_item_if_correct") # Do not lock snap zone here. Problem if table want many meals, but to many sides have filled up slots, so can't place plates. _unsatisfied_orders.erase(food_item.id) _update_state_from_orders() return - print("Table: absorb_item_if_correct() held object is not a Plate or Side") + SweetLogger.debug("absorb_item_if_correct() held object is not a Plate or Side", [], "table.gd", "_absorb_item_if_correct") func _update_state_from_orders(): - print("Table _update_state_from_orders: unsatisfied_orders: ", _unsatisfied_orders) + SweetLogger.debug("_update_state_from_orders: unsatisfied_orders: {0}", [_unsatisfied_orders], "table.gd", "_update_state_from_orders") if _unsatisfied_orders.size() > 0 and _state != TableState.EATING: _set_state(TableState.WAITING_FRIEND) @@ -254,7 +254,7 @@ func _collect_money_from_food(): elif food_item: GameManager.set_money(GameManager.money + food_item.sell_value) - print("Table _collect_money_from_food(), money: ", GameManager.money) + SweetLogger.debug("_collect_money_from_food(), money: {0}", [GameManager.money], "table.gd", "_collect_money_from_food") func _set_snap_zones_enabled(value: bool) -> void: @@ -265,7 +265,7 @@ func _set_snap_zones_enabled(value: bool) -> void: ## Server-only state transition: sets the new state's timer and assigns ## _state (whose setter refreshes the display on every peer). func _set_state(newState: TableState) -> void: - print("Table State START: ", TableState.keys()[newState]) + SweetLogger.debug("State START: {0}", [TableState.keys()[newState]], "table.gd", "_set_state") match newState: TableState.IDLE: @@ -307,7 +307,7 @@ func _set_state(newState: TableState) -> void: # When state timer is finished, do this stuff before moving to next state func _state_end(oldState: TableState): - print("Table State END : ", TableState.keys()[oldState]) + SweetLogger.debug("State END: {0}", [TableState.keys()[oldState]], "table.gd", "_state_end") match oldState: TableState.EMPTY: customers.visible = true diff --git a/UI/shop_station_button.gd b/UI/shop_station_button.gd index 600f690..eab38d4 100644 --- a/UI/shop_station_button.gd +++ b/UI/shop_station_button.gd @@ -17,12 +17,12 @@ func _ready() -> void: func _on_button_pressed() -> void: - print("ShopStationButton buy ", station_name) + SweetLogger.debug("buy {0}", [station_name], "shop_station_button.gd", "_on_button_pressed") _buy_station() func _buy_station() -> void: - print("ShopStationButton _buy_station:, ", "cost=", cost, " current money=", GameManager.money) + SweetLogger.debug("_buy_station: cost={0} current money={1}", [cost, GameManager.money], "shop_station_button.gd", "_buy_station") GameManager.set_money(GameManager.money - cost) var transform = Helper.get_snapped_transform(XRHelpers.get_xr_origin(self).get_node_or_null("PlayerBody")) var forward: Vector3 = -transform.basis.z.normalized() diff --git a/UI/shop_ui.gd b/UI/shop_ui.gd index d1d0e2d..3ac529f 100644 --- a/UI/shop_ui.gd +++ b/UI/shop_ui.gd @@ -32,9 +32,9 @@ func _process(_delta: float) -> void: func toggle_shop(): if GameManager.game_state == GameManager.GameState.BUILDING: - print("Shop UI toggle shop") + SweetLogger.debug("toggle shop", [], "shop_ui.gd", "toggle_shop") enabled = !enabled - print ("Shop UI _process: money=", GameManager.money, " label text=", money_label.text) + SweetLogger.debug("_process: money={0} label text={1}", [GameManager.money, money_label.text], "shop_ui.gd", "toggle_shop") @@ -54,11 +54,11 @@ func _set_poke_enabled_for_controller(controller_node: XRController3D, value: bo var poke_node = Helper.find_first_child_of_type(controller_node, XRToolsPoke) if poke_node: - print("Shop UI _set_poke_enabled_for_controller: ", poke_node.get_path(), " poke enabled: ", value) + SweetLogger.debug("_set_poke_enabled_for_controller: {0} poke enabled: {1}", [poke_node.get_path(), value], "shop_ui.gd", "_set_poke_enabled_for_controller") poke_node.enabled = value poke_node.visible = value else: - print("Shop UI _set_poke_enabled_for_controller: ", controller_node.name, " poke not found") + SweetLogger.debug("_set_poke_enabled_for_controller: {0} poke not found", [controller_node.name], "shop_ui.gd", "_set_poke_enabled_for_controller") # For some reason, this is called every frame the button is down. So we need our own timer. func _on_controller_button_pressed(button_name: String) -> void: @@ -80,7 +80,7 @@ func _on_other_controller_button_pressed(button_name: String) -> void: func _on_station_bought(_instance) -> void: enabled = false money_label.text = str(GameManager.money) + "$" - print("Shop UI _on_station_bought: new money: ", GameManager.money) + SweetLogger.debug("_on_station_bought: new money: {0}", [GameManager.money], "shop_ui.gd", "_on_station_bought") func detect_hand_from_xr_ancestor() -> void: @@ -96,4 +96,4 @@ func detect_hand_from_xr_ancestor() -> void: other_controller = right_controller elif controller == right_controller: other_controller = left_controller - print("Shop UI detected hand: ", controller.get_tracker_hand()) + SweetLogger.debug("detected hand: {0}", [controller.get_tracker_hand()], "shop_ui.gd", "detect_hand_from_xr_ancestor") diff --git a/addons/godot-xr-tools/materials/highlight.tres b/addons/godot-xr-tools/materials/highlight.tres index 0480f11..6213abb 100644 --- a/addons/godot-xr-tools/materials/highlight.tres +++ b/addons/godot-xr-tools/materials/highlight.tres @@ -1,4 +1,4 @@ -[gd_resource type="ShaderMaterial" load_steps=7 format=3 uid="uid://dyuaw57o8y3i"] +[gd_resource type="ShaderMaterial" format=3 uid="uid://dyuaw57o8y3i"] [sub_resource type="VisualShaderNodeColorParameter" id="VisualShaderNodeColorParameter_nl6jr"] parameter_name = "Color" @@ -16,42 +16,6 @@ constant = 0.1 operator = 2 [sub_resource type="VisualShader" id="VisualShader_wb0u4"] -code = "shader_type spatial; -render_mode blend_mix, depth_draw_opaque, cull_back, diffuse_lambert, specular_schlick_ggx; - -uniform vec4 Color : source_color; - - - -void fragment() { -// ColorParameter:2 - vec4 n_out2p0 = Color; - - -// FloatConstant:4 - float n_out4p0 = 0.100000; - - -// VectorOp:3 - vec3 n_out3p0 = vec3(n_out2p0.xyz) * vec3(n_out4p0); - - -// Fresnel:5 - float n_in5p3 = 1.00000; - float n_out5p0 = pow(1.0 - clamp(dot(NORMAL, VIEW), 0.0, 1.0), n_in5p3); - - -// VectorOp:6 - vec3 n_out6p0 = vec3(n_out2p0.xyz) * vec3(n_out5p0); - - -// Output:0 - ALBEDO = n_out3p0; - EMISSION = n_out6p0; - - -} -" nodes/fragment/0/position = Vector2(660, 60) nodes/fragment/2/node = SubResource("VisualShaderNodeColorParameter_nl6jr") nodes/fragment/2/position = Vector2(40, 40) diff --git a/addons/sweet-logger/LICENSE b/addons/sweet-logger/LICENSE new file mode 100644 index 0000000..3ca32e8 --- /dev/null +++ b/addons/sweet-logger/LICENSE @@ -0,0 +1,21 @@ +MIT License + +Copyright (c) 2026 sweetpea + +Permission is hereby granted, free of charge, to any person obtaining a copy +of this software and associated documentation files (the "Software"), to deal +in the Software without restriction, including without limitation the rights +to use, copy, modify, merge, publish, distribute, sublicense, and/or sell +copies of the Software, and to permit persons to whom the Software is +furnished to do so, subject to the following conditions: + +The above copyright notice and this permission notice shall be included in all +copies or substantial portions of the Software. + +THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, +FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE +AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER +LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, +OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE +SOFTWARE. diff --git a/addons/sweet-logger/README.md b/addons/sweet-logger/README.md new file mode 100644 index 0000000..b40388c --- /dev/null +++ b/addons/sweet-logger/README.md @@ -0,0 +1,105 @@ +## hey - sweet logger you got there! +--- + +A Godot 4 addon that makes reading logs and debugging sane when you run multiple game instances at once. + +It's meant as a drop-in/stand-in for `print()`: same habit of sprinkling logs through your systems, but every line carries more context - which peer printed it, what kind of log it is, which script and function it came from. That makes it much easier to follow what each client (and the server) is doing when several instances share one console. + +When you're testing multiplayer locally (host + clients in separate run instances), the editor console fills with interleaved output from every peer. Sweet Logger formats each line the same way so you can tell at a glance **what kind of log it is**, **which peer it came from**, **when it happened**, and **which script/function** produced it. + +--- + +## Features + +- **Peer-aware labels** - tags each line as `SERVER`, a client peer ID, or `DISCONNECTED` +- **Color-coded peers** - consistent colors per peer so interleaved console output is easy to scan +- **Log levels** - `log`, `info`, `warning`, `error`, `debug` with distinct colors +- **Script context** - optional script and function name columns +- **Local timestamps** - `mm:ss:ms` by default (optional hours) +- **Rich console output** - uses `print_rich` with aligned columns + +--- + +## Installation + +### From the Godot Asset Library + +1. In Godot, open the **AssetLib** tab. +2. Search for **Sweet Logger** and download it. +3. Open **Project → Project Settings → Plugins** and enable **Sweet Logger**. +4. The plugin registers a `SweetLogger` autoload automatically. + +### Manual + +1. Copy the `addons/sweet-logger` folder into your project's `addons/` directory. +2. In Godot, open **Project → Project Settings → Plugins** and enable **Sweet Logger**. +3. The plugin registers a `SweetLogger` autoload automatically. + +--- + +## Usage + +Call the autoload from anywhere: + +```gdscript +SweetLogger.info("Player joined", [], "lobby.gd", "on_peer_connected") +SweetLogger.warning("High latency: {0}ms", [rtt], "net.gd", "_process") +SweetLogger.error("RPC failed", [], "sync.gd", "apply_state") +SweetLogger.debug("Tick {0}", [tick], "game.gd", "_physics_process") +SweetLogger.log("Hello from peer") +``` + +### Message formatting + +Pass optional args and use `{0}`, `{1}`, … placeholders: + +```gdscript +SweetLogger.info("Spawned {0} at {1}", [entity_name, position], "spawner.gd", "spawn") +``` + +### API + +| Method | Level | +| --------------------------------------------------------------------- | ------- | +| `SweetLogger.log(message, args=[], script_name="", function_name="")` | General | +| `SweetLogger.info(...)` | Info | +| `SweetLogger.warning(...)` | Warning | +| `SweetLogger.error(...)` | Error | +| `SweetLogger.debug(...)` | Debug | + + +All methods share the same signature: message, optional format args, optional script name, optional function name. + +## Configuration + +On the `SweetLogger` autoload (or in the inspector when selected): + + +| Export | Default | Description | +| ---------------------- | ------- | --------------------------------------- | +| `SHOW_SCRIPT_NAME` | `true` | Include the script name column | +| `SHOW_FUNCTION_NAME` | `true` | Include the function name column | +| `SHOW_TIMESTAMP_HOURS` | `false` | Use `hh:mm:ss:ms` instead of `mm:ss:ms` | + +## Log line layout + +Each line is roughly: + +``` +[LEVEL][timestamp][PEER][script::function] message +``` + +- **LEVEL** - color by type (info blue, warning yellow, error red, etc.) +- **timestamp** - local time for correlating events across instances +- **PEER** - `SERVER`, numeric client ID, or `DISCONNECTED`, each with a stable color +- **script::function** - where the log was emitted (when you pass those args) + +--- + +## Why this exists + +Godot's "Run Multiple Instances" is great for testing multiplayer games on one machine, but plain `print()` output from every peer lands in one console with no clear ownership. Sweet Logger keeps a fixed column layout and peer coloring so you can follow one client's story (or the server's) without losing the others. + +## License + +MIT - see [LICENSE](addons/sweet-logger/LICENSE). \ No newline at end of file diff --git a/addons/sweet-logger/plugin.cfg b/addons/sweet-logger/plugin.cfg new file mode 100644 index 0000000..fed2812 --- /dev/null +++ b/addons/sweet-logger/plugin.cfg @@ -0,0 +1,7 @@ +[plugin] + +name="Sweet Logger" +description="Rich console logging with peer-aware prefixes. Registers the SweetLogger autoload." +author="sweetpea" +version="1.0.0" +script="plugin.gd" diff --git a/addons/sweet-logger/plugin.gd b/addons/sweet-logger/plugin.gd new file mode 100644 index 0000000..45b73ad --- /dev/null +++ b/addons/sweet-logger/plugin.gd @@ -0,0 +1,13 @@ +@tool +extends EditorPlugin + +const AUTOLOAD_NAME := "SweetLogger" +const AUTOLOAD_PATH := "res://addons/sweet-logger/sweet_logger.gd" + +func _enter_tree() -> void: + var key := "autoload/%s" % AUTOLOAD_NAME + if not ProjectSettings.has_setting(key): + add_autoload_singleton(AUTOLOAD_NAME, AUTOLOAD_PATH) + +func _exit_tree() -> void: + remove_autoload_singleton(AUTOLOAD_NAME) diff --git a/addons/sweet-logger/plugin.gd.uid b/addons/sweet-logger/plugin.gd.uid new file mode 100644 index 0000000..b04a701 --- /dev/null +++ b/addons/sweet-logger/plugin.gd.uid @@ -0,0 +1 @@ +uid://cm16x8s6cox4w diff --git a/addons/sweet-logger/sweet_logger.gd b/addons/sweet-logger/sweet_logger.gd new file mode 100644 index 0000000..5b75b33 --- /dev/null +++ b/addons/sweet-logger/sweet_logger.gd @@ -0,0 +1,289 @@ +extends Node + +## Global Logger singleton for consistent logging across the game. +## All logs are prefixed with [peer_id]: to identify which instance is logging. +## Uses print_rich with colorized backgrounds for log type, local time, peer IDs, and script context. + +# COLORS +#===================================================================================# +## Log type configuration with background color, message background color, and contrast text color +const LOG_TYPES = { + "log": { + "bg_color": "#2d2d2d", + "message_bg_color": "#3d3d3d", + "text_color": "#ffffff" + }, + "info": { + "bg_color": "#2563eb", + "message_bg_color": "#3b82f6", + "text_color": "#ffffff" + }, + "warning": { + "bg_color": "#fbbf24", + "message_bg_color": "#fcd34d", + "text_color": "#ffffff" + }, + "error": { + "bg_color": "#dc2626", + "message_bg_color": "#ef4444", + "text_color": "#ffffff" + }, + "debug": { + "bg_color": "#7c3aed", + "message_bg_color": "#a78bfa", + "text_color": "#ffffff" + } +} + +## Contrast text color that works on all backgrounds +const CONTRAST_TEXT = "#ffffff" + +## Predefined colors for special peer IDs +const SPECIAL_PEER_COLORS = { + "SERVER": { + "bg_color": "#7c3aed", + "text_color": "#ffffff" + }, + "DISCONNECTED": { + "bg_color": "#6b7280", + "text_color": "#ffffff" + } +} + +const PEER_COLOR_PALETTE = [ + {"bg_color": "#10b981", "text_color": "#ffffff"}, # emerald green + {"bg_color": "#06b6d4", "text_color": "#ffffff"}, # cyan + {"bg_color": "#ec4899", "text_color": "#ffffff"}, # fuchsia pink + {"bg_color": "#f97316", "text_color": "#ffffff"}, # orange + {"bg_color": "#14b8a6", "text_color": "#ffffff"}, # teal + {"bg_color": "#84cc16", "text_color": "#000000"}, # lime green + {"bg_color": "#0ea5e9", "text_color": "#ffffff"}, # sky blue + {"bg_color": "#22c55e", "text_color": "#ffffff"}, # green + {"bg_color": "#e11d48", "text_color": "#ffffff"}, # rose red + {"bg_color": "#d946ef", "text_color": "#ffffff"}, # magenta +] + +## Background color for the entire log line +const LOG_LINE_BG_COLOR = "#1a1a1a" + +## Background color for the script/function name column +const SCRIPT_FUNCTION_BG_COLOR = "#4a5a6a" + +## Background color for the local time column (between log type and peer id) +const TIMESTAMP_BG_COLOR = "#1e3a5f" +#===================================================================================# + +# WIDTHS +#===================================================================================# +## Column widths for alignment (in characters) +const PEER_ID_COLUMN_WIDTH = 10 +const LOG_TYPE_COLUMN_WIDTH = 8 +## Default mm:ss:ms; with SHOW_TIMESTAMP_HOURS, hh:mm:ss:ms +const TIMESTAMP_COLUMN_WIDTH_MMSSMS = 9 +const TIMESTAMP_COLUMN_WIDTH_HHMMSSMS = 12 +const SCRIPT_FUNCTION_COLUMN_WIDTH = 40 +#===================================================================================# + +# CONFIGURATION +#===================================================================================# +## Cache for peer ID colors to ensure consistency +var _peer_color_cache: Dictionary = {} + +## Enable/disable showing script name and function name in logs +@export var SHOW_SCRIPT_NAME = true +@export var SHOW_FUNCTION_NAME = true +## When false (default), timestamp is local mm:ss:ms. When true, local hh:mm:ss:ms (wider column). +@export var SHOW_TIMESTAMP_HOURS = false +#===================================================================================# + +# GETTERS +#===================================================================================# +func _get_peer_id() -> String: + """Get the current peer ID, or return a default identifier if not connected.""" + if multiplayer == null: + return "DISCONNECTED" + + # Check if we're the server (server always has ID 1, but we check is_server() for clarity) + if multiplayer.is_server(): + return "SERVER" + + # Get the unique ID (will be 1 for server, or random positive int > 1 for clients) + var peer_id = multiplayer.get_unique_id() + return str(peer_id) + +func _get_peer_color_config(peer_id_str: String) -> Dictionary: + """Get color configuration for a peer ID string.""" + # Check special peer IDs first + if SPECIAL_PEER_COLORS.has(peer_id_str): + return SPECIAL_PEER_COLORS[peer_id_str] + + # Check cache + if _peer_color_cache.has(peer_id_str): + return _peer_color_cache[peer_id_str] + + # Generate consistent color based on peer ID + # Try to parse the peer_id_str as a number + var peer_id_num = peer_id_str.to_int() + var color_index: int + if peer_id_num > 0: + color_index = peer_id_num % PEER_COLOR_PALETTE.size() + else: + # If parsing fails, use hash of the string for consistency + var hash_value = peer_id_str.hash() + color_index = abs(hash_value) % PEER_COLOR_PALETTE.size() + + var color_config = PEER_COLOR_PALETTE[color_index].duplicate() + _peer_color_cache[peer_id_str] = color_config + return color_config + +#===================================================================================# + +# FORMATTERS +#===================================================================================# +func _format_message(message: String, args: Array = []) -> String: + """Format message with optional arguments.""" + if args.is_empty(): + return message + + var formatted = message + for i in range(args.size()): + formatted = formatted.replace("{" + str(i) + "}", str(args[i])) + + return formatted + +func _format_rich_text(text: String, bg_color: String, text_color: String) -> String: + """Format text with background and text colors using BBCode.""" + return "[bgcolor=%s][color=%s]%s[/color][/bgcolor]" % [bg_color, text_color, text] + +func _format_space_with_bg(bg_color: String) -> String: + """Format a space character with a background color.""" + return "[bgcolor=%s] [/bgcolor]" % bg_color + +func _get_padding(text_length: int, width: int) -> String: + """Get padding string for a given text length and target width.""" + if text_length >= width: + return "" + var padding = "" + for i in range(width - text_length): + padding += " " + return padding + +func _pad_text(text: String, width: int) -> String: + """Pad text to a specific width for column alignment.""" + return text + _get_padding(text.length(), width) + +func _truncate_text(text: String, max_length: int) -> String: + """Truncate text to a maximum length.""" + if text.length() <= max_length: + return text + return text.substr(0, max_length) + +func _get_local_timestamp_string() -> String: + """Local time: mm:ss:ms by default, or hh:mm:ss:ms when SHOW_TIMESTAMP_HOURS is true.""" + var unix = Time.get_unix_time_from_system() + var ms = clampi(int(floor(fmod(unix, 1.0) * 1000.0)), 0, 999) + var t = Time.get_time_dict_from_system() + if SHOW_TIMESTAMP_HOURS: + return "%02d:%02d:%02d:%03d" % [t.hour, t.minute, t.second, ms] + return "%02d:%02d:%03d" % [t.minute, t.second, ms] + +#===================================================================================# + +# PRINT +#===================================================================================# +func _print_rich_log(peer_id_str: String, log_type: String, message: String, script_name: String = "", function_name: String = "") -> void: + """Print a rich formatted log with peer ID and log type colors.""" + var peer_color = _get_peer_color_config(peer_id_str) + var log_config = LOG_TYPES.get(log_type, LOG_TYPES["log"]) + + # Use peer ID directly without "Peer" prefix + var peer_label = peer_id_str + var log_type_label = log_type.to_upper() + + # Pad peer ID column for alignment + var peer_padded = _pad_text(peer_label, PEER_ID_COLUMN_WIDTH) + + # Format peer ID with its background color + var peer_formatted = _format_rich_text(peer_padded, peer_color.bg_color, peer_color.text_color) + + # Format log type with its background color + var log_type_padded = _pad_text(log_type_label, LOG_TYPE_COLUMN_WIDTH) + var log_type_formatted = _format_rich_text(log_type_padded, log_config.bg_color, log_config.text_color) + + # Local time column (between log type and peer id) + var ts_width = TIMESTAMP_COLUMN_WIDTH_HHMMSSMS if SHOW_TIMESTAMP_HOURS else TIMESTAMP_COLUMN_WIDTH_MMSSMS + var time_padded = _pad_text(_get_local_timestamp_string(), ts_width) + var time_formatted = _format_rich_text(time_padded, TIMESTAMP_BG_COLOR, CONTRAST_TEXT) + + # Build the context string (script name and function name) combined in one column + var context_string = "" + var script_function_parts: Array[String] = [] + + if SHOW_SCRIPT_NAME and script_name != "": + var script_truncated = _truncate_text(script_name, 18) + script_function_parts.append(script_truncated) + + if SHOW_FUNCTION_NAME and function_name != "": + var function_truncated = _truncate_text(function_name, 20) + script_function_parts.append(function_truncated) + + if not script_function_parts.is_empty(): + # Combine script and function names with a separator + var combined = "::".join(script_function_parts) + # Pad, then format with custom background color (so whitespace has background too) + var combined_padded = _pad_text(combined, SCRIPT_FUNCTION_COLUMN_WIDTH) + var combined_formatted = _format_rich_text(combined_padded, SCRIPT_FUNCTION_BG_COLOR, log_config.text_color) + context_string = combined_formatted + + # Format message with text color only (no background) + var message_formatted = "[color=%s]%s[/color]" % [log_config.text_color, message] + + # Format spaces with peer ID background color + var peer_space = _format_space_with_bg(peer_color.bg_color) + + # Combine log type, context, and message with peer-colored spaces + var peer_and_message = peer_formatted + if context_string != "": + peer_and_message += peer_space + context_string + peer_and_message += peer_space + message_formatted + + # Create the full log line: log type, timestamp, then peer id and message + var log_line = log_type_formatted + time_formatted + peer_and_message + var wrapped_line = "[bgcolor=%s]%s[/bgcolor]" % [LOG_LINE_BG_COLOR, log_line] + + print_rich(wrapped_line) + +#===================================================================================# + +# CALLERS +#===================================================================================# +func log(message: String, args: Array = [], script_name: String = "", function_name: String = "") -> void: + """Basic log function with peer_id prefix.""" + var formatted = _format_message(message, args) + var peer_id_str = _get_peer_id() + _print_rich_log(peer_id_str, "log", formatted, script_name, function_name) + +func info(message: String, args: Array = [], script_name: String = "", function_name: String = "") -> void: + """Log an informational message.""" + var formatted = _format_message(message, args) + var peer_id_str = _get_peer_id() + _print_rich_log(peer_id_str, "info", formatted, script_name, function_name) + +func warning(message: String, args: Array = [], script_name: String = "", function_name: String = "") -> void: + """Log a warning message.""" + var formatted = _format_message(message, args) + var peer_id_str = _get_peer_id() + _print_rich_log(peer_id_str, "warning", formatted, script_name, function_name) + +func error(message: String, args: Array = [], script_name: String = "", function_name: String = "") -> void: + """Log an error message.""" + var formatted = _format_message(message, args) + var peer_id_str = _get_peer_id() + _print_rich_log(peer_id_str, "error", formatted, script_name, function_name) + +func debug(message: String, args: Array = [], script_name: String = "", function_name: String = "") -> void: + """Log a debug message.""" + var formatted = _format_message(message, args) + var peer_id_str = _get_peer_id() + _print_rich_log(peer_id_str, "debug", formatted, script_name, function_name) +#===================================================================================# diff --git a/addons/sweet-logger/sweet_logger.gd.uid b/addons/sweet-logger/sweet_logger.gd.uid new file mode 100644 index 0000000..ba0cf4c --- /dev/null +++ b/addons/sweet-logger/sweet_logger.gd.uid @@ -0,0 +1 @@ +uid://cdfw054e8nhxv diff --git a/global/GameManager.gd b/global/GameManager.gd index f94b19d..43f8ceb 100644 --- a/global/GameManager.gd +++ b/global/GameManager.gd @@ -9,9 +9,9 @@ func set_money(value): if multiplayer.is_server(): money = max(0,value) client_sync_money.rpc(money) - print("GameManager: set_money money set to ", money) + SweetLogger.info("set_money money set to {0}", [money], "GameManager.gd", "set_money") else: - print("GameManager: set_money client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set money directly, sending request to server") + SweetLogger.info("set_money client/(peer_id={0}) attempted to set money directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_money") server_set_money.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") # CLIENT -> SERVER: Request a change @@ -29,9 +29,9 @@ func set_day_number(value: int) -> void: if multiplayer.is_server(): day_number = value client_sync_day_number.rpc(day_number) - print("GameManager: set_day_number day_number set to ", day_number) + SweetLogger.info("set_day_number day_number set to {0}", [day_number], "GameManager.gd", "set_day_number") else: - print("GameManager: set_day_number client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set day_number directly, sending request to server") + SweetLogger.info("set_day_number client/(peer_id={0}) attempted to set day_number directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_day_number") server_set_day_number.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -51,9 +51,9 @@ func set_meals_in_play(value: Array[String]) -> void: if multiplayer.is_server(): meals_in_play = value client_sync_meals_in_play.rpc(meals_in_play) - print("GameManager: set_meals_in_play meals_in_play set to ", meals_in_play) + SweetLogger.info("set_meals_in_play meals_in_play set to {0}", [meals_in_play], "GameManager.gd", "set_meals_in_play") else: - print("GameManager: set_meals_in_play client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set meals_in_play directly, sending request to server") + SweetLogger.info("set_meals_in_play client/(peer_id={0}) attempted to set meals_in_play directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_meals_in_play") server_set_meals_in_play.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -73,9 +73,9 @@ func set_sides_in_play(value: Array[String]) -> void: if multiplayer.is_server(): sides_in_play = value client_sync_sides_in_play.rpc(sides_in_play) - print("GameManager: set_sides_in_play sides_in_play set to ", sides_in_play) + SweetLogger.info("set_sides_in_play sides_in_play set to {0}", [sides_in_play], "GameManager.gd", "set_sides_in_play") else: - print("GameManager: set_sides_in_play client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set sides_in_play directly, sending request to server") + SweetLogger.info("set_sides_in_play client/(peer_id={0}) attempted to set sides_in_play directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_sides_in_play") server_set_sides_in_play.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -96,9 +96,9 @@ func set_day_length_seconds(value: float) -> void: if multiplayer.is_server(): day_length_seconds = value client_sync_day_length_seconds.rpc(day_length_seconds) - print("GameManager: set_day_length_seconds day_length_seconds set to ", day_length_seconds) + SweetLogger.info("set_day_length_seconds day_length_seconds set to {0}", [day_length_seconds], "GameManager.gd", "set_day_length_seconds") else: - print("GameManager: set_day_length_seconds client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set day_length_seconds directly, sending request to server") + SweetLogger.info("set_day_length_seconds client/(peer_id={0}) attempted to set day_length_seconds directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_day_length_seconds") server_set_day_length_seconds.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -118,9 +118,9 @@ func set_customers_per_day(value: float) -> void: if multiplayer.is_server(): customers_per_day = value client_sync_customers_per_day.rpc(customers_per_day) - print("GameManager: set_customers_per_day customers_per_day set to ", customers_per_day) + SweetLogger.info("set_customers_per_day customers_per_day set to {0}", [customers_per_day], "GameManager.gd", "set_customers_per_day") else: - print("GameManager: set_customers_per_day client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set customers_per_day directly, sending request to server") + SweetLogger.info("set_customers_per_day client/(peer_id={0}) attempted to set customers_per_day directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_customers_per_day") server_set_customers_per_day.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -140,9 +140,9 @@ func set_customers_count_increase_per_day(value: float) -> void: if multiplayer.is_server(): customers_count_increase_per_day = value client_sync_customers_count_increase_per_day.rpc(customers_count_increase_per_day) - print("GameManager: set_customers_count_increase_per_day customers_count_increase_per_day set to ", customers_count_increase_per_day) + SweetLogger.info("set_customers_count_increase_per_day customers_count_increase_per_day set to {0}", [customers_count_increase_per_day], "GameManager.gd", "set_customers_count_increase_per_day") else: - print("GameManager: set_customers_count_increase_per_day client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set customers_count_increase_per_day directly, sending request to server") + SweetLogger.info("set_customers_count_increase_per_day client/(peer_id={0}) attempted to set customers_count_increase_per_day directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_customers_count_increase_per_day") server_set_customers_count_increase_per_day.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -162,9 +162,9 @@ func set_group_min_size(value: int) -> void: if multiplayer.is_server(): group_min_size = value client_sync_group_min_size.rpc(group_min_size) - print("GameManager: set_group_min_size group_min_size set to ", group_min_size) + SweetLogger.info("set_group_min_size group_min_size set to {0}", [group_min_size], "GameManager.gd", "set_group_min_size") else: - print("GameManager: set_group_min_size client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set group_min_size directly, sending request to server") + SweetLogger.info("set_group_min_size client/(peer_id={0}) attempted to set group_min_size directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_group_min_size") server_set_group_min_size.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -184,9 +184,9 @@ func set_group_max_size(value: int) -> void: if multiplayer.is_server(): group_max_size = value client_sync_group_max_size.rpc(group_max_size) - print("GameManager: set_group_max_size group_max_size set to ", group_max_size) + SweetLogger.info("set_group_max_size group_max_size set to {0}", [group_max_size], "GameManager.gd", "set_group_max_size") else: - print("GameManager: set_group_max_size client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set group_max_size directly, sending request to server") + SweetLogger.info("set_group_max_size client/(peer_id={0}) attempted to set group_max_size directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_group_max_size") server_set_group_max_size.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -213,9 +213,9 @@ func set_game_state(value: GameState) -> void: game_state = value client_sync_game_state.rpc(game_state) Signals.game_state_changed.emit(game_state) - print("GameManager: set_game_state game_state set to ", game_state) + SweetLogger.info("set_game_state game_state set to {0}", [game_state], "GameManager.gd", "set_game_state") else: - print("GameManager: set_game_state client/(peer_id=", multiplayer.get_unique_id(), ") attempted to set game_state directly, sending request to server") + SweetLogger.info("set_game_state client/(peer_id={0}) attempted to set game_state directly, sending request to server", [multiplayer.get_unique_id()], "GameManager.gd", "set_game_state") server_set_game_state.rpc_id(1, value) @rpc("any_peer", "call_remote", "reliable") @@ -233,26 +233,26 @@ func get_random_meal() -> String: push_error("GameManager: get_random_meal() called but meals_in_play is empty") return "" var rand_index = randi() % meals_in_play.size() - print("GameManager: get_random_meal() returning ", meals_in_play[rand_index]) + SweetLogger.debug("get_random_meal() returning {0}", [meals_in_play[rand_index]], "GameManager.gd", "get_random_meal") return meals_in_play[rand_index] func get_random_side() -> String: - print("GameManager: get_random_side() ") + SweetLogger.debug("get_random_side()", [], "GameManager.gd", "get_random_side") if sides_in_play.size() == 0: push_error("GameManager: get_random_side() called but sides_in_play is empty") return "" var rand_index = randi() % sides_in_play.size() - print("GameManager: get_random_side() list=%s returning %s" % [sides_in_play, sides_in_play[rand_index]]) + SweetLogger.debug("get_random_side() list={0} returning {1}", [sides_in_play, sides_in_play[rand_index]], "GameManager.gd", "get_random_side") return sides_in_play[rand_index] func _restart(): - print("restart Game") + SweetLogger.info("restart Game", [], "GameManager.gd", "_restart") game_state = GameState.RUNNING func game_over(): - print("Game Over") + SweetLogger.info("Game Over", [], "GameManager.gd", "game_over") game_state = GameState.GAME_OVER Signals.game_over.emit() diff --git a/global/RecipeManager.gd b/global/RecipeManager.gd index 7182cfe..19c571f 100644 --- a/global/RecipeManager.gd +++ b/global/RecipeManager.gd @@ -111,22 +111,22 @@ static func get_item_scene(item_id: StringName) -> PackedScene: static func print_all_recipes() -> void: load_recipes() if not _loaded: - print("RecipeManager: could not load recipes.yaml; no recipes printed.") + SweetLogger.warning("could not load recipes.yaml; no recipes printed.", [], "RecipeManager.gd", "print_all_recipes") return if _combining_map.is_empty(): - print("RecipeManager: no combining recipes found") + SweetLogger.warning("no combining recipes found", [], "RecipeManager.gd", "print_all_recipes") return - print("#### RecipeManager: Loaded recipes ####") + SweetLogger.info("#### RecipeManager: Loaded recipes ####", [], "RecipeManager.gd", "print_all_recipes") _print_combining_recipes() - print("") + SweetLogger.info("", [], "RecipeManager.gd", "print_all_recipes") _print_cooking_recipes() - print("") + SweetLogger.info("", [], "RecipeManager.gd", "print_all_recipes") _print_chopping_recipes() - print("") + SweetLogger.info("", [], "RecipeManager.gd", "print_all_recipes") _print_rolling_recipes() - print("") + SweetLogger.info("", [], "RecipeManager.gd", "print_all_recipes") _print_augmenting_recipes() static func _print_combining_recipes() -> void: @@ -135,12 +135,12 @@ static func _print_combining_recipes() -> void: var key_str = str(pair_key) var separator_index = key_str.find("|") if separator_index == -1: - print("RecipeManager: invalid combining map key '%s'" % key_str) + SweetLogger.warning("invalid combining map key '{0}'", [key_str], "RecipeManager.gd", "_print_combining_recipes") continue var first = key_str.substr(0, separator_index) var second = key_str.substr(separator_index + 1, key_str.length() - separator_index - 1) - print(" %s <-combine-- %s + %s" % [result_id, first, second]) + SweetLogger.info(" {0} <-combine-- {1} + {2}", [result_id, first, second], "RecipeManager.gd", "_print_combining_recipes") static func _print_cooking_recipes() -> void: @@ -148,22 +148,22 @@ static func _print_cooking_recipes() -> void: var cook_defs = _cooking_map[cooked_id] if typeof(cook_defs) == TYPE_ARRAY: for cook_def in cook_defs: - print(" %s <-cook-- %s - time: %.1f" % [cooked_id, cook_def["ingredient"], cook_def["time"]]) + SweetLogger.info(" {0} <-cook-- {1} - time: {2}", [cooked_id, cook_def["ingredient"], cook_def["time"]], "RecipeManager.gd", "_print_cooking_recipes") else: var cook_def = cook_defs - print(" %s <-cook-- %s - time: %.1f" % [cooked_id, cook_def["ingredient"], cook_def["time"]]) + SweetLogger.info(" {0} <-cook-- {1} - time: {2}", [cooked_id, cook_def["ingredient"], cook_def["time"]], "RecipeManager.gd", "_print_cooking_recipes") static func _print_chopping_recipes() -> void: for chopped_id in _chopping_map.keys(): var chop_def = _chopping_map[chopped_id] - print(" %s <-chop-- %s - work: %.1f" % [chopped_id, chop_def["ingredient"], chop_def["work"]]) + SweetLogger.info(" {0} <-chop-- {1} - work: {2}", [chopped_id, chop_def["ingredient"], chop_def["work"]], "RecipeManager.gd", "_print_chopping_recipes") static func _print_rolling_recipes() -> void: for rolled_id in _rolling_map.keys(): var roll_def = _rolling_map[rolled_id] - print(" %s <-roll-- %s - work: %.1f" % [rolled_id, roll_def["ingredient"], roll_def["work"]]) + SweetLogger.info(" {0} <-roll-- {1} - work: {2}", [rolled_id, roll_def["ingredient"], roll_def["work"]], "RecipeManager.gd", "_print_rolling_recipes") static func _print_augmenting_recipes() -> void: @@ -171,7 +171,7 @@ static func _print_augmenting_recipes() -> void: var augment_def = _augmenting_map[target_id] for ingredient_id in augment_def.keys(): var attr_key = augment_def[ingredient_id] - print(" %s <-augment-- %s adds attribute '%s'" % [target_id, ingredient_id, attr_key]) + SweetLogger.info(" {0} <-augment-- {1} adds attribute '{2}'", [target_id, ingredient_id, attr_key], "RecipeManager.gd", "_print_augmenting_recipes") static func _build_scene_paths() -> void: diff --git a/global/global_key_events.gd b/global/global_key_events.gd index c51aa55..e7079b3 100644 --- a/global/global_key_events.gd +++ b/global/global_key_events.gd @@ -28,14 +28,14 @@ func satisfy_table_orders() -> void: func set_buidling_mode(): - print("Global key event: Setting building mode") + SweetLogger.info("Setting building mode", [], "global_key_events.gd", "set_buidling_mode") GameManager.set_game_state(GameManager.GameState.BUILDING) func set_running_mode(): - print("Global key event: Setting running mode") + SweetLogger.info("Setting running mode", [], "global_key_events.gd", "set_running_mode") GameManager.set_game_state(GameManager.GameState.RUNNING) func set_game_over(): - print("Global key event: Setting game over") + SweetLogger.info("Setting game over", [], "global_key_events.gd", "set_game_over") GameManager.set_game_state(GameManager.GameState.GAME_OVER) diff --git a/global/helper.gd b/global/helper.gd index 267155c..439886c 100644 --- a/global/helper.gd +++ b/global/helper.gd @@ -25,15 +25,15 @@ static func find_first_child_of_type(node: Node, type: Variant) -> Node: # Returns true if decendant is a decendant node of root, false otherwise. Returns false if either node is null. static func is_node_decendant_of(decendant: Node, root: Node) -> bool: if not decendant or not root: - print("Helper.is_node_decendant_of: decendant or root is null") + SweetLogger.debug("is_node_decendant_of: decendant or root is null", [], "helper.gd", "is_node_decendant_of") return false var current: Node = decendant while current: if current == root: - print("Helper.is_node_decendant_of: decendant %s is a descendant of root %s" % [decendant.name, root.name]) + SweetLogger.debug("is_node_decendant_of: decendant {0} is a descendant of root {1}", [decendant.name, root.name], "helper.gd", "is_node_decendant_of") return true current = current.get_parent() - print("Helper.is_node_decendant_of: decendant %s is NOT a descendant of root %s" % [decendant.name, root.name]) + SweetLogger.debug("is_node_decendant_of: decendant {0} is NOT a descendant of root {1}", [decendant.name, root.name], "helper.gd", "is_node_decendant_of") return false diff --git a/project.godot b/project.godot index 046dc07..10511c9 100644 --- a/project.godot +++ b/project.godot @@ -23,6 +23,8 @@ NetworkManager="*res://Net/network_manager.gd" GlobalKeyEvents="*uid://c60unagog5oi1" Signals="*uid://fuux6cxfjwdc" GameManager="*uid://y4sol8l8vih1" +SweetLogger="*uid://cdfw054e8nhxv" +MoveWindows="*uid://de8j52uus1pbv" [debug] @@ -32,12 +34,13 @@ file_logging/enable_file_logging=true window/size/viewport_width=1000 window/size/viewport_height=650 +window/size/initial_position_type=0 window/stretch/mode="canvas_items" window/stretch/aspect="expand" [editor_plugins] -enabled=PackedStringArray("res://addons/godot-xr-tools/plugin.cfg", "res://addons/kanban_tasks/plugin.cfg", "res://addons/yaml/plugin.cfg") +enabled=PackedStringArray("res://addons/godot-xr-tools/plugin.cfg", "res://addons/kanban_tasks/plugin.cfg", "res://addons/sweet-logger/plugin.cfg", "res://addons/yaml/plugin.cfg") [filesystem] diff --git a/test/mp_test_driver.gd b/test/mp_test_driver.gd index 54ef6ce..3b4a495 100644 --- a/test/mp_test_driver.gd +++ b/test/mp_test_driver.gd @@ -1419,11 +1419,11 @@ func _open_log() -> void: path = OS.get_environment("TEMP").path_join("vryhungry_mptest_%s.log" % role) _log_file = FileAccess.open(path, FileAccess.WRITE) _log_path = ProjectSettings.globalize_path(path) - print("[MPTEST] step log -> %s" % _log_path) + SweetLogger.info("[MPTEST] step log -> {0}", [_log_path], "mp_test_driver.gd", "_open_log") func _log(s: String) -> void: - print("[MPTEST %s] %s" % [_role, s]) + SweetLogger.info("[MPTEST {0}] {1}", [_role, s], "mp_test_driver.gd", "_log") if _log_file: _log_file.store_line(s) _log_file.flush() diff --git a/test/run_tests_in_editor.gd b/test/run_tests_in_editor.gd index a1f404b..5e19ca4 100644 --- a/test/run_tests_in_editor.gd +++ b/test/run_tests_in_editor.gd @@ -42,7 +42,7 @@ func _run() -> void: _clear_previous_results(logs_dir) print_rich("[b]Running the multiplayer test suite...[/b]") - print(" the editor will be unresponsive until it finishes (~2 minutes)") + SweetLogger.info("the editor will be unresponsive until it finishes (~2 minutes)", [], "run_tests_in_editor.gd", "_run") var server_pid := _launch(exe, project_dir, ["--server"], SERVER_SCENE) if server_pid <= 0: @@ -61,7 +61,7 @@ func _run() -> void: OS.delay_msec(500) waited += 0.5 if OS.is_process_running(server_pid): - print(" timed out after %ds, stopping the instances" % TIMEOUT_SEC) + SweetLogger.warning("timed out after {0}s, stopping the instances", [TIMEOUT_SEC], "run_tests_in_editor.gd", "_run") OS.kill(server_pid) if OS.is_process_running(client_pid): OS.kill(client_pid) @@ -108,7 +108,7 @@ func _print_report(logs_dir: String) -> void: push_error("No report at %s — the run did not finish. Check logs/mptest_server.log" % path) return var text := FileAccess.get_file_as_string(path) - print("") + SweetLogger.info("", [], "run_tests_in_editor.gd", "_print_report") # Colour the summary so a failure is obvious in the Output panel. for line in text.split("\n"): if line.begins_with("FAIL") or line.contains("RESULT: FAILED"): @@ -118,8 +118,8 @@ func _print_report(logs_dir: String) -> void: elif line.begins_with("PASS"): print_rich("[color=gray]%s[/color]" % line) else: - print(line) - print("report: %s" % path) + SweetLogger.info("{0}", [line], "run_tests_in_editor.gd", "_print_report") + SweetLogger.info("report: {0}", [path], "run_tests_in_editor.gd", "_print_report") func _build_gif(project_dir: String, logs_dir: String) -> void: diff --git a/test/testworldLoad.gd b/test/testworldLoad.gd index 48a891b..1fab4cb 100644 --- a/test/testworldLoad.gd +++ b/test/testworldLoad.gd @@ -3,8 +3,8 @@ extends Node # Called when the node enters the scene tree for the first time. func _ready() -> void: - print(get_stations()) - print(get_items()) + SweetLogger.debug("stations: {0}", [get_stations()], "testworldLoad.gd", "_ready") + SweetLogger.debug("items: {0}", [get_items()], "testworldLoad.gd", "_ready")