One Debug line slows down prg by factor 50

[Kurzer]

Hello everyone,

I have the problem in my current project that a single debug line slows down the runtime of the program by a factor of about 50.
In debug mode I display the content of a structured variable in a ForEach loop, which contains about 175 records sent from my web server.

The variable has the structure structResultset:

Code: Select all

	Structure structResultrow
		Map mpResultrow.s()
	EndStructure
	
	Structure structResultset
		Command.s
		Status.s
		Message.s
		Count.i
		List lsResultset.structResultrow()
	EndStructure

I display the data with the following code:

Code: Select all

	With *Result
		Debug ""
		Debug "------------ " + sText + " ------------"
		Debug "Command: " + "PRIVACY............" ; \Command
		Debug "Status: " + "PRIVACY............" ; \Status
		Debug "Message: " + "PRIVACY............" ; \Message
		Debug "Entries: " + \Count
		Debug "---"
		If \Status <> DBI::#DBI_Status_Err ; And iShowDetails = #True
			ForEach \lsResultset()
				ForEach \lsResultset()\mpResultrow()
					sMapKey = MapKey(\lsResultset()\mpResultrow())
					; Debug sMapKey + ": " + "PRIVACY............" ; \lsResultset()\mpResultrow(sMapKey)
				Next
			Next
		EndIf
	EndWith

The problem can be seen in the following screen recording. The recording is made in real time. First I run the program with debug output enabled, then with commented out debug output.
I replaced the output of the server data with the Sting "PRIVACY.....", because otherwise private customer data would be shown. But this has no influence on the runtime behaviour.



The loading of the data is divided into 8 sections. You can see the load indicator growing after each section.
The curious thing is, that I use the same procedure to display the data of all other sections, which the server sends. Everything is displayed in fractions of a second except this one section.

The delay even lasts so long that my browser shows a timeout message. I then click on "Continue Waiting" and after a long time the SpiderBasic program finally continues running.

The problematic section is the one with the most data, but with 33612 characters sent by the server it is not too big. The structured variable will contain slightly less data because the entire JSON string the server sends is exactly 33612 characters long.

Does anyone have any idea what could be the cause for this?

Markus

[Kurzer]

I tried to reproduce the effect with the following code, but the delay is not nearly as strong as in my project.

Code: Select all

Structure structResultrow
	Map mpResultrow.s()
EndStructure

Structure structResultset
	Command.s
	Status.s
	Message.s
	Count.i
	List lsResultset.structResultrow()
EndStructure

Global stResultSet.structResultset, i.i, iTime.i

Procedure ShowResult(*Result.structResultset)
	Protected.s sMapKey
	
	With *Result
		Debug "Command: " + \Command
		Debug "Status: "  + \Status
		Debug "Message: " + \Message
		Debug "Entries: " + \Count
		Debug "---"
		If \Status <> "ERR"
			ForEach \lsResultset()
				ForEach \lsResultset()\mpResultrow()
					sMapKey = MapKey(\lsResultset()\mpResultrow())
					Debug sMapKey + ": " + \lsResultset()\mpResultrow(sMapKey)
				Next
			Next
		EndIf
	EndWith
	
EndProcedure


stResultSet\Command = "Test"
stResultSet\Status = "Test"
stResultSet\Message = "Test"
stResultSet\Count = 175
For i = 0 To 174
	If AddElement(stResultSet\lsResultset()) <> 0
		stResultSet\lsResultset()\mpResultrow("userid") = Str(i)
		stResultSet\lsResultset()\mpResultrow("firstname") = "Garry"
		stResultSet\lsResultset()\mpResultrow("lastname") = "Miller"
		stResultSet\lsResultset()\mpResultrow("street") = "Glimmer Avenue 23"
		stResultSet\lsResultset()\mpResultrow("postcode") = "A4566"
		stResultSet\lsResultset()\mpResultrow("city") = "New York"
		stResultSet\lsResultset()\mpResultrow("active") = "1"
	EndIf
Next i

iTime = ElapsedMilliseconds()
ShowResult(@stResultSet)
Debug "Elapsed time in ms: " + Str(ElapsedMilliseconds() - iTime)

Edit: It has clearly to do with the output to the debug window.
If I redirect the output e.g. to an editor gadget, the loading and displaying of the data is done again in fractions of a second.

Maybe this post should be moved to the Forum Bugs?



Markus