Script Debugger Possible Data Leak

Script Debugger
#1

I have recently run into a few mysterious errors with Script Debugger’s debugger, I had another couple of problems yesterday and had a flash of insight with this one.

This code works (the entire script and all the libraries work) with Debugger mode off. With Debugger on I get an error here which is obvious bollocks

		    if (ScriptData's appDataStatus) and (1 ≤ (theAppData's imagesPerSecond)) then -- if the existing data is valid
				set cumImageCount to countProcessedImages + (theAppData's imageCount)
				set cumBatchCount to countEXIFtoolBatches + (theAppData's batchCount)
				set cumElapsedImageTime to ((theAppData's imageCount) / (theAppData's imagesPerSecond)) + (countProcessedImages / imageEXIFtoolRate)
				set cumElapsedBatchTime to ((theAppData's batchCount) / (theAppData's batchesPerSecond)) + (countEXIFtoolBatches / batchEXIFtoolRate)
				set cumImageRate to (cumImageCount / cumElapsedImageTime)
				set cumBatchRate to (cumBatchCount / cumElapsedBatchTime)
				log {theAppData's imagesPerSecond, cumImageRate}
				set theAppData's imagesPerSecond to cumImageRate
				--copy cumImageRate to (imagesPerSecond of theAppData)
				set theAppData's imageCount to cumImageCount

The log statement works perfectly and gives the following:
(100, 121.025249637964)
However, with debugger off the following line generates this error that stops execution
The variable imagesPerSecond is not defined.
The offending object is “‘utxt’(“imagesPerSecond”)”

This is obvious bollocks because the “imagesPerSecond” used in this line is a property name, not a variable, and it is defined and accessible, as evidenced by the previous line.

If I try the alternative copy command, I get the same problem.

If I turn debugger off, the script execution passes here, it executes the log statement and executes to the end without error.

After retiring in some some frustration, I started wondering if Script Debugger was mixing up labels.
I have a Global variable with one property named “imagesPerSecond”:
{imagesPerSecond:121.025249637964, imageCount:0, batchesPerSecond:16.0, batchCount:0}

There is also local variable “imagesPerSecond” which is is declared in a local statement above but undefined and unused at this stage of execution.(near end of second line)

	local imageEXIFtoolRate, batchEXIFtoolRate, imageEXIFtoolRateDisp, batchEXIFtoolRateDisp
	local elapsedOverheadTime, overheadTimeDisp, elapsedExecutionTime, roundedExecutionTime, imagesPerSecond, imagesPerSecondDisp
	local cumImageCount, cumBatchCount, cumElapsedImageTime, cumElapsedBatchTime, cumImageRate, cumBatchRate

The local variable refers to a slightly different quantity; I hadn’t had a chance to name them clearly yet.

I renamed the variables and properties more clearly and separately - the name of the property in the Global Variable and the name of the local variable are now different, and the problem has disappeared
Property–> EXIFtoolImageRate Local Variable → imagAvgRate.

Thee first snippet above is now as follows

	local imageEXIFtoolRate, batchEXIFtoolRate, imageEXIFtoolRateDisp, batchEXIFtoolRateDisp
	local elapsedOverheadTime, overheadTimeDisp, elapsedExecutionTime, roundedExecutionTime, imagAvgRate, imagesPerSecondDisp
	local cumImageCount, cumBatchCount, cumElapsedImageTime, cumElapsedBatchTime, cumImageRate, cumBatchRate

(next code irrelevant but included for completeness)

## calculate and update the application's performance data
	if validExifTimeAnalysis then -- -- if the new data is valid 
		set imageEXIFtoolRate to (1 / EXIFtimePerImage)
		set imageEXIFtoolRateDisp to U's roundDecimals((imageEXIFtoolRate), 0)
		set batchEXIFtoolRate to (1 / EXIFtimePerBatch)
		set batchEXIFtoolRateDisp to U's roundDecimals((batchEXIFtoolRate), 1)
		set EXIFtoolRateMessage to "EXIFtool Batch requests per second " & batchEXIFtoolRateDisp & ";   EXIFtool Images per second: " & imageEXIFtoolRateDisp

(below is where the problem used to occur

			if (ScriptData's appDataStatus) and (1 ≤ (theAppData's EXIFtoolImageRate)) then -- if the existing data is valid
			set cumImageCount to countProcessedImages + (theAppData's imageCount)
			set cumBatchCount to countEXIFtoolBatches + (theAppData's batchCount)
			set cumElapsedImageTime to ((theAppData's imageCount) / (theAppData's EXIFtoolImageRate)) + (countProcessedImages / imageEXIFtoolRate)
			set cumElapsedBatchTime to ((theAppData's batchCount) / (theAppData's EXIFtoolBatchRate)) + (countEXIFtoolBatches / batchEXIFtoolRate)
			set cumImageRate to (cumImageCount / cumElapsedImageTime)
			set cumBatchRate to (cumBatchCount / cumElapsedBatchTime)
			set theAppData's EXIFtoolImageRate to cumImageRate
			--copy cumImageRate to (EXIFtoolImageRate of theAppData)
			set theAppData's imageCount to cumImageCount

I have stopped ScriptDebugger and restarted it several times, and also copied the Applescript code to a new file without changing the problem behavior

I think this kind of problem might also be a potential data leak. I had an occurrence a few weeks where I copied my debugged and running script (related to this script) from ScriptDebugger to Script Editor, and pn the first run Script Editor said I had an uninitialized variable. I tracked it down, and it was in fact not initialized, but Script Debugger was running it without showing any error. I added a line to initialize the variable, but did not document the situation. Could be this confusion but in reverse.

MacOS 13.62, Script Debugger 8.06, Mac Studio M1 64GB

#2

I don’t think you can have a local variable and a global variable in the same handler of a script with the same name (including the implicit run handler). It’s not odd that it doesn’t work for you in SD with Debugging off, I think it’s odd that it works anywhere.

When I try to reproduce in ScriptDebugger, I get inconsistent results.

The first time I run it I get the same same error with debugging on.

If I note out the local declaration, no error.

(I think the log command is picking up the global variable, but the set command is looking for the local variable.)

If I paste it into a new script and run it without debugging, sometimes I get an error, sometimes not.

set theAppData to {imagesPerSecond:121.025249637964, imageCount:0, batchesPerSecond:16.0, batchCount:0}
set countProcessedImages to 1
set cumImageRate to 0
set cumImageCount to countProcessedImages + (theAppData's imageCount)
local imagesPerSecond
log {theAppData's imagesPerSecond, cumImageRate}
set theAppData's imagesPerSecond to cumImageRate
--copy cumImageRate to (imagesPerSecond of theAppData)
set theAppData's imageCount to cumImageCount

→ Mac OS: 12.7.1 (21G920)
→ Script Debugger 8.0.6 (8A69)

#3

Thank you for your quick reply, but that was not the situation. The Global variable and the local variable did not have the same name, and clearly that should never work.

The situation was that there was a global variable, “theAppData”, which is a record with some properties. One of the properties was named “samplesPerSecond”. There was also a local variable named “samplesPerSecond”.

I have not seen any constraint mentioned in Applescript documentation that properties of a record cannot be named the same as another variable.

Since I wrrote, I have copied the code into Script Editor, and it didn’t have any problem with the original version of tthe code

  • It executes correctly and without error in Script Editor
  • It executes correctly and without error Script Debugger with Debugger off
  • The Applescript log statement reports the records’s property and the variable differently and correctly, immediately before the error
  • The records’s property and the variable show correctly and separately in the variable inspection pane of Script Debugger with debugger mode on
#4

What may be happening is that at execution time the variable name and the property label are being confused.

At this point it would be helpful if you could post a reproducible example of this error occurring with the minimal amount of code.

Something along the lines of what I posted where your example only includes the lines of script necessary to reproduce.

That would help Mark and Shane see the issue.

#5

I think so too (40 years experience as a HW/SW/Systems engineer)
I will start work on a reduced example but it will take me a few days.

#6

I’m not sure if this is fully appropriate in this context, but the issue of local/global variable collisions has come up in the past:

2 Likes
#7

It may also be informative to change the name of the local variable and/or the property and see if it happens again.

#8

Hi Ed, I did change the variable and property names and saw the problem disappear. That is what triggered me to write this feedback in the first place (and I believe I did mention this in my original post).

I could have just left it and instituted a naming scheme for all my record properties so that there should never be a property - variable name overlap. I do use records quite a bit and this would be considerable work, but I also think that a debugger which gets confused about variable names has a credibility issue.

So I thought I would at least let LNS know about the issue in hopes that it could be put on the list of bugs to be fixed.

I’ve just got to fix up a bit of formatting and I will post the version you requested.

#9

Here is a version that demonstrates the problem with code and variables reduced to a minimum.
I got this by removing anything not related from the original application, and replacing everything returned from EXIFtool, CaptureOne and TextEdit by lists, records and numbers.

(**** Description
 A version ewduced for the purposes of demonstrating label confusion between a the name of a local variable and the name of a property in in a Global variable.
 
Yet to be determined what parts of this code are essential.
*)

use AppleScript version "2.4" -- Yosemite (10.10) or later
use scripting additions

on getScriptControl()
	
	local appDataDefaults
	
	set appDataDefaults to {imagesPerSecond:100, imageCount:0, batchesPerSecond:16.0, batchCount:0}
	
	return {appDataDefaults:appDataDefaults}
end getScriptControl

loadApplicationData()

executionHandler()


on executionHandler()
	
	global theAppData
	
	local countProcessedImages
	set countProcessedImages to 10
	
	local elapsedExecutionTime, imagesPerSecond -- renaming imagesPerSecond kills the error in Debug Mode
	local cumImageCount, cumBatchCount, cumImageRate, cumBatchRate
	
	
	set cumImageCount to 10
	set cumBatchCount to 2
	set cumImageRate to 192.367829783732
	set cumBatchRate to 12.588910615888
	
	
	log {theAppData's imagesPerSecond, cumImageRate} -- this always works
	set theAppData's imagesPerSecond to cumImageRate
	--copy cumImageRate to (imagesPerSecond of theAppData) --  this also fails in Debug Mode
	set theAppData's imageCount to cumImageCount
	set theAppData's batchesPerSecond to cumBatchRate
	set theAppData's batchCount to cumBatchCount
	
	## These two lines are not essentiaal to the problem (although one would think so)
	set elapsedExecutionTime to 0.201650977135
	set imagesPerSecond to (countProcessedImages / elapsedExecutionTime)
	
	return
end executionHandler

on loadApplicationData()
	
	global theAppData
	
	tell getScriptControl() to copy its appDataDefaults to theAppData
	
end loadApplicationData
#10

It appears to be a scope conflict. The edge cases in AppleScript are a nightmare, with local variables, explicitly-declared global variables, undeclared variables, objects declared within handlers, and top-level entities having subtly different and often unexpected rules.

Wrapping the property name in pipes resolves the scoping issue in debug mode. The fact that the pipes don’t disappear on compilation indicates that there’s more than one cumImageRate. I will try to see if I can figure out what’s going on.

set theAppData's |imagesPerSecond| to cumImageRate

Removing the explicit local declaration for cumImageRate also resolves the issue.

The best description of scoping rules I’ve read are in Chapter 10 of AppleScript: The Definitive Guide (2e) by Matt Neuberg.

#11

It looks like it’s a bug in Script Debugger’s debug mode that occurs when the same-named variable is declared as a local but not assigned an initial value. It doesn’t occur in Script Debugger’s normal mode or in Script Editor.

Here’s a further reduced example:

set R to {x:1}
local x

#set x to 6 -- Assign an initial value to local x.
set R's x to 3

return R -- Weirdly, commenting out this line also stops the error from appearing.

This will trigger the error when debug mode is active.

Notes for @alldritt and @ShaneStanley:

  • Assigning an initial value to x (set x to 6) or removing the explicit local declaration for x (local x) will stop the bug from occurring.
  • In this example, if you put pipes around x in set R's x to 3, the pipes will disappear on compilation, however the resulting script will not trigger the bug until the script is recompiled, even though the compiled text is identical.
  • If there are no lines of code after set R's x to 3, the bug does not trigger. I have no explanation for this whatsoever. However, I do note that Script Debugger highlights the line after the error, rather than the same line as the error like it normally does.
1 Like
#12

Thanks for that. I was trying to reduce the issue as well and kept getting inconsistent results, where sometimes it would not error out, and this explained that.

1 Like
#13

Yes, very strange. I wonder if it’s because Script Debugger is mistakenly trying to highlight the line after the error… if there’s no further lines of executable code, it doesn’t display the error message.

#14

@alldritt and @ShaneStanley – just wanted to make sure you were aware of this (looks like a bug). I tagged you above in an edit, but I’m not sure if that sends you a notification. Thanks.

#15

The discussion here has been really valuable to me.
I now understand what’s going on clearly and learned some stuff about Applescript as well.
I can easily detect when its happening, and the fix is simple.
I’m no longer worried about this.

3 Likes
ANNOUNCE: Script Debugger 8.0.7 (8A73)
ANNOUNCE: Script Debugger 8.0.7 (8A76)
ANNOUNCE: Script Debugger 8.0.7 (8A75)
#16

Thank you for providing such a clear and simple example of the problem.

Script Debugger is indeed failing. The problem is that Script Debugger incorrectly thinks the local x has been assigned a value through the set R's x to ... statement when in fact it has not. Because the local version of X has not been assigned a value, the hidden instrumentation code Script Debugger inserts into your script fails when I tries to sample the value of the local x. If you give the local x a value before the set R's x to ... statement the problem goes away (is masked).

The reason the final statement (R) causes the error to appear is that Script Debugger’s instrumentation code executes between the set ... and R statements and fails. If the final statement is commented out then the problematic instrumentation code is not inserted and thus the Script Debugger failure does not take place.

In the meantime, if you give the local x a value before the

1 Like