Output not displaying in correct order when using parallel Luau and BindableEvents with Immediate SignalBehavior

Reproduction Steps

Studio Version 0.561.0.5610360 (64bit)

Use this place file:
parallel_output_order_bug_report.rbxl (37.8 KB)

Or follow these steps:

  1. Create LocalScript in PlayerScripts with Code A.
  2. Create LocalScript with Code B, parented to the first LocalScript. Set Enabled = false and Name = “ActorScript”.
Code A ("LocalScript"
local Parallel = true

local ReceiveEvent = Instance.new("BindableEvent")
ReceiveEvent.Parent = script
ReceiveEvent.Event:Connect(function(ID)
	debug.profilebegin("Receive spinlock "..ID)
	local FinishAt = os.clock() + (0.5 / 1000)
	while os.clock() < FinishAt do end
	debug.profileend()
	
	debug.profilebegin("Receive print "..ID)
	print("Receive", ID)
	debug.profileend()
end)

if Parallel then
	local Actors = {}
	
	local ActorScriptTemplate = script.ActorScript
	for Index = 1, 10 do
		local Actor = Instance.new("Actor")
		Actor.Name = tostring(Index)
		Actor.Parent = script
		
		local SendEvent = Instance.new("BindableEvent")
		SendEvent.Name = "SendEvent"
		SendEvent.Parent = Actor
		
		local ActorScript = ActorScriptTemplate:Clone()
		ActorScript.Parent = Actor
		ActorScript.Enabled = true
		
		Actors[#Actors+1] = Actor
	end
	
	game:GetService("RunService").RenderStepped:Connect(function()
		print("--- FRAME BEGIN")
		for ID = 1, 10 do
			-- Use ID as both the index into the Actors array and the identifier
			-- for specific signal callbacks.
			local Actor = Actors[ID]
			Actor.SendEvent:Fire(ReceiveEvent, ID)
		end
	end)
else
	local SendEvent = Instance.new("BindableEvent")
	SendEvent.Parent = script
	SendEvent.Event:Connect(function(ID)
		debug.profilebegin("Send print "..ID)
		print("Send Before", ID)
		ReceiveEvent:Fire(ID)
		print("Send After", ID)
		debug.profileend()
	end)

	game:GetService("RunService").RenderStepped:Connect(function()
		print("--- FRAME BEGIN")
		for ID = 1, 10 do
			SendEvent:Fire(ID)
		end
	end)
end
Code B ("ActorScript")
script.Parent.SendEvent.Event:ConnectParallel(function(ReceiveEvent, ID)
	debug.profilebegin("Send print "..ID)
	print("Send Before", ID)
	ReceiveEvent:Fire(ID)
	print("Send After", ID)
	debug.profileend()
end)

Then to test the bug:

  1. Make sure Workspace.SignalBehavior is set to Immediate.
  2. Make sure the Parallel variable in Code A is true (when it is false the code will execute serially - it exists just for comparing the normal correct behaviour without parallelism).
  3. Play the game and dump using the microprofiler after a few seconds. Also take a copy or screenshot of the output if necessary.
  4. Compare the execution order of the “Send print X”, “Receive spinlock X”, and “Receive print X” microprofiler labels with the order of the “Send before/after X” and “Receive X” prints in the output.

(The “Send” prints and labels correspond to the code executed in parallel, and the “Receive” prints and labels correspond to code that gets executed after the parallel execution block.

The spinlock is there to have some extra confirmation that there’s nothing weird going on between the “start” of the “receive” event’s callback and the point where it calls print().)

Expected Behavior

The displayed order of prints in the output should match the execution order of the prints as they appear in the microprofiler. Having prints accurately represent order of code execution is important for productive debugging.

Actual Behavior

When Workspace.SignalBehavior is set to Immediate, prints are displayed in the output in a strange order.

Notice how in this image all the prints appear in clumps as if the prints were executed serially. Then compare this to the microprofiler labels, which show all the “send” prints being executed first, then all the “receive” prints being executed after, serially:

Naively, it appears that the order the “receive” event is fired by the “send” event callback determines the ordering of the prints by the “receive” event?

Issue Area: Studio
Issue Type: Display
Impact: High
Frequency: Constantly

2 Likes

Thank you for the report.
This happens because adding a message to Studio Output is also deferred in parallel stage, we will check if we can make output immediate.

3 Likes

Even if you can’t make them immediate, preserving order is more important than performance here. It’s fine if parallel can’t be ordered perfectly, but within each thread order should be preserved as much as possible.

1 Like

This issue is now fixed. (some extra characters to post)

3 Likes