Hammerspoon: Memory leak in hs.osascript

Created on 10 Nov 2018  路  19Comments  路  Source: Hammerspoon/hammerspoon

I noticed recently that Hammerspoon's memory footprint on my computer seemed to be growing over time. After doing some investigating using lua-mtrace I tracked down the issue to a line in one of my spoons that calls hs.osascript.javascript.

Here's a minimal line of code to run in the Hammerspoon console to reproduce the behavior:

test = hs.timer.doEvery(0.5, function() hs.osascript.javascript("") end)

If you open Activity Monitor and go to the Memory tab, you'll see that Hammerspoon's memory footprint grows as this timer is running. Running test:stop() to stop the timer stops the memory footprint from increasing.

When the timer is running the lua-mtrace log fills up with lines like this,

@ ....app/Contents/Resources/extensions/hs/osascript/init.lua:101 + 0x600002ad59f0 0x50 s

which corresponds to this line,

local ok, object, descriptor = module._osascript(source, "JavaScript")

which calls the runosascript() function in the internal.m file for the module.

Profiling with Xcode using Instruments confirms this. Here's the "Heaviest Stack Trace" for runosascript() after running the timer for a minute or so, in case that's helpful:

  56 libdyld.dylib   86.81 MB     start
  55 Hammerspoon   86.81 MB     main /Users/malo/Documents/Code/Hammerspoon/hammerspoon/Hammerspoon/MJAppDelegate.m:364
  54 AppKit   86.81 MB     NSApplicationMain
  53 AppKit   85.24 MB     -[NSApplication run]
  52 AppKit   83.46 MB     -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]
  51 AppKit   83.36 MB     _DPSNextEvent
  50 HIToolbox   65.46 MB     _BlockUntilNextEventMatchingListInModeWithFilter
  49 HIToolbox   65.46 MB     ReceiveNextEventCommon
  48 HIToolbox   65.46 MB     RunCurrentEventLoopInMode
  47 CoreFoundation   65.38 MB     CFRunLoopRunSpecific
  46 CoreFoundation   65.04 MB     __CFRunLoopRun
  45 CoreFoundation   29.00 MB     __CFRunLoopDoTimers
  44 CoreFoundation   29.00 MB     __CFRunLoopDoTimer
  43 CoreFoundation   29.00 MB     __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__
  42 Foundation   28.86 MB     __NSFireTimer
  41 internal.so   28.86 MB     -[HSTimer callback:] /Users/malo/Documents/Code/Hammerspoon/hammerspoon/extensions/timer/internal.m:51
  40 LuaSkin   28.86 MB     -[LuaSkin protectedCallAndTraceback:nresults:] /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/LuaSkin/Skin.m:244
  39 LuaSkin   28.86 MB     lua_pcallk /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/lua-5.3.5/src/lapi.c:969
  38 LuaSkin   28.86 MB     luaD_pcall /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/lua-5.3.5/src/ldo.c:746
  37 LuaSkin   28.86 MB     luaD_rawrunprotected /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/lua-5.3.5/src/ldo.c:156
  36 LuaSkin   28.86 MB     luai_objcttry /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/LuaSkin/lobjectivec_exceptions.m:84
  35 LuaSkin   28.86 MB     f_call /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/lua-5.3.5/src/lapi.c:943
  34 LuaSkin   28.86 MB     luaD_callnoyield /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/lua-5.3.5/src/ldo.c:526
  33 LuaSkin   28.86 MB     luaD_call /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/lua-5.3.5/src/ldo.c:516
  32 LuaSkin   28.86 MB     luaV_execute /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/lua-5.3.5/src/lvm.c:1134
  31 LuaSkin   28.86 MB     luaD_precall /Users/malo/Documents/Code/Hammerspoon/hammerspoon/LuaSkin/lua-5.3.5/src/ldo.c:451
  30 internal.so   28.86 MB     runosascript /Users/malo/Documents/Code/Hammerspoon/hammerspoon/extensions/osascript/internal.m:26
  29 OSAKit   28.79 MB     -[OSAScript compileAndReturnError:]
  28 OpenScripting   28.33 MB     OSACompile
  27 JavaScript   28.07 MB     JavaScriptComponent
  26 CoreFoundation   28.07 MB     -[NSInvocation invoke]
  25 CoreFoundation   28.07 MB     __invoking___
  24 JavaScriptOSA   28.07 MB     -[JSStorage(JSProcedures) compileScriptData:modeFlags:scriptID:]
  23 JavaScriptOSA   28.07 MB     -[JSStorage addScript:]
  22 JavaScriptOSA   28.00 MB     -[JSStorageScriptContext initWithScript:]
  21 JavaScriptAppleEvents   28.00 MB     JSAEContextSetup
  20 JavaScriptAppleEvents   26.96 MB     JSAEExports
  19 JavaScriptAppleEvents   14.77 MB     JSAEApplicationConstructor
  18 JavaScriptAppleEvents   14.02 MB     JSAEApplicationPrototypeCreate
  17 JavaScriptAppleEvents    8.09 MB     JSAELibraryConstructor
  16 JavaScriptAppleEvents    7.60 MB     JSAELibraryPrototypeCreate
  15 JavaScriptAppleEvents    6.31 MB     JSAEObjectSpecifierConstructor
  14 JavaScriptAppleEvents    6.07 MB     -[JSValue(DefineProperties) defineProperties:]
  13 JavaScriptCore    6.07 MB     -[JSValue invokeMethod:withArguments:]
  12 JavaScriptCore    6.07 MB     objectToValue(JSContext*, objc_object*)
  11 JavaScriptCore    6.07 MB     ObjcContainerConvertor::convert(objc_object*)
  10 JavaScriptCore    6.07 MB     objectToValueWithoutCopy(JSContext*, objc_object*)
   9 JavaScriptCore    6.07 MB     -[JSContext(Internal) wrapperForObjCObject:]
   8 JavaScriptCore    6.07 MB     -[JSWrapperMap jsWrapperForObject:inContext:]
   7 JavaScriptCore    6.07 MB     -[JSObjCClassInfo wrapperForObject:inContext:]
   6 JavaScriptCore    3.24 MB     -[JSContext(Internal) wrapperForJSObject:]
   5 JavaScriptCore    3.24 MB     -[JSWrapperMap objcWrapperForJSValueRef:inContext:]
   4 Foundation    3.24 MB     -[NSConcreteMapTable setObject:forKey:]
   3 Foundation    3.21 MB     -[NSConcreteMapTable grow]
   2 Foundation    1.61 MB     allocateCollectableUnscannedStorage
   1 libsystem_malloc.dylib    1.61 MB     malloc
   0 libsystem_malloc.dylib    1.61 MB     malloc_zone_malloc

Most helpful comment

We do run hs.osascript scripts on the main thread (easy way to tell - it's called by Lua->C and we only ever run Lua on the main thread. Secondary way to tell, there's a [LuaSkin shared] in the function - that will abort() if it's not called on the main thread).

I think the reality here is that these scripting frameworks are not super well cared for these days, and they are crashy and leaky. On that basis, our only options here are to just accept it as it is, or create some kind of helper binary that we spawn for each OSAScript execution, so its leak/crash problems don't infect our binary, but we currently don't have any of the build-time or run-time mechanisms needed for helper binaries.

All 19 comments

@malob - Thanks so much for introducing me to lua-mtrace - I think that's going to be VERY helpful!

In regards to the leak, @cmsj or @asmagill, because of this line of code:

OSAScript *osa = [[OSAScript alloc] initWithSource:source language:[OSALanguage languageForName:language]];

...does this mean we need a [osa release] somewhere in there?

So I was playing around and it seems that we can't do something like [osa release] since Automatic Reference Counting is in use. I tried wrapping the code in the runosascript() function in a @autoreleasepool block, but that didn't help.

I was suspicious that the memory leak was in Apple's framework, and did some googling around. I seems that NSAppleScript did some a memory leak issue that seems to have never been resolved, but it seems people are under the impression that it isn't present in OSAScript.

I know very little Objective-C, so I don't really understand how memory allocation works. As such, I'm not sure what to try next. My naive hunch is that the issue has something to do with how LuaSkin manages memory, but I really don't know what I'm talking about 馃槢.

Curious... Does this make any difference?

local timer = require("hs.timer")
local osascript = require("hs.osascript")
test = timer.doEvery(0.5, function() local result = osascript.javascript("") end)

@latenitefilms, nope, same things happens.

I just tried running the following commands one at a time in this order while observing the memory allocation and didn't see any of the memory getting freed up:

test:stop()
test = nil
collectgarbage()
timer = nil
collectgarbage()
osascript = nil
collectgarbage()

Ummm, well until @cmsj or @asmagill jump in, I guess one possible workaround is to trigger your JavaScript code via hs.task or hs.execute?

Hmmm I that might work. I'm using it like you would in place of AppleScript to automate changing some system settings. E.g.:

local function setSystemDM(state)
  return hs.osascript.javascript(
    string.format(
      "Application('System Events').appearancePreferences.darkMode.set(%s)",
      state
    )
  )
end

Though I think I can also run that via the command line. I'll look into that. Thanks!

(Also just worth noting hs.osascript.applescript() has the same memory leak issue.)

Does this issue affect the hs.spotify commands? My assumption is that they are using the applescript spotify interface behind the scenes, but I don't know.

I just glanced at the hs.spotify code and it definitely is using AppleScript. As such, I'd assume Hammerspoon's memory footprint would increase every time a function from that extension is called, but I haven't actually tested it.

Any thoughts on this @cmsj ?

I've been running into this as I pretty heavily use apple script for spotify, chrome, etc. I notice the issue when my whole machine starts slowing down. Reloading hammerspoon seems to temporary resolve it, so until this is fully resolved, this restart binding might be helpful to others:

hs.hotkey.bind({'ctrl', 'cmd'}, 'delete', function() hs.reload() end)

@malob I wonder if this is an issue with hs.timer rather than hs.osascript specifically.

Does this have the same issues?

print(collectgarbage("count"))
local timer = require("hs.timer")
local osascript = require("hs.osascript")
for i=1, 100 do
local result = osascript.javascript("")
end
collectgarbage()
collectgarbage()
print(collectgarbage("count"))

This link may or may not be relevant: NSTimers causing leaks.

@latenitefilms, I don't think so. I had wondered if that might be the issue, so I tried the following from the console,

for i = 1, 1000, 1 do hs.osascript.javascript("") end

which ends up allocating about 1 GB of memory according to Activity Monitor.

Running the code you suggested above seems to allocate about ~100 MB of memory according to Activity Monitor. The output is:

2018-12-10 12:43:36: 6466.8173828125
2018-12-10 12:43:36: 6462.1455078125

@malob - Just for fun, it might be worth trying to turn off automatic reference counting for the osascript extension and add in the release code just to see what happens?

I wonder if the leak is actually within NSAppleEventDescriptor+Parsing.m, rather than internal.m? I can't see anything obvious, but I haven't had a chance to do any proper testing.

Hopefully @asmagill might be able to have a quick look at this issue over the holiday break.

@latenitefilms, seems worth trying 馃檪. I won't have time to play around for a little while, but I'll let you know if I get the chance.

@malob - I tried disabling automatic reference counting for hs.osascript and manually releasing osa, but it had no impact. Every time I executed:

for i = 1, 1000, 1 do hs.osascript.javascript("") end

...memory usage would climb dramatically.

I'm guessing this might actually be a bug in Apple's framework? Thoughts @asmagill ?

Here's some screenshots of Instruments for anyone who cares:

screen shot 2018-12-16 at 4 30 54 pm

screen shot 2018-12-16 at 5 07 58 pm

This might be relevant:

https://stackoverflow.com/questions/948380/why-does-nsapplescripts-compileandreturnerror-always-succeed?rq=1

Maybe OSAScript needs to run on the main thread?

We do run hs.osascript scripts on the main thread (easy way to tell - it's called by Lua->C and we only ever run Lua on the main thread. Secondary way to tell, there's a [LuaSkin shared] in the function - that will abort() if it's not called on the main thread).

I think the reality here is that these scripting frameworks are not super well cared for these days, and they are crashy and leaky. On that basis, our only options here are to just accept it as it is, or create some kind of helper binary that we spawn for each OSAScript execution, so its leak/crash problems don't infect our binary, but we currently don't have any of the build-time or run-time mechanisms needed for helper binaries.

Thanks for the detailed explanation @cmsj - very much appreciated!

I guess one potential workaround would be to use hs.task and the osascript terminal command?

Maybe one solution could be to add an optional "asynchronous" boolean to the hs.osascript.applescript and hs.osascript.javascript parameters, which then uses hs.task instead of the Objective-C OSAScript Framework? We could then add a note in the notes section that says that if you're having memory issues with the standard hs.osascript.applescript and hs.osascript.javascript functions that maybe the asynchronous will be a better option?

Or maybe the AppleScript-ObjC bridge is worth exploring?

Related: https://stackoverflow.com/a/48671690

Was this page helpful?
0 / 5 - 0 ratings

Related issues

luckman212 picture luckman212  路  4Comments

jasonrudolph picture jasonrudolph  路  4Comments

zhenwenc picture zhenwenc  路  4Comments

dasmurphy picture dasmurphy  路  4Comments

BigSully picture BigSully  路  3Comments