Hammerspoon / hammerspoon

Staggeringly powerful macOS desktop automation with Lua
http://www.hammerspoon.org
MIT License
12.09k stars 582 forks source link

General slowness after a while, how to debug? #2605

Open Madd0g opened 3 years ago

Madd0g commented 3 years ago

I noticed that after a few hours/days, HS becomes sluggish until I reload the config, then it's fast again.

I'm doing tons of things, using many parts of the api with a lot of custom code. HS is my command center.

It's running a low-traffic internal webserver, IPC, running processes every few secs, drawing on the screen, running applescript, using axuielement every few secs, updating menus every few secs, watching battery/power, parsing json/xml, lots of timer, hotkey, window, app-related handling.

I'm wondering if I can somehow pinpoint the areas of my code that are causing the sluggishness? Should I convert hs.drawing to hs.canvas if I'm putting things on the screen 10-15 times a minute? Any cleanup related advice for variables, timers, processes, other things? I'm pretty much a beginner in lua.

Thanks

cmsj commented 3 years ago

is there a significant difference in RAM usage between the sluggish state and the reloaded state?

Madd0g commented 3 years ago

I see the Hammerspoon process gaining about 100MB a day. No sluggishness so far.

but as I was watching the process I noticed other things:

  1. I'm calling hammerspoon from Karabiner-Elements with the /usr/local/bin/hs -c "<LUA CODE>" command line, but I see dozens of hanging hs processes in activity monitor. Some don't seem to close after the code they run? Can I somehow force them to quit? (I just started doing this since it's much much faster than doing the same with applescript)
  2. Same thing with processes I start from HS, I see tons of them even though the code is supposed to kill the ones that don't quit on their own:
local mod = {}
local timer = nil

function mod.start()
    timer = hs.timer.doEvery(8, function ()
        -- I copied this termination example from somewhere
        if mod._task and mod._task:isRunning() then
            print("+++ powermetrics task taking too long; killing it!")
            mod._task:terminate()
        end
        local cmd = "/usr/bin/sudo"
        mod._task = hs.task.new(cmd, function(ret, out, err)
            if ret == 0 then
                -- do things
            else
                print(err)
            end
        end, {
            "-A", "/usr/bin/powermetrics", "-n", "1", "-i", "1", "-f", "plist"
        }):start()
    end)

end

function mod.stop()
    timer.stop(timer)
    timer = nil
end

return mod

Can you see anything wrong in the above? I do see the message about killing the process in the console once in a while.

Madd0g commented 3 years ago

I spoke too soon, it's around 700MB (starts around 170) now and animations are getting slower and slower... also got this in the console (after calling HS from Karabiner):

ERROR:   LuaSkin: hs.ipc:callback - error during callback for Hammerspoon: ...rspoon.app/Contents/Resources/extensions/hs/ipc/init.lua:416: ipc port is no longer valid
stack traceback:
    [C]: in method 'sendMessage'
    ...rspoon.app/Contents/Resources/extensions/hs/ipc/init.lua:416: in function 'hs.ipc.internal.__defaultHandler'

Also, I see in activity monitor that the hammerspoon process has a big number of ports, 4th on the list of processes sorted by ports, don't know what that means.

after reload I see 1.7k but just before I had to reload it was showing 8k.

luckman212 commented 3 years ago

@Madd0g that code sample above... what exactly are you hoping it will do? One thing I noticed there is hs.task.new() calls sudo with the -A parameter (askpass mode). If your environment doesn't have the SUDO_ASKPASS variable set to a command that returns your root password, then this will fail.

Madd0g commented 3 years ago

@luckman212 - it does work, I put the powermetrics command in the sudoers file based on advice in this thread and it doesn't ask for a password.

It's really strange though, the higher the CPU usage, the more this process gets stuck and never exits. I wonder if _task:terminate() doesn't work because of the sudo trick

luckman212 commented 3 years ago

Ok, well the -A flag is for askpass so I would take that out and retest. I don't think it's needed when adding exceptions in sudoers.

Madd0g commented 3 years ago

I retested without the -A flag, no difference.

But now I know exactly how to repro the powermetrics hanging process - I run one of my project builds that creates very high CPU while building for about 40 seconds. During that time the timer runs 3-4 times but leaves behind 1-2 processes.

I tried running the same command from the terminal under the same high CPU conditions and I don't see it get stuck, it always quits.

luckman212 commented 3 years ago

I'm still not sure exactly what this Spoon is supposed to do, but:

Madd0g commented 3 years ago

yeah powermetrics does its polling on interval (5s) by default and never stops, but if you pass -n 1 -i 1 it samples for just 1ms and quits.

I would actually prefer to only launch it once, but the API docs say hs.task is not meant for tasks that keep streaming data.

I am not sure exactly what the desired output is here

I'm reading some values from the output, fan speed and process list.

Madd0g commented 3 years ago

yeah, that's a good point about mod._task:terminate(), I wasn't even thinking that in order to send a SIGTERM to the process you need any kind of additional auth.

gineer01 commented 3 years ago

I used to have a similar slowness issue (Hammerspoon could take up to multiple GB of memory) and managed to track it down to #1980 . You might want to check if your config or any Spoon you use have Applescript. I have to ban hs.osascript and any module/spoon using it with this code in my config.

hs.osascript = "DO NOT USE. MEMORY LEAK."
hs.itunes = "DO NOT USE. MEMORY LEAK." -- it uses osascript
Madd0g commented 3 years ago

@gineer01 - that's interesting, I recently switched the most frequent thing I was doing with applescript to use axuielement. so basically I reduced my applescript usage by at least 90%, but the slowness got more frequent.

the only applescript that is left are things that I trigger maybe 2-3 times a day.

Madd0g commented 3 years ago

so I've been checking activity monitor every time before restarting HS. memory doesn't not seem like a big indicator, but again the "Ports" number is always high when I check (about 4x than the number at startup).

from this page it says:

These are Not network ports.

macOS is built on top of the Carnage Mellon MACH kernel, and processes talk to the MACH micro kernel and between each other using 'ports'.

I recently started using IPC and the hs command line a lot (I trigger hammerspoon with it from Karabiner-Elemenents), could that be related? it opening some connection but never closing it?

EDIT: another thing about my usage of the hs CLI tool - after I noticed the hanging processes, I changed my code like this and that eliminated the hanging hs process.

- /usr/local/bin/hs -c \"%s\"
+ /usr/local/bin/hs -c \"return %s\"

just adding that return seemed to allow the hs processes to close, I'm not sure where I got this solution from, but it solved that problem.