Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Aerial 3.34 crashing legacyScreensSaver - Sonoma 14.1 #1341

Closed
luckman212 opened this issue Oct 29, 2023 · 34 comments
Closed

Aerial 3.34 crashing legacyScreensSaver - Sonoma 14.1 #1341

luckman212 opened this issue Oct 29, 2023 · 34 comments

Comments

@luckman212
Copy link

  • Mac model: Mac Mini 2020 M1
  • macOS version: 14.1 (23B74)
  • Monitor: (1) DELL S2721QS via HDMI port

Since about the last week or so (that I noticed) my screensaver has been crashing/hanging. When this happens, only a blank black screen is shown instead of the videos when the screensaver activates.

Checking activity monitor reveals the legacyScreenSaver process is hanging and eating 100% of the CPU.

image

I have to force-quit that to get things working again. Is anyone else experiencing this or have any ideas on how to troubleshoot it further?

Attached below are a spindump and a process sample.

@glouel
Copy link
Collaborator

glouel commented Oct 30, 2023

Hi @luckman212

Do you get the blank screen immediately or do you get like sometimes a couple videos playing, then a black screen and it hangs ?

This is very weird and there's not much I can find in the dumps.

Could you try opening Aerial's settings, go into Advanced, scroll down a bit, make sure debug mode is checked.

Then next time it crashes, note the time it happens, then grab the log Aerial created and attach it here ? it might give me a rough clue of what may be hanging, this is very weird in any case and first report of the kind.

Please keep me posted when you get the log, thanks !

@luckman212
Copy link
Author

Thank you @glouel

I just enabled Debug mode. Next time it happens I will post more detail.

@beetlefrosch
Copy link

I have the same problem.
Aerial comes up without videos, the screen saver crashes. This means that the screen saver no longer runs and the screen no longer goes to sleep!

Mac Studio with Apple M1 Max
macOS 14.1.
Aerial 3.3.5

@luckman212
Copy link
Author

@beetlefrosch I made a small script that checks for this condition and automatically kills legacyScreenSaver if it spins out of control.

Give it a try if you want: https://github.com/luckman212/aerial-watchdog

@beetlefrosch
Copy link

@beetlefrosch I made a small script that checks for this condition and automatically kills legacyScreenSaver if it spins out of control.

Give it a try if you want: https://github.com/luckman212/aerial-watchdog

Danke!
Unfortunately, neither the screen saver nor the sleep mode works after the crash. Switching to dark mode also no longer works!

@glouel
Copy link
Collaborator

glouel commented Nov 23, 2023

@luckman212 did you catch it yet with your watchdog ? If you have a log and a rough time, let me know.

Danke! Unfortunately, neither the screen saver nor the sleep mode works after the crash. Switching to dark mode also no longer works!

@beetlefrosch if I understand the issue correctly, you manually need to kill legacyScreenSaver to get it to work again.

I have no idea about the dark mode stuff though, I can't quite understand how that one would be related 🧐

@glouel
Copy link
Collaborator

glouel commented Nov 23, 2023

Also to both, do you happen to also use the "not video wallpapers" provided by Apple as your desktop backgrounds (not talking about Companion if you use it, but what is in System Settings) ? Or simple images ?

Edit : To clarify what I mean, do you use these :
Capture d’écran 2023-11-23 à 17 25 48

@luckman212
Copy link
Author

@glouel sorry for the late reply!

to answer... no I don't use dynamic wallpapers! just a plain boring grey background

screenshot_DXDbi2F1

so far (knock wood) the screen saver has not crashed in at least a few days. If it does, I will surely post my logs, I have debug mode enabled still.

By the way, is the log auto pruning itself? My log only seems to contain about 48 hrs of entries - is there a way to make it retain a longer period?

@glouel
Copy link
Collaborator

glouel commented Nov 28, 2023

No worries @luckman212, glad to hear it didn't crash again and thanks for confirming about the background.

Regarding log yes, because I spew so so much log lines, I ended up adding some pruning when the file reaches 1 MB in size, old versions of Aerial used to keep hundreds of MB of logs for nothing. There's no way to change that though, sorry. It should still be fine though here, just grab the file post crash if that happens and that's ok, it only prunes on startup.

@luckman212
Copy link
Author

ok, understood - I added a line to my watchdog to make a timestamped copy of the logfile before killing the process, to be sure everything leading up to it is captured. Will post if it happens again!

@luckman212
Copy link
Author

I had a crash this morning! (I had also updated to macOS 14.1.2 yesterday). When I woke the machine, it was at a plain black login screen (no screensaver running). The crash occurred right around 11:16am, which I can determine from the timestamped filename of the logfile from my watchdog.

Here's the log, not sure if it contains anything useful. If there's anything else I can do to help debug please let me know!

AerialLog-2023-12-01_111641.txt

@glouel
Copy link
Collaborator

glouel commented Dec 1, 2023

Thanks @luckman212, the timestamp and grab is pretty helpful, it does give me a few ideas.

It looks like you have your Aerial cache on an externally mounted volume, am I seeing this right ?

About 40s before it looks like it can't access your cache somehow, whether because of a permission thing (which is weird), or maybe maybe somehow your external volume disconnected ?

What kind of volume mount are you using ? I'm starting to think it may be something around that, some volume disconnecting and Aerial crashing because of it, trying to open stuff it can't somehow, or disconnecting in the middle of the video and me not handling it right.

It could definitely explain the utter randomness of it, I know macOS is pretty terrible at keeping my NAS volume mounted sometimes, to the point I can't use that reliably for Time Machine (and USB on my M1 Max is... temperamental 😅). I could see something related happening to you maybe.

@luckman212
Copy link
Author

Hmm interesting. Yes, I am storing my cache on an external device to save room on my internal SSD. The connection is via Thunderbolt 4 cable to a Samsung M.2 SSD. I never move or disconnect it, it's permanently there. I didn't get any message about an unexpected disconnect either. The cable is not loose or anything.

If you think it's helpful, I could try to set up a daemon to watch the unified system log for any USB/Thunderbolt related events.

@glouel
Copy link
Collaborator

glouel commented Dec 1, 2023

It might be worth it if you can yeah, can you try digging in your current System logs maybe if you have it ? Or save it just in case, look around this time :

2023-12-01 11:16:00.984 : 🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨 removeCruft couldn't access scoped resouce

This is where I get a failed access to your cache for the first time.

Crash possibly happens then :

2023-12-01 11:16:42.925 : 🖼️ <AerialView: 0x133635390> playing video (OFFLINE MODE) : file:///Volumes/Xtra/Aerial/Cache/DL_B002_C011_SDR_20191122_SDR_2K_HEVC.mov

@luckman212
Copy link
Author

Yes of course I will for sure. I just left my desk for a bit but I will check as soon as I get back.

@luckman212
Copy link
Author

Maybe something (But I don't know what this really represents). No errors visibly shown, no other side effects. This could be related to some sort of APFS snapshotting/housekeeping? The only thing I noticed is that Apple seems to have oddly misspelled storagekitd as storagetkid in the message text...

image

Here's the full output of the log command for a 10-minute span around the time of the crash:

~ $ log show --predicate 'subsystem == "com.apple.storagekit"' --start '2023-12-01 11:10:00' --end '2023-12-01 11:20:00' --style syslog
Filtering the log data using "subsystem == "com.apple.storagekit""
Skipping info and debug messages, pass --info and/or --debug to include.
Timestamp                       (process)[PID]
2023-12-01 11:16:02.422423-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection initWithConnection:]: Connected via XPC from pid 629
2023-12-01 11:16:02.422433-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13ae0c2c0> added. There are now 2 client(s) connected to storagetkid
2023-12-01 11:16:02.422537-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Creating session for DM client from pid 629
2023-12-01 11:16:02.423138-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Session thread: <NSThread: 0x13c112ac0>{number = 70, name = (null)}
2023-12-01 11:16:02.425557-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_APFSEnsureBooter_updatePrebootForVolume:keepSessionAlive:options:reply:]: disk3s1s1, keepSessionAlive=1
2023-12-01 11:16:02.425656-0500  localhost storagekitd[813]: [com.apple.storagekit:general] SK_DM operation started on <NSThread: 0x13c112ac0>{number = 70, name = 86603147-CA9D-4B16-8E17-1642C4566F61}
2023-12-01 11:16:02.425759-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_APFSEnsureBooter_updatePrebootForVolume:keepSessionAlive:options:reply:]_block_invoke: volume=disk3s1s1, keepSessionAlive=1
2023-12-01 11:16:02.432542-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_endSessionWithReply:]: <NSThread: 0x13c112ac0>{number = 70, name = 86603147-CA9D-4B16-8E17-1642C4566F61}
2023-12-01 11:16:02.432817-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection invalidationHandler]: 86603147-CA9D-4B16-8E17-1642C4566F61
2023-12-01 11:16:02.432828-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13ae0c2c0> removed. There are now 1 client(s) connected to storagetkid
2023-12-01 11:16:03.724977-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection initWithConnection:]: Connected via XPC from pid 11083
2023-12-01 11:16:03.724993-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13c142cd0> added. There are now 2 client(s) connected to storagetkid
2023-12-01 11:16:03.725137-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Creating session for DM client from pid 11083
2023-12-01 11:16:03.725830-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Session thread: <NSThread: 0x13c038bd0>{number = 72, name = (null)}
2023-12-01 11:16:03.730082-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection invalidationHandler]: 6AE52714-89C8-434D-A65D-5A8B4BA8ECE2
2023-12-01 11:16:03.730104-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13c142cd0> removed. There are now 1 client(s) connected to storagetkid
2023-12-01 11:16:04.561761-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_APFSEnsureBooter_updatePrebootForVolume:keepSessionAlive:options:reply:]_block_invoke: Update preboot of disk3s1s1 is complete, keepSessionAlive=1
2023-12-01 11:16:04.561841-0500  localhost storagekitd[813]: [com.apple.storagekit:general] SK_DM operation ended on <NSThread: 0x13c112ac0>{number = 70, name = 86603147-CA9D-4B16-8E17-1642C4566F61}
2023-12-01 11:16:10.204492-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection initWithConnection:]: Connected via XPC from pid 629
2023-12-01 11:16:10.204508-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13c11cec0> added. There are now 2 client(s) connected to storagetkid
2023-12-01 11:16:10.204655-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Creating session for DM client from pid 629
2023-12-01 11:16:10.205428-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Session thread: <NSThread: 0x13c00bf30>{number = 73, name = (null)}
2023-12-01 11:16:10.208903-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_APFSEnsureBooter_updatePrebootForVolume:keepSessionAlive:options:reply:]: disk3s1s1, keepSessionAlive=1
2023-12-01 11:16:10.208971-0500  localhost storagekitd[813]: [com.apple.storagekit:general] SK_DM operation started on <NSThread: 0x13c00bf30>{number = 73, name = D641D000-82CF-493C-89E9-6524EBE0C98F}
2023-12-01 11:16:10.209060-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_APFSEnsureBooter_updatePrebootForVolume:keepSessionAlive:options:reply:]_block_invoke: volume=disk3s1s1, keepSessionAlive=1
2023-12-01 11:16:10.214339-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_endSessionWithReply:]: <NSThread: 0x13c00bf30>{number = 73, name = D641D000-82CF-493C-89E9-6524EBE0C98F}
2023-12-01 11:16:10.214626-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection invalidationHandler]: D641D000-82CF-493C-89E9-6524EBE0C98F
2023-12-01 11:16:10.214642-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13c11cec0> removed. There are now 1 client(s) connected to storagetkid
2023-12-01 11:16:11.583833-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection initWithConnection:]: Connected via XPC from pid 11086
2023-12-01 11:16:11.583847-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13af1bab0> added. There are now 2 client(s) connected to storagetkid
2023-12-01 11:16:11.583997-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Creating session for DM client from pid 11086
2023-12-01 11:16:11.584715-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Session thread: <NSThread: 0x13c14e3f0>{number = 75, name = (null)}
2023-12-01 11:16:11.588730-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection invalidationHandler]: D1515913-412B-4E20-9BCB-8E17F172B6EF
2023-12-01 11:16:11.588754-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13af1bab0> removed. There are now 1 client(s) connected to storagetkid
2023-12-01 11:16:12.421866-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_APFSEnsureBooter_updatePrebootForVolume:keepSessionAlive:options:reply:]_block_invoke: Update preboot of disk3s1s1 is complete, keepSessionAlive=1
2023-12-01 11:16:12.421946-0500  localhost storagekitd[813]: [com.apple.storagekit:general] SK_DM operation ended on <NSThread: 0x13c00bf30>{number = 73, name = D641D000-82CF-493C-89E9-6524EBE0C98F}
2023-12-01 11:16:42.042127-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection initWithConnection:]: Connected via XPC from pid 1699
2023-12-01 11:16:42.042131-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13c439930> added. There are now 2 client(s) connected to storagetkid
2023-12-01 11:16:42.042202-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Creating session for DM client from pid 1699
2023-12-01 11:16:42.043899-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_beginSessionWithPreferredLoc:installEnv:externalAuth:reply:]: Session thread: <NSThread: 0x13ae48d40>{number = 77, name = (null)}
2023-12-01 11:16:42.047808-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection SK_DM_endSessionWithReply:]: <NSThread: 0x13ae48d40>{number = 77, name = E2E028D5-EB98-47B7-955A-22527DE33044}
2023-12-01 11:16:42.048179-0500  localhost storagekitd[813]: [com.apple.storagekit:general] -[SK_DM_DaemonConnection invalidationHandler]: E2E028D5-EB98-47B7-955A-22527DE33044
2023-12-01 11:16:42.048387-0500  localhost storagekitd[813]: [com.apple.storagekit:general] <SK_DM_DaemonConnection: 0x13c439930> removed. There are now 1 client(s) connected to storagetkid

@beetlefrosch
Copy link

The problem still occurs with the current version of macOS.

The screen saver comes on, but it remains black!
Bildschirmfoto 2023-12-03 um 10 48 10

@glouel
Copy link
Collaborator

glouel commented Dec 4, 2023

@luckman212 it's very vague, it could be a disconnect in there that cause it but it's not super conclusive like a thunderbolt bus reset or something...

@beetlefrosch if you followed the remainder of the discussion, did you also move your cache to an external drive ? Or added videos from an external drive ? See if we can narrow it down.

@beetlefrosch
Copy link

@glouel No, neither! Everything as it is by default. No changes on my part!

@luckman212
Copy link
Author

Thanks for looking @glouel

Also if you look at that other issue at exelban/stats#1710 the developer says it's "normal" side effect of using that API.

@glouel
Copy link
Collaborator

glouel commented Dec 4, 2023

Ok thanks both, I'll keep thinking about it.

This is a super long shot @luckman212 but can you check this file, it's the last one from your log :

file:///Volumes/Xtra/Aerial/Cache/DL_B002_C011_SDR_20191122_SDR_2K_HEVC.mov

See if it's not 0 bytes, see if it plays correctly and completely in Quicktime, etc ?

@luckman212
Copy link
Author

@glouel

No the file is 175MB and appears intact. I was able to open it with QuickTime Player and play it through entirely.

image

@luckman212
Copy link
Author

I had another crash yesterday, here are some logs. Same removeCruft signpost seen in Aerial's log:

2023-12-05 17:37:07.282 : 🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨 removeCruft couldn't access scoped resouce

A different media file though...
comp_GMT026_363A_103NC_E1027_KOREA_JAPAN_NIGHT_v18_SDR_PS_20180907_SDR_2K_HEVC.mov

AerialLog-2023-12-05_174216.txt

And here's the full output of log show --start '2023-12-05 17:30:00' --end '2023-12-05 17:45:00' --style syslog >syslog.txt:

syslog.txt.zip

It is a lot to sort through. So I haven't dug too deep into that. But maybe we can start to see a pattern, especially if @beetlefrosch collects his log as well.

@glouel
Copy link
Collaborator

glouel commented Dec 6, 2023

Thanks a lot, I think the pattern around removeCruft is interesting enough to warrant a lot more logging on my part, I'll see what I can add, maybe I can log the actual error. I may push an update tonight, will keep you posted ! But yes, please keep collecting those in the meantime, they may give us a clue, thanks !

@glouel
Copy link
Collaborator

glouel commented Dec 6, 2023

Also, removeCruft coincides with a case where Aerial can't seem to find your monitors for some reasons, not sure if there's something around that :

2023-12-05 17:37:07.282 : 🖼️ missing foundScreen, workarounding Optional(<NSScreen: 0x144404450; name=""; backingScaleFactor=1.000000; frame={{0, 0}, {1920, 1080}}; visibleFrame={{55, 0}, {1865, 1055}}>)
2023-12-05 17:37:07.283 : 🖼️ screen attached
2023-12-05 17:37:07.283 : 4
2023-12-05 17:37:07.283 : 🖼️🌾 Using : nil

I usually try to list the monitors although, because I keep logging so much stuff I'm getting a bit confused by my own logs, but your monitor always shows up like this when things are right :

Optional(<NSScreen: 0x149f79a30; name="DELL S2721QS"; backingScaleFactor=2.000000; frame={{0, 0}, {1920, 1080}}; visibleFrame={{55, 0}, {1865, 1055}}>)

(1920x1080, retina factor 2)

Before the crash though, here's what I see :

Optional(<NSScreen: 0x144404450; name=""; backingScaleFactor=1.000000; frame={{0, 0}, {1920, 1080}}; visibleFrame={{55, 0}, {1865, 1055}}>)

No name, no retina (!). Resolution is the same

Maybe related, maybe unrelated, worth pointing out though. I'll keep you posted in any case. Also try to update to 14.2 if you haven't, supposedly Apple made some improvements although who knows if it's related. Someone had an issue related to those weird empty screens that seemingly went away with 14.2 yesterday (but in their case, it only caused wrongly sized videos).

@luckman212
Copy link
Author

Oh ok. I'm not on the dev beta track but I will install it later today. Thank you for all of this help tracking this rare bug!

@luckman212
Copy link
Author

@glouel I ended up not having time last week to update, but now that 14.2 has been officially released, I've just updated both my Macs to it. Will keep an eye out for future missing foundScreen errors!

@luckman212
Copy link
Author

luckman212 commented Jan 4, 2024

Just posting an update here since it's been a few weeks. I don't think Aerial has crashed since I updated to 14.2 / 14.2.1 🚀

I saw someone commenting in #1340 so I wanted to add my anecdotal evidence.

Don't want to jinx it but this may have been an OS issue that is now fixed. My watchdog script hasn't triggered, and I just scanned my Aerial.log which only goes back to 12-26-2023 but no crashes noted in there.

@glouel
Copy link
Collaborator

glouel commented Jan 22, 2024

I'll close this, should you see any crash please let me know !

@glouel glouel closed this as completed Jan 22, 2024
@luckman212
Copy link
Author

Well, I think I just had this crash again. This time on Sonoma 14.3 (23D56).

The lock screen was black same as before, and strangely my USB-C keyboard wasn't working. I had to unplug/replug it to get it working again.

Here's the logfile, in case there's anything interesting there...

AerialLog-2024-01-27_154535.txt

@beetlefrosch
Copy link

Nothing has changed for me either, the problem persists even with the latest update. Black screen.

@Nicholas-Westby
Copy link

FYI, my guess is this is a very general problem unrelated to this codebase, perhaps having to do with macOS changes.

I am trying to build my first Swift app and was following this page to create a screensaver: https://jamesliu.io/blog/2018-08-05-macos-screensaver/

Here's a zip file you can use to reproduce:

Swirloids.zip

I Googled the error I saw in activity monitor and landed on this GitHub issue and thought I'd add some extra context.

Here's what I see in my activity monitor:

activity-monitor

In case you want a quick reference for my code instead of opening that zip file, here is the SwirloidsView.swift file:

import ScreenSaver

class SwirloidsView: ScreenSaverView {
    var latestTime: String = ""
    
    override init?(frame: NSRect, isPreview: Bool) {
        super.init(frame: frame, isPreview: isPreview)
        
        animationTimeInterval = 5
    }

    required init?(coder decoder: NSCoder) {
        super.init(coder: decoder)
    }

    /**
     animateOneFrame is called every time the screen saver frame is to be updated, and
     is used to re-draw the time/quote if required.
     */
    override func animateOneFrame() {
        let time = getTime()

        if time != latestTime {
            clearStage()
            drawText(time)
            latestTime = time
        }
    }

    /**
     getTime returns the current time as a formatted string.

     - Returns: A new string showing the current time, formatted as HH:mm:ss
     */
    func getTime() -> String {
        let date = Date()
        let formatter = DateFormatter()
        formatter.dateFormat = "HH:mm:ss"

        return formatter.string(from: date)
    }

    /**
     drawText draws a provided string to the bottom-left of the stage.

     - Parameter text: The text to draw onto the stage.
     */
    func drawText(_ text: String) {
        NSColor.black.set()
        text.draw(at: NSPoint(x: 100.0, y: 200.0), withAttributes: nil)
    }

    /**
     clearStage clears the stage, by filling it with a solid colour.
     */
    func clearStage() {
        NSColor.green.setFill()
        self.bounds.fill();
        //NSRectFill(self.bounds)
    }

    /**
     draw is called to initialise the stage of the screen saver.
     */
    override func draw(_ rect: NSRect) {
        super.draw(rect)

        let time = getTime()

        clearStage()
        drawText(time)
    }
}

#Preview {
    SwirloidsView()
}

As you can see, it's pretty basic, and is able to reproduce this issue. Just build, "show build folder in finder", find the saver file in the products/debug folder, and open it to install the screensaver, then preview it.

Another thing I notice is that it paints the first frame, but then just gets stuck there. It should be painting an updated time every second, but the time never changes.

When I dismiss the screensaver and attempt to view it again, I get a black screen (perhaps because it's already busy on the old screensaver that won't quit).

I am on the latest macOS version as of today:

macos-version

And this is the latest MacBook Pro with M3 Pro.

@glouel
Copy link
Collaborator

glouel commented Feb 18, 2024

Hey @Nicholas-Westby

First thanks a lot for chiming in with your example.

I'll try to give a few pointers below and a general understanding of what's wrong in Sonoma to cause this. But I would highly highly highly recommend you file a bug with feedback assistant on your Mac to Apple with your simple example (and hopefully some info I give below can give you a better understanding of the errors you see).

FYI, my guess is this is a very general problem unrelated to this codebase, perhaps having to do with macOS changes.

Yep this is my understanding too. We have some mitigations but it's not effective for everyone it seems. You've noticed two separate things that I believe are linked :

When I dismiss the screensaver and attempt to view it again, I get a black screen (perhaps because it's already busy on the old screensaver that won't quit).

So this is what people call the black screen bug most of the time, somehow, you get black screens. Some people talk about getting it progressively if they have multiple monitors, one screen starts acting up, then another, then another, see here : #1359

The second issue is the crashing that you describe

Here's a zip file you can use to reproduce:

Swirloids.zip

I Googled the error I saw in activity monitor and landed on this GitHub issue and thought I'd add some extra context.

Here's what I see in my activity monitor:

activity-monitor

Do you reproduce 100% the crash or is it once in a while ? My understanding is that it happens only some of the time, and most of the time you get the first issue (still there but black screen). Can you confirm ?

So the big question, why does this happen ?

Screensavers are plugins, as in, a class that gets loaded, then instantiated for each screen, by some part of macOS. Because of security risks, Apple started adding a layer between ScreenSaverEngine.app (which used to load screensavers) and 3rd party screensavers. It's called legacyScreenSaver.appex, it's an app extension, and the root of all issues for the last 5 years with screensavers :)

With Sonoma, things got a lot worse though, as they changed how screen savers and wallpaper works in a very very convoluted way. There's a thread somewhere with our findings on this but long story short, a casualty of all this is that legacyScreenSaver hangs around when you exit the screensaver by yourself (it doesn't I believe if your mac goes to sleep, but will if you start the saver and interrupt it before your mac goes to sleep).

This is not how things used to work. legacyScreenSaver used to exit gracefully, thus killing us, a few seconds after you exited the screensaver and went back to the desktop. But now it doesn't. Moreover, it keeps our instances around (one per screen), and will keep piling up new ones everytime you start the screensaver (you can log this easily if you are curious). At best this brings a huge memory leak.

Because our class is instantiated by the system, we have little say in all this and can't deinstantiate ourselves. We did find "one weird trick" where we can force our parent process to exit. It's certainly a bit naughty, but it works 99.9% of the time and avoids both bugs :

  • legacyScreenSaver doesn't have time to crash
  • since we recycle it we avoid the instance stacking and everything that comes with it.

Still, for some, it still crashes, so that trick is imperfect.

Another solution I had was using Aerial's Companion app to look for legacyScreenSaver (wallpaper) and kill it from the Companion after you get back to desktop. I never pursued this because, annoyingly, the wallpaper word gets localised. Maybe this is just a superficial thing in Activity Monitor but I never tried to look it up more.

Maybe it could act as a second line of defence as, most of the time, if you force quit it, things go back to normal. But again, for some people, sometimes macOS freaks out about something somewhere, and only a reboot fixes it (yay).

So yeah, long story short, it's massively annoying.

If you want to give a try to the same mitigation we came up with, look at the AerialView.swift class and look for 2 functions called onSleepNote and willStop. They are linked to some system events that we hook to in the function just above (see the notification code for both that you will also need).

Another thing I notice is that it paints the first frame, but then just gets stuck there. It should be painting an updated time every second, but the time never changes.

So I don't use animateOneFrame but my best recollection is that this has not worked for years.

You need to listen to startAnimation and stopAnimation and do your thing from there.

Again, feel free to ask (maybe create a separate issue) if you have questions about screensavers, but please please please report your bug with your sample to Apple, as this can only help to get more reports on this.

@beetlefrosch
Copy link

Just for the sake of completeness, the problem still exists, even after the latest macOS update! Does anything happen here? Update or something similar?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants