I haven't observed this myself, though my plugins that execute scripts do a lot more work in the script itself, so I probably wouldn't have noticed.
Have you timed it in LR 5 or LR 4? It would be interesting to know if this is version-specific (though the chances of it getting "fixed" are vanishingly small).
The obvious workaround is to write a batch script that handles multiple photos per call to execute(), to amortize the cost of invocation. It's pretty easy to invoke Exiftool that way, though properly handling errors in processing files takes extra care.
I tested LR5, it's 22ms per call. Tested LR6 again, it's 130ms per call. Quite a difference, and it really adds up with lots of photos. Lightroom was using 100% CPU during the test (= single core). And, btw. these testes were run on a Mac, but isn't the Lightroom tradition that Windows version is always slower...
I know exiftool has batch mode, but this is not exiftool I guess I have to implement some kind of batch mode, its not really worth waiting 2 minutes for just scripts to start.
I ran your test on my Macbook Pro with native OS 10.10.3 and Windows 8.1 running in Parallels, each measurement the average of 3 runs of your script:
Version Mac Windows 5.7.1 12.4 ms 22.8 ms 6.0 25.0 ms 22.6 ms 5.7.1/6.0 0.50 0.99
Much different than your results. The 50% slow-down on Mac is suspicious (but much less than what you measured). Is it possible you still have background tasks running in your LR 6, e.g. building previews, face indexing, or some plugin doing background stuff? I.e. is the CPU close to idle before you start your timing?
isn't the Lightroom tradition that Windows version is always slower...
I think that was the folklore many versions ago. In LR 3, the API calls involving multiple tasks (e.g. having to be run on a separate task) took roughly 5-10 times longer on Windows than on Mac. When we pointed out that LrTasks.yield() was similarly slower on Windows, one of the lead engineers tracked it down to a slower implementation of Lua tasks on Windows and fixed the problem in LR 4.
Interesting results indeed. I'm running Macbook Pro 13" Retina Late 2013. CPU usage is idle both before and after benchmark (Lightroom eating around 1-2% CPU just for kicks).
Now I deleted presets, preferences and all plugins. execute() runs in 25ms. I added all my own created plugins, still around same (28ms). I guess it's either the number of plugins, or some other plugin that breaks the camel's back.
Anyway, 20+ms per invocation is a still bit more than I would like, so maybe the final conclusion is that one should avoid extra calls to execute(). It is not as fast as one would expect on 21st century.
It is not as fast as one would expect on 21st century.
As a point of comparison, executing a shell script with 1000 /usr/bin/true lines takes 1.26 seconds, or 1.26 ms per /usr/bin/true, 20x faster. I think we're paying for a Lua-based API that's had little love and attention from a core systems engineer for a number of years.
I've done some more testing, it looks like there is some kind of internal problem with Lightroom.
I've installed one single plugin to run the benchmark. Starting fresh Lightroom 6.1.1, it is running 25ms per execute call.
Now, if I open LR plugin manager 20 times by repeatedly pressing cmd+shift+option+. and enter to close dialog.
Now, same benchmark runs 50ms per execute call.
The increase in in execution time is unrelated to reloading the plugin in the plugin manager. Rather, LrTasks.execute() just slows down the more you call it.
In LR CC 2015.1.1 / OS X 10.10.4, I timed LrTasks.execute() running continuously for over an hour, in three different catalogs, with no other plugins enabled. One catalog was empty, one had 200 photos, and one had 25K photos.
Here’s a plot of the seconds per call versus the number of seconds since the start:
Here’s the same plot, but with a moving average used to smooth the lines:
On all three catalogs, the seconds/call starts at 0.01 or 0.02 but zooms up to 0.03–0.05 within a minute or so. Then for the empty catalog, after about 47 minutes, seconds/call drops back down to about 0.013; for the catalog with 200 photos, it drops from 0.05 to 0.03 after 25 minutes.
In all three catalogs, seconds/call exhibits regular fluctuations, with a period of about 150 seconds for the empty catalog, 360 seconds for the 200-photo catalog, and 65 seconds for the 25K catalog.
This suggests that LrTasks.execute() may be competing with background housekeeping threads in LR. Perhaps these threads are holding a lock or some other critical resource.
Another hypothesis is that these fluctuations may be partially caused by garbage collection and memory allocation. In particular, I’m wondering if there’s some bad behavior with respect to weak references being used to manage open file handles. It’s conceivable that a mediocre implementation of weak references takes time proportional to the amount of memory allocated. The empty catalog ended up with 212 MB allocated, the 200-photo catalog with 307 MB, and the 25K-photo catalog with 1 GB.
local n = 100 LrTasks.startAsyncTask (function() local start = LrDate.currentTime () local i = 0 while true do local t = LrDate.currentTime () for j = 1, n do LrTasks.execute ("/usr/bin/true") i = i + 1 end local t = LrDate.currentTime () - t Debug.logn (i, LrDate.currentTime () - start, t / n) end end)