Hammerspoon / hammerspoon

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

hs.timer.doEvery() is unreliable when the computer is asleep #1942

Open nloveladyallen opened 5 years ago

nloveladyallen commented 5 years ago

I made a custom clock for my menu bar and set a timer to update it every 10 seconds with hs.timer.doEvery(10, updateTimeMenulet), but sometimes when waking up from sleep, it will no longer update, showing a time between when the computer went to sleep and when it woke up. I added a log message to the update function and found that it also stops updating for hours at a time while the computer is asleep:

[...]
2018-09-23 07:05:43: 07:05:43       init: Updating menulet
2018-09-23 07:05:53: 07:05:53       init: Updating menulet
2018-09-23 07:06:03: 07:06:03       init: Updating menulet
2018-09-23 08:52:20: 08:52:20       init: Updating menulet
2018-09-23 08:52:30: 08:52:30       init: Updating menulet
2018-09-23 08:52:40: 08:52:40       init: Updating menulet
[...]

Could be related to #1886.

cmsj commented 5 years ago

I think the timer not firing while the computer is asleep, is what I would expect to happen. It should start firing again once the machine wakes up. Are you capturing the hs.timer object returned by doEvery() somewhere? If not, it could be getting garbage-collected.

kimjianzsu commented 5 years ago

I used to have a similar issue while using hs.timer.doEvery(60, someFn). I printed out some logs and found that the timer lived for ~40 minutes and then quit.

I read through API doc https://www.hammerspoon.org/docs/hs.timer.html#doEvery , and found a hint from the note: "This function is a shorthand for hs.timer.new(interval, fn):start()"

So I thought the root cause of this issue was because the timer object created by hs.timer.doEvery was assigned to a local variable implicitly in hammerspoon framework and got reclaimed by Lua Garbage Collector later (that's why it usually stopped working after 40 minutes)

Now I assign the timer to a global variable and it works pretty well, never stops!!!!! myTimer = hs.timer.new(60, someFn) myTimer:start()

latenitefilms commented 5 years ago

Huh. That’s weird.

myTimer = hs.timer.doEvery(60, someFn)

...should be identical to:

myTimer = hs.timer.new(60, someFn):start()

I can’t any any obvious bugs in the code that would cause unwanted garbage collection.

Thoughts @cmsj?

cmsj commented 5 years ago

hs.timer.doEvery() couldn't be any simpler:

module.doEvery = function(...)
  return module.new(...):start()
end

@kimjianzsu were you capturing the output of doEvery() in a global variable before?

nloveladyallen commented 5 years ago

@kimjianzsu 's fix solved my problem.

cmsj commented 5 years ago

I'm going to re-open this since it seems like there may be a deeper problem here.

wwwjfy commented 4 years ago

Not sure why but this started to happen to me too recently and it had been working fine for long.

I have timers set up to popup for example at specific time every day, and it works fine until I let display sleep (pmset displaysleepnow), not computer sleep, and the timer is "delayed".

And it's not Hammerspoon issue, but macOS issue. I'm not sure if it's related to macOS version upgrade, because before some time, it worked just fine.

I wrote a simple app to demonstrate it:

import Cocoa

let dateFormatter: DateFormatter = {
    let formatter = DateFormatter()
    formatter.dateFormat = "yyyy-MM-dd'T'HH:mm:ss"
    formatter.timeZone = TimeZone(identifier: "Asia/Singapore")
    return formatter
}()

class HSTimer {
    var timer: Timer?
    let interval: TimeInterval
    let repeats: Bool

    init(interval: TimeInterval, repeats: Bool) {
        self.interval = interval
        self.repeats = repeats
    }

    @objc
    func callback(timer: Timer) {
        self.log(str: "timer callback triggered")
        self.log(str: String(format: "firedate is now %@", dateFormatter.string(from: timer.fireDate)))

        if (!timer.isValid) {
            self.log(str: "timer is invalid")
            return
        }
        self.log(str: "timer callback finished")
    }

    func start() {
        self.log(str: String(format: "create timer with interval %lf repeat %d", self.interval, self.repeats))
        self.timer = Timer.scheduledTimer(timeInterval: self.interval, target: self, selector: #selector(callback(timer:)), userInfo: nil, repeats: self.repeats)
    }

    func log(str: String) {
        print(dateFormatter.string(from: Date()), str)
    }
}

@NSApplicationMain
class AppDelegate: NSObject, NSApplicationDelegate {

    @IBOutlet weak var window: NSWindow!

    func applicationDidFinishLaunching(_ aNotification: Notification) {
        // Insert code here to initialize your application
        let timer = HSTimer(interval: 3600, repeats: true)
        timer.start()
    }
}

It stopped triggering when display sleeps:

2020-07-02T02:07:32 timer callback triggered
2020-07-02T02:07:32 firedate is now 2020-07-02T02:07:32
2020-07-02T02:07:32 timer callback finished
2020-07-02T03:07:32 timer callback triggered
2020-07-02T03:07:32 firedate is now 2020-07-02T03:07:32
2020-07-02T03:07:32 timer callback finished
2020-07-02T09:59:08 timer callback triggered
2020-07-02T09:59:08 firedate is now 2020-07-02T04:07:32
2020-07-02T09:59:08 timer callback finished
wwwjfy commented 4 years ago

I think I figured out the reason. The system goes to sleep a while after display sleeps. I tried to monitor the events and got NSWorkspaceWillSleepNotification.

This pauses the NSTimer. I think we'll need to listen to the event and recalculate next fire time to make it accurate. The functions won't be triggered when it's sleeping, still. But that should be expected.

wwwjfy commented 4 years ago

My current workaround is to prevent computer from sleeping. In System Preference => Energy Saver, tick Prevent computer from sleeping automatically when the display is off.

I think at least we should write down such behavior in hs.timer document to avoid surprise. I'll submit a PR.

asmagill commented 4 years ago

Do the timers resume (though with a skewed next fire time) when the machine wakes up? I would assume that truly missed times would be lost (e.g. if the system was asleep for a duration in which it should have fired 10 times, those 10 are skipped), but I think I read that NSTimer is supposed to make a good faith effort to get back on track when the system wakes up... forget where, though, so if you're saying that they don't resume, I'll try and find it again... I think it was in a document that described alternatives to NSTimer that are a supposed to be more energy efficient (but with a loss of precision -- you specify more of a "not before" time rather than a "trigger at" time).

wwwjfy commented 4 years ago

It will resume. In some cases it doesn't matter much, like hourly tasks. But if I want to execute something at say 10AM every day, it's not usable when it's triggered randomly during a day. 😅This would be what I expect doAt does.

The energy efficient thing you said is another feature I believe, App Nap, or Timer tolerance

asmagill commented 4 years ago

Interesting...I wonder what happens to the fireDate property on the object when this occurs (probably nothing and it's only when it's set that anything changes with the internal counter, but this is an educated guess at the moment)... yeah, it sounds like we'll need an array of current timers and then check to see on wakeup which ones need resetting.

For the example you cite, if the machine was asleep at 10AM and then awoken at say 11, what would you want to happen? Should the missed timer be fired immediately, or should it be skipped (but if it's a repeating timer, make sure the next fire time is adjusted to be correct)?

I can see a case for both, so I suspect we should add a flag... yeah, this will take some thought and at least a little work, so I agree that in the short term, the change of documentation should be implemented. @cmsj, I think the proposed addition in #2414 should be approved, but I await your thoughts before merging it.

wwwjfy commented 4 years ago

Yes, no change to fireDate (I had my little experimental app, and log pasted in the earlier comment)

what would you want to happen?

I agree there is no single correct answer for every user and every case. But the adjustment can be done regardless. To make things simpler, we can start by skipping it (maybe a warning in the log when we detect such)

leafac commented 3 years ago

In my use case the issue was garbage collection. I assigned the timer to a global variable and that fixed it. Here’s the code:

local dateAndTime = hs.menubar.new():setClickCallback(
                        function() hs.application.open("Calendar") end)
dateAndTimeTimerToPreventGarbageCollection =
    hs.timer.doEvery(1, function()
        dateAndTime:setTitle(os.date("%Y-%m-%d  %H:%M  %A"))
    end)

Note that I’m not doing .new() then :show(), as proposed above, because doEvery() returns the timer.

Here’s an idea: Hammerspoon could keep an internal table of references to timers. It wouldn’t actually do anything with these references, but just keep them around to prevent timers from being garbage collected. If you think that keeping timers around forever could be a problem maybe they could be removed from the table on :stop().

wwwjfy commented 3 years ago

@leafac it's not the same issue. I think you should raise another one.

leafac commented 3 years ago

@wwwjfy: Can you please clarify? My comment about garbage collection is related to this comment above.

wwwjfy commented 3 years ago

This issue is about unreliably triggered timers when system is sleeping according to the title. GC will remove timers completely. So they are different. We shouldn't mix them in one thread.

On Sat, Oct 31, 2020, at 18:16, Leandro Facchinetti wrote:

@wwwjfy https://github.com/wwwjfy: Can you please clarify? My comment about garbage collection is related to this comment above https://github.com/Hammerspoon/hammerspoon/issues/1942#issuecomment-430450705.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Hammerspoon/hammerspoon/issues/1942#issuecomment-719913511, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAA64P36YTHLYBJ3OGY4BR3SNPPY3ANCNFSM4FWW7DIA.

-- BR, Tony

Etheryte commented 1 year ago

I've recently run into the same problem (on Ventura), where the timer would sometimes (but not always) not resume after the system wakes from sleep.

The workaround I'm currently using is to wrap the whole thing in a hs.caffeinate.watcher, but I don't see how this should be functionally different from what Hammerspoon does internally? Nonetheless it seems to work whereas just the timer itself sometimes randomly fails (despite being bound to a global variable).

function watchDoEvery(interval, fn)
  local timer = hs.timer.doEvery(interval, fn);
  return hs.caffeinate.watcher.new(function()
    if timer ~= nil then
      timer:stop();
    end
    timer = hs.timer.doEvery(interval, fn);
  end):start();
end
github-actions[bot] commented 2 weeks ago

This issue needs more information. Please see our request above.