Hammerspoon: hs.timer.doEvery() is unreliable when the computer is asleep

[nloveladyallen]

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]

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]

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]

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]

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]

@kimjianzsu 's fix solved my problem.

[cmsj]

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

[wwwjfy]

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]

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]

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]

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]

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]

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]

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]

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]

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

[leafac]

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

[wwwjfy]

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