Weird logic error

Godot Version

4.3 stable

Question

I’m having a odd problem with my code. I have a series of events that occur to move a npc character.

First I call set_movement_target, then that enables the _physics_process to handle the movement using the navigation agent, after it reaches the target location then it runs a function named handle_move_finished, that does the after move code and uses current_action as its match statement.

The problem I am having is when it reaches the handle_move_finished the current_action has changed somehow, the only problem is that the only place it is set to idle is at the end of the handle_move_finished function.

I have logging on every function. Here is the log:

worker - set movement target
destination: goto_machine
worker - change status : moving
current action: goto_machine
current status: moving
finished moving…
worker - handle_move_finished
current action: idle ← this should be goto_machine
current status: moving

How did it change actions? When nothing happened between the move trigger and the finished moving function call.

Any ideas?

Literally the only place that current_action is set to idle is at the end of the handle_move_finished function.

Impossible to say without looking at the code. Your print statements seem in the order you describe though, it can only change to idle at the end of handle_move_finished, and it does.

Since this involves physics processing, there might be multiple processes running in parallel. Could another process or signal be changing the state?

Does the navigation system use any deferred or queued calls that might be executing out of order?

Are there any signals connected to the navigation agent that might trigger when movement completes?

I dont think there are any parells
I dont have any signals attached to the nav
i dont have any defered or queued calls

here is the script, the order of events globaly is as follows.

npc spawns at location
npc moves to breakroom location
wait a couple seconds
npc moves to machine
npc sends event to machine that its there
machine sends event to npc to change status to is_working
machine starts making products
… if machine inventory reaches full then sent event to npc to deliver products to pallet

npc received event from machine
npc takes products from machine
npc moves to pallet for products
(upon leaving machine stops working)
npc tells pallet that it has arrived
pallet takes the items and tells npc to return
npc returns to machine
the process repeats from that point, back up to the npc arriving at the machine

there is another event that can be sent to the npc to tell it to go to the resources pallet for parts.

I’m making a factory game if that makes sense.

extends CharacterBody2D


var SPEED = 200
var target_position_node
var current_level = 'Level1'
var worker_level = 1
var has_target_position = false

var worker_id 		
var work_start_time = 6
var work_end_time = 17
var machine_assigned = "unassigned"

var current_status = 'idle'
var current_action = 'idle'
var last_action = "idle"
var attributes = {}
var worker_name = null
var after_timer_goto_action = null
var last_status = null
var last_position

var inventory_carry = {
	'carry_box_limit' : 2,
	'resources': {},
	'products': {}
}

var passthrough_extra_data = {}
 
@onready var nav_agent := $NavigationAgent2D as NavigationAgent2D

@onready var breakroom_wait_time: Timer = $BreakroomWaitTime
@onready var hairSprite: AnimatedSprite2D = $CompositeSprites/Hair
@onready var bodySprite: AnimatedSprite2D = $CompositeSprites/Body
@onready var armsSprite: AnimatedSprite2D = $CompositeSprites/Arms
@onready var headSprite: AnimatedSprite2D = $CompositeSprites/Head
@onready var shoesSprite: AnimatedSprite2D = $CompositeSprites/Shoes
@onready var pantsSprite: AnimatedSprite2D = $CompositeSprites/Pants
@onready var moving_stuck_check_timer: Timer = $MovingStuckCheckTimer


func _ready() -> void:
	
	SignalBus.set_daytime.connect(set_daytime)
	SignalBus.triggerMachine2NPCEvent.connect(_on_machine_to_npc_event)
	SignalBus.triggerPallet2NpcEvent.connect(_on_pallet_to_npc_event)
	
	worker_name = PlayerData.worker_settings[worker_id]['name']
	 
	var start_position_node = translateTargetPosition(PlayerData.worker_settings[worker_id]['position_name'])
	position = start_position_node.position		
	target_position_node = start_position_node
	
	machine_assigned = PlayerData.worker_settings[worker_id]['machine_assigned']
	if machine_assigned == "unassigned":
		SignalBus.popup_notification.emit('Worker ['+worker_name+'] has no machine assignment!')
		var breakroom_position = translateTargetPosition('BreakroomLocation')
		if (start_position_node.name == breakroom_position.name):
			visible = false
			if breakroom_wait_time.is_stopped():
				set_movement_target('goto_machine', {})
				visible = true
		else:
			visible = true
			set_movement_target('goto_breakroom', {})
	
	current_status = PlayerData.worker_settings[worker_id]['status']
	
	match current_status:
		'idle':
			match start_position_node.name:
				'WorkerSpawnLocation':
					pass
					
				'BreakroomLocation':
					if breakroom_wait_time.is_stopped():
						if after_timer_goto_action == null:
							after_timer_goto_action = 'goto_machine'
						breakroom_wait_time.start()
				#'ProductPalletLocation':
				#'ResourcePlalletLocation':
				_:
					set_movement_target('goto_machine', {})
					
		'is_working':
			change_current_status_helper("at_machine")
			SignalBus.triggerNPC2MachineEvent.emit(worker_id, machine_assigned, 'at_machine', {})
			
			
	
	bodySprite.play('idle')
		
	print("current action: " + current_action)
	print("current status: " + current_status)
	 
func set_movement_target(destination, extraData):
	print("worker - set movement target")
	print("destination: " + destination)
	print(extraData)
	
	match destination:
		'goto_breakroom':
			target_position_node = translateTargetPosition('BreakroomLocation')
			nav_agent.target_position = target_position_node.position
			has_target_position = true
			change_current_status_helper("moving")
			current_action = 'goto_breakroom'
			var wait_time = getProperyFromDict('wait_time', extraData)
			if (wait_time):
				breakroom_wait_time.wait_time = wait_time	
			after_timer_goto_action = getProperyFromDict('after_action', extraData)
		
		"goto_machine":
			target_position_node = translateTargetPosition(machine_assigned + 'WorkLocation')
			nav_agent.target_position = target_position_node.position
			has_target_position = true
			change_current_status_helper("moving")
			current_action = 'goto_machine'
			
		"goto_resources_pallet":
			target_position_node = translateTargetPosition('ResourcePalletLocation')
			nav_agent.target_position = target_position_node.position		
			change_current_status_helper("moving")
			current_action = 'goto_resources_pallet'
			has_target_position = true
			
		"goto_products_pallet":
			target_position_node = translateTargetPosition('ProductPalletLocation')
			nav_agent.target_position = target_position_node.position		
			change_current_status_helper("moving")
			current_action = 'goto_products_pallet'
			has_target_position = true
			
		"goto_spawnpoint":
			target_position_node = translateTargetPosition('WorkerSpawnLocation')
			nav_agent.target_position = target_position_node.position		
			change_current_status_helper("moving")
			current_action = 'goto_spawnpoint'
			has_target_position = true
			
	
	print("current action: " + current_action)
	print("current status: " + current_status)
 
func handle_move_finished():
	print('worker - handle_move_finished')
	print("current action: " + current_action)
	print("current status: " + current_status)
				
	match current_action:
		"goto_breakroom":			
			change_current_status_helper("at_breakroom")
			print('at breakroom, wait : ' + str(breakroom_wait_time.wait_time))
			visible = false;
			breakroom_wait_time.start()
			
		"goto_machine":
			change_current_status_helper("at_machine")
			if passthrough_extra_data.is_empty():
				SignalBus.triggerNPC2MachineEvent.emit(worker_id, machine_assigned, 'at_machine', {})
			else:
				SignalBus.triggerNPC2MachineEvent.emit(worker_id, machine_assigned, 'at_machine', passthrough_extra_data)
				passthrough_extra_data = {}
			
		'goto_resources_pallet':
			change_current_status_helper("at_resource_pallet")
						
			SignalBus.triggerNPC2PalletEvent.emit('fetch_resources', {
				'resources': passthrough_extra_data['need_resources']
			})
			
		'goto_products_pallet':
			change_current_status_helper("at_product_pallet")
			var product
			for key in inventory_carry['products'].keys():
				product = key
			
			SignalBus.triggerNPC2PalletEvent.emit('deliver_products', {
				'type': 'products',
				'product': product,
				'total': inventory_carry['products'][product]['total'],
				'worker_id': worker_id
			})
			
		'goto_spawnpoint':
			change_current_status_helper("idle")
			visible = false
			
	current_action = 'idle'
	
	
func change_current_status_helper(newStatus):	
	print("worker - change status : " + newStatus)
	last_status = current_status
	current_status = newStatus

func set_daytime(day: int, hour: int, minute: int) -> void:	
	
	if current_status == 'idle' && current_action == 'idle':
		print('status/action is idle')		
		print('hour: ' + str(hour))
		print('work start time: '+ str(work_start_time))
		print(hour == work_start_time)
		# check if work start time
		if hour == work_start_time:
			print('Start of shift')
			if target_position_node.name != 'WorkerSpawnLocation':
				target_position_node = translateTargetPosition(machine_assigned + 'WorkLocation')
				position = target_position_node.position
				
			visible = true
			set_movement_target('goto_breakroom', {'wait_time': 2, "after_action": 'goto_machine'})
		
	if hour == work_end_time:
		if current_status != 'moving':
			if after_timer_goto_action != 'goto_spawnpoint':
				set_movement_target('goto_breakroom', {'wait_time': 2, "after_action": 'goto_spawnpoint'})	
	else:
		if hour> work_end_time || hour < work_start_time:
			print("is non working hours")
			print( target_position_node.name)
			if current_status != 'moving' && target_position_node.name != 'WorkerSpawnLocation':
				print ('not moving and not at span')
				if current_status != 'idle' && current_action == 'idle':
					set_movement_target('goto_spawnpoint', {})	
					breakroom_wait_time.stop()
	

func _on_pallet_to_npc_event(workerId, event, extraData):
	print ('worker _on_pallet_to_npc_event')	
	print(event)
	print(extraData)
	print(workerId)
	
	print('worker id: ' + workerId)
	if workerId == worker_id:
		print("-- worker matched")
		match event:
			'empty_carry':
				inventory_carry[extraData['product_dest']][extraData['product']] = {}
				set_movement_target('goto_machine', {})
			'return_resources':
				#check if need resources is set
				var need_resources = getProperyFromDict('need_resources', extraData)
				if need_resources == null:
					#check if carry is set
					var carry = getProperyFromDict('carry', extraData)
					if carry == null:
						set_movement_target('goto_machine', {})
					else:
						for key in carry.keys():
							inventory_carry['resources'][key] = carry[key]
						passthrough_extra_data = inventory_carry['resources']
						set_movement_target('goto_machine', {})	
	
					
	 
		
	
func _on_machine_to_npc_event(workerId: String, machineId: String, event: String, extraData: Dictionary):
	print ('worker _on_machine_to_npc_event')		
	print(event)
	print(extraData)
	print(machineId)
	
	print ('machine id: ' + machineId)
	if machineId == machine_assigned:
		print("-- machine matched")
		print('worker id: ' + workerId)
		if workerId == worker_id:
			print("-- worker matched")			
			match event:
				'empty_carry':
					inventory_carry[extraData['product_dest']][extraData['product']] = {}
					set_movement_target('goto_machine', {})
				
				'change_status':
					var newstatus = getProperyFromDict('newstatus', extraData)
					change_current_status_helper(newstatus)
					
				'deliver_product':
					var product = getProperyFromDict('product', extraData) # gears
					var product_is_resource = getProperyFromDict('product_is_resource', extraData) # t?f
					var num_boxes = getProperyFromDict('num_boxes', extraData) # total num boxes on machine pallet
					var num_per_box = getProperyFromDict('num_per_box', extraData) # number per box
					
					var 	carry_box_limit = getProperyFromDict('carry_box_limit', inventory_carry)
					if carry_box_limit > num_boxes:
						carry_box_limit = num_boxes
						
					var ptype = 'products'
					var mdest = 'goto_products_pallet'
					if product_is_resource:
						ptype = 'resources'
						mdest = 'goto_resource_pallet'
					
					var test = getProperyFromDict(product, inventory_carry[ptype])
					if test == null:
						inventory_carry[ptype][product] = {'total': num_per_box * carry_box_limit}
					else:
						inventory_carry[ptype][product]['total'] = num_per_box * carry_box_limit

					SignalBus.triggerNPC2MachineEvent.emit(worker_id, machine_assigned, 'subtract_inventory', {'num_boxes': carry_box_limit})
			
					print('set move to :' + mdest)
					set_movement_target(mdest, {})
					
				'fetch_resources':
					passthrough_extra_data = extraData
					set_movement_target('goto_resources_pallet', {})
		
func getProperyFromDict(key, data):
	return Utilities.getProperyFromDict(key,data)
	
func getAttribute(key):
	return getProperyFromDict(key, attributes);
		
func translateTargetPosition(destination):
	var nodes = get_tree().get_nodes_in_group(str(current_level, "MapLocations"))
	for n in nodes:
		name = n.name		
		if name.contains(destination):
			return n

	return translateTargetPosition('WorkerSpawnLocation')
 
		
func save_worker_settings():
	print("save worker settings")
	PlayerData.worker_settings[worker_id]['machine_assigned'] = machine_assigned
	PlayerData.worker_settings[worker_id]['status'] = current_status
	if target_position_node != null:
		PlayerData.worker_settings[worker_id]['position_name'] = target_position_node.name
	else:
		PlayerData.worker_settings[worker_id]['position_name'] = 'WorkerSpawnLocation'
	SignalBus.savePlayerSettings.emit('worker_settings')
 

func _physics_process(delta: float) -> void:
	
	if (has_target_position):		
		var rot_offset = Vector2(1, 0).angle_to((velocity - position * 5).normalized())
		var speed = (SPEED / 2) + ((SPEED/2) * rot_offset) * delta
		var dir = to_local(nav_agent.get_next_path_position()).normalized()		
		velocity = dir * speed
		if nav_agent.is_navigation_finished():
			shoesSprite.stop()
			armsSprite.stop()
			has_target_position = false
			print("-- finished moving...")
			handle_move_finished()
		else:
			shoesSprite.play('walk')
			armsSprite.play('walk')
		move_and_slide()
		
	 

func _on_breakroom_wait_time_timeout() -> void:

	print('## _on_breakroom_wait_time_timeout')
	print("current action: " + current_action)
	print("current status: " + current_status)	
	print("after action: " + after_timer_goto_action)	
	 
	if after_timer_goto_action != null:
		visible = true		
		set_movement_target(after_timer_goto_action, {})
		after_timer_goto_action = ''
				
		
			


func _on_moving_stuck_check_timer_timeout() -> void:
	pass
	
	#print('worker - _on_moving_stuck_check_timer_timeout')
	#if current_status == 'moving':
	#	print ('-- status moving')
	#	if position == last_position:
	#		print ('-- same position, reset it')
	#		nav_agent.target_position = target_position_node.position
	#		has_target_position = true
	#	last_position = position

Anyone see a problem in the code? or maybe even in the way i’m handling the process? I am really stuck at the moment on how to fix the problem.

I think your current_action = 'idle' at the end of handle_move_finished() is likely the culprit. I think it’s potentially stomping the setup you did earlier in the function.

that doesnt make a lot of sense. How can it run and change the value before executing the first three lines in the function?

As far as I can see, the only place current_action is assigned a value of idle is at the end of handle_move_finished(). That doesn’t seem to mesh up with the print log you listed, but:

  • you aren’t listing anything to identify individual workers; are you testing this with a single worker, or might you have multiple workers’ output interleaved?
  • various of your match statements that handle things don’t have default cases, and you’re using strings, so if you typo any of your states anywhere the match will silently fall through and do nothing – this could easily be causing the problem – personally, I’d suggest an enum to catch the typos and _: print("WAT?!?") on the end of your matches

I’d advise testing with a single worker, and sticking a print statement inside _physics_process() just inside the test for has_target_position:

if (has_target_position):
    print("[_physics_process]: current_action = " + current_action)
    [...]

I suspect you’ll find current_action is idle far earlier than you expect, but either way it will help you determine when current_action goes astray.

I’ve changed some of the debug print statements to give a better order of events. I only have one worker, machine right now. A Enum is a great idea, and I have added catch all to the match statements.

new log with more detail and slightly cleaner. Starts from machine sending npc signal to deliver products.

[WORKER _on_machine_to_npc_event]
--deliver_product
extra data:
{ "product": "gears", "num_boxes": 24, "num_per_box": 2, "product_is_resource": false }
-- machine id: Machine1
---- machine matched
-- worker id: worker_01
---- worker matched
-- send signal to machine - subtract_inventory

	[MACHINE - _on_npc_to_machine_event]
	-- worker id: worker_01
	-- machine id: Machine1
	-- event: subtract_inventory
	extra data:
	{ "num_boxes": 2 }
	number boxes: 22

-- set move to :goto_products_pallet

[WORKER - set_movement_target]
-- destination: goto_products_pallet
-- extra data:
{  }
	[WORKER - change_current_status_helper] change status to : moving
	-- current action: goto_products_pallet
	-- current status: moving

[_physics_process]: current_action = goto_products_pallet

[WORKER - handle_move_finished]
-- current action: goto_products_pallet
-- current status: moving
	[WORKER - change_current_status_helper] change status to : at_product_pallet
	#######################
	#### missing current status/action debug from change status function
	#######################

--- send event to pallet (deliver products)

	[ products pallet] - _handle_npc_to_pallet_event
	deliver_products
	{ "type": "products", "product": "gears", "total": 4, "worker_id": "worker_01" }
		[ products pallet] - update_pallet_display
		total inv: 4
		total boxes: 2

[WORKER - _on_pallet_to_npc_event]
-- empty_carry
extra data:
{ "product_dest": "products", "product": "gears" }
-- worker id: worker_01
---- worker matched
-- empty_carry

[WORKER - set_movement_target]
-- destination: goto_machine
-- extra data:
{  }
	[WORKER - change_current_status_helper] change status to : moving
	-- current action: goto_machine
	-- current status: moving

#######################
#### missing func handle_move_finish beginning debug statements and occurs before the physics process finishes
#######################
[WORKER - handle_move_finished] -- set current action to idle

[_physics_process]: current_action = idle

[WORKER - handle_move_finished]
-- current action: idle
-- current status: moving
### no match for idle

#######################
#### The current_action should be set to goto_machine
#######################

I’ve decided to change everything from using only signals to using area2d hooks, or at least I’m trying that route and that seems to be fixing the problem.

Ah, good. That’s one thing I forgot to mention; signals may or may not be processed in the order you expect. I’m not sure how Godot implements signals internally, but let’s say we have a simple bit of pseudocode:

var value = "default"

func sig():
    value = "sig"

func foo():
    emit(sig)
    value = "foo"

If we call foo(), it emits a signal and then writes to value, so you might expect that value == "foo" at the end. But what if the underlying system causes emit() to queue the call for later? In that case, value == "sig".

Either option is a valid way of implementing signals, but the flow control implications are very different. Depending on which method the Godot devs picked, your code may not be running in the order you expected.