TotalFinder hangs (or crashes) Finder at startup

mwoerner · July 3, 2014, 11:14pm

I think this may be related to having shortcuts to servers in the sidebar.

I have rolled back to 10.9.2 & at work I need to access a server through AFP. I dragged both the server & some subfolders on it into my Finder sidebar for quicker access. I did not notice any issues whilst at work but now that I am at home, I’m getting up to half a minute of beach balling. This is not always the case (I think time away from the Finder plays a role here) but if I double-click on a dmg file it is guaranteed to happen.

So I removed the Sidebar entries & the problem has not reared its head for over a day now. I wanted to remove any references to the file server but I am not sure where that information would be kept.

I had a similar problem over a year ago when I foolishly invested in a Transporter & after starting up my Mac, the Finder would lock up for over a minute, several times, whilst giving me error messages about missing servers.

Hope this helps.

werdy · July 4, 2014, 8:57am

On Macbook Pro with 10.9.3 (and 10.9.4) have the same issue. I have uninstalled TotalFinder, removee all TotalFinder related files from Library, restarted, installed 1.6.1 but no luck. Logs from console:

2014.07.04. 10:47:15,002 TotalFinder[573]: agent v##VERSION## started (TotalFinder)
2014.07.04. 10:47:15,008 TotalFinder[573]: Finder is not running. Launching it... (/System/Library/CoreServices/Finder.app)
2014.07.04. 10:47:15,135 TotalFinder[573]: requesting injection into com.apple.finder[574]
2014.07.04. 10:47:15,687 Finder[574]: TotalFinderInjector v1.6.1 received init event
2014.07.04. 10:47:15,711 Finder[574]: TotalFinderInjector: Installing TotalFinder ...
2014.07.04. 10:47:15,712 Finder[574]: Launching TotalFinderCrashWatcher from '/Library/ScriptingAdditions/TotalFinder.osax/Contents/Resources/TotalFinder.bundle/Contents/Resources/TotalFinderCrashWatcher.app'
2014.07.04. 10:47:15,734 TotalFinder[573]: TotalFinder has been succesfully injected into com.apple.finder[574]
2014.07.04. 10:47:15,750 TotalFinderCrashWatcher[577]: Watching '/Users/werdy/Library/Logs/DiagnosticReports' for new crash reports with prefix 'Finder'
2014.07.04. 10:47:28,362 Console[591]: setPresentationOptions called with NSApplicationPresentationFullScreen when there is no visible fullscreen window; this call will be ignored.
2014.07.04. 10:47:31,131 com.apple.IconServicesAgent[351]: main Failed to composit image for binding VariantBinding [0x455] flags: 0x8 binding: FileInfoBinding [0x1b3] - extension: gif, UTI: com.compuserve.gif, fileType: ????.
2014.07.04. 10:47:31,132 quicklookd[594]: Warning: Cache image returned by the server has size range covering all valid image sizes. Binding: VariantBinding [0x203] flags: 0x8 binding: FileInfoBinding [0x103] - extension: gif, UTI: com.compuserve.gif, fileType: ???? request size:16 scale: 1
2014.07.04. 10:47:31,150 com.apple.IconServicesAgent[351]: main Failed to composit image for binding VariantBinding [0x225] flags: 0x8 binding: FileInfoBinding [0x52d] - extension: sid, UTI: org.sidmusic.sidtune, fileType: ????.
2014.07.04. 10:47:31,151 quicklookd[594]: Warning: Cache image returned by the server has size range covering all valid image sizes. Binding: VariantBinding [0x403] flags: 0x8 binding: FileInfoBinding [0x303] - extension: sid, UTI: org.sidmusic.sidtune, fileType: ???? request size:16 scale: 1
2014.07.04. 10:47:33,277 com.apple.IconServicesAgent[351]: main Failed to composit image for binding VariantBinding [0x1b5] flags: 0x8 binding: FileInfoBinding [0x457] - extension: mp3, UTI: public.mp3, fileType: MP3 .
2014.07.04. 10:47:33,278 quicklookd[594]: Warning: Cache image returned by the server has size range covering all valid image sizes. Binding: VariantBinding [0x603] flags: 0x8 binding: FileInfoBinding [0x503] - extension: mp3, UTI: public.mp3, fileType: MP3  request size:16 scale: 1
2014.07.04. 10:48:26,701 com.apple.mtmd[97]: attempting to thin because of low free space on System (/) by removing 2014-07-04 10:24:22 +0200, estimate 0 bytes to recover, 1 snapshot can be thinned
2014.07.04. 10:48:45,830 com.apple.SecurityServer[15]: Killing auth hosts
2014.07.04. 10:48:45,830 com.apple.SecurityServer[15]: Session 100014 destroyed
2014.07.04. 10:48:58,000 kernel[0]: process Finder[574] thread 7580 caught burning CPU! It used more than 50% CPU (Actual recent usage: 87%) over 180 seconds. thread lifetime cpu usage 90.680991 seconds, (81.988606 user, 8.692385 system) ledger info: balance: 90001463504 credit: 90001463504 debit: 0 limit: 90000000000 (50%) period: 180000000000 time since last refill (ns): 103050176172 
2014.07.04. 10:48:58,087 ReportCrash[607]: Invoking spindump for pid=574 thread=7580 percent_cpu=87 duration=104 because of excessive cpu utilization
2014.07.04. 10:49:01,044 spindump[608]: Saved cpu_resource.spin report for Finder version 10.9.4 (10.9.4) to /Library/Logs/DiagnosticReports/Finder_2014-07-04-104901_Werdys-Macbook-Pro.cpu_resource.spin
2014.07.04. 10:49:22,304 WindowServer[143]: disable_update_timeout: UI updates were forcibly disabled by application "Finder" for over 1.00 seconds. Server has re-enabled them.

I hope this help to resolve this bug.

werdy · July 4, 2014, 9:16am

Disabling only Tabs plugin has solved the problem.

darwin · July 4, 2014, 10:20am

Ok, the problem is somewhere in the Tabs plugin. Thanks for narrowing it down.

@werdy It would be great if you could send me the file /Library/Logs/DiagnosticReports/Finder_2014-07-04-104901_Werdys-Macbook-Pro.cpu_resource.spin to support@binaryage.com. It could tell where exactly is Tabs code spending the CPU time.

werdy · July 4, 2014, 10:29am

@darwin Sent.

darwin · July 4, 2014, 10:44am

In that report there were two active plugins in memory, Tabs and ColumnViewAutoWidth. Could you do another test, just with Tabs enabled?

Also I have one additional tweak to try.

Enable only Tabs plugin. Make sure the issue is reproducible. Then set this tweak and restart Finder + TotalFinder again.

defaults write com.apple.finder TotalFinderDisableCrashInfo -bool yes

werdy · July 4, 2014, 11:14am

Only Tabs enabled it hanged:

    2014.07.04. 13:03:36,099 TotalFinder[573]: requesting injection into com.apple.finder[2688]
    2014.07.04. 13:03:36,416 Finder[2688]: TotalFinderInjector v1.6.1 received init event
    2014.07.04. 13:03:36,429 Finder[2688]: TotalFinderInjector: Installing TotalFinder ...
    2014.07.04. 13:03:36,430 Finder[2688]: Launching TotalFinderCrashWatcher from '/Library/ScriptingAdditions/TotalFinder.osax/Contents/Resources/TotalFinder.bundle/Contents/Resources/TotalFinderCrashWatcher.app'
    2014.07.04. 13:03:36,437 TotalFinder[573]: TotalFinder has been succesfully injected into com.apple.finder[2688]
    2014.07.04. 13:03:38,491 Finder[2688]: Skipping loading plugin ColorfulSidebar because it is disabled by plist switch TotalFinderColorfulSidebarDisabled.
    2014.07.04. 13:03:38,492 Finder[2688]: Skipping loading plugin ColumnViewAutoWidth because it is disabled by plist switch TotalFinderColumnViewAutoWidthDisabled.
    2014.07.04. 13:03:38,492 Finder[2688]: Skipping loading plugin CopyPathMenu because it is disabled by plist switch TotalFinderCopyPathMenuDisabled.
    2014.07.04. 13:03:38,492 Finder[2688]: Skipping loading plugin CutAndPaste because it is disabled by plist switch TotalFinderCutAndPasteDisabled.
    2014.07.04. 13:03:38,492 Finder[2688]: Skipping loading plugin DockProgressBar because it is disabled by plist switch TotalFinderDockProgressBarDisabled.
    2014.07.04. 13:03:38,492 Finder[2688]: Skipping loading plugin FoldersOnTop because it is disabled by plist switch TotalFinderFoldersOnTopDisabled.
    2014.07.04. 13:03:38,493 Finder[2688]: Skipping loading plugin Labels because it is disabled by plist switch TotalFinderLabelsDisabled.
    2014.07.04. 13:03:38,493 Finder[2688]: Skipping loading plugin NoDesktopDots because it is disabled by plist switch TotalFinderNoDesktopDotsDisabled.
    2014.07.04. 13:03:38,493 Finder[2688]: Skipping loading plugin SystemFiles because it is disabled by plist switch TotalFinderSystemFilesDisabled.
    2014.07.04. 13:03:38,494 Finder[2688]: Skipping loading plugin Visor because it is disabled by plist switch TotalFinderVisorDisabled.
    2014.07.04. 13:05:16,000 kernel[0]: process Finder[2688] thread 78498 caught burning CPU! It used more than 50% CPU (Actual recent usage: 80%) over 180 seconds. thread lifetime cpu usage 90.613343 seconds, (81.521489 user, 9.091854 system) ledger info: balance: 90001594441 credit: 90001594441 debit: 0 limit: 90000000000 (50%) period: 180000000000 time since last refill (ns): 112121656741 
    2014.07.04. 13:05:16,985 ReportCrash[2703]: Invoking spindump for pid=2688 thread=78498 percent_cpu=80 duration=113 because of excessive cpu utilization
    2014.07.04. 13:05:19,794 spindump[2704]: Saved cpu_resource.spin report for Finder version 10.9.4 (10.9.4) to /Library/Logs/DiagnosticReports/Finder_2014-07-04-130519_Werdys-Macbook-Pro.cpu_resource.spin

With crash info disabled hanged again (without crash info):

2014.07.04. 13:08:07,390 TotalFinder[573]: requesting injection into com.apple.finder[2710]
2014.07.04. 13:08:07,688 Finder[2710]: TotalFinderInjector v1.6.1 received init event
2014.07.04. 13:08:07,702 Finder[2710]: TotalFinderInjector: Installing TotalFinder ...
2014.07.04. 13:08:07,702 Finder[2710]: Disabled advanced crash info (defaults delete com.apple.finder TotalFinderDisableCrashInfo)
2014.07.04. 13:08:07,703 Finder[2710]: Launching TotalFinderCrashWatcher from '/Library/ScriptingAdditions/TotalFinder.osax/Contents/Resources/TotalFinder.bundle/Contents/Resources/TotalFinderCrashWatcher.app'
2014.07.04. 13:08:07,711 TotalFinder[573]: TotalFinder has been succesfully injected into com.apple.finder[2710]
2014.07.04. 13:08:09,763 Finder[2710]: Skipping loading plugin ColorfulSidebar because it is disabled by plist switch TotalFinderColorfulSidebarDisabled.
2014.07.04. 13:08:09,763 Finder[2710]: Skipping loading plugin ColumnViewAutoWidth because it is disabled by plist switch TotalFinderColumnViewAutoWidthDisabled.
2014.07.04. 13:08:09,763 Finder[2710]: Skipping loading plugin CopyPathMenu because it is disabled by plist switch TotalFinderCopyPathMenuDisabled.
2014.07.04. 13:08:09,763 Finder[2710]: Skipping loading plugin CutAndPaste because it is disabled by plist switch TotalFinderCutAndPasteDisabled.
2014.07.04. 13:08:09,764 Finder[2710]: Skipping loading plugin DockProgressBar because it is disabled by plist switch TotalFinderDockProgressBarDisabled.
2014.07.04. 13:08:09,764 Finder[2710]: Skipping loading plugin FoldersOnTop because it is disabled by plist switch TotalFinderFoldersOnTopDisabled.
2014.07.04. 13:08:09,764 Finder[2710]: Skipping loading plugin Labels because it is disabled by plist switch TotalFinderLabelsDisabled.
2014.07.04. 13:08:09,764 Finder[2710]: Skipping loading plugin NoDesktopDots because it is disabled by plist switch TotalFinderNoDesktopDotsDisabled.
2014.07.04. 13:08:09,764 Finder[2710]: Skipping loading plugin SystemFiles because it is disabled by plist switch TotalFinderSystemFilesDisabled.
2014.07.04. 13:08:09,765 Finder[2710]: Skipping loading plugin Visor because it is disabled by plist switch TotalFinderVisorDisabled.

I will send you cpu_resource.spin file in email for the first case.

darwin · July 4, 2014, 11:37am

Thank you very much.

Please test another tweak (with Tabs plugin enabled):

defaults write com.apple.finder TotalFinderDontRestoreTabsState -bool yes

darwin · July 4, 2014, 11:41am

And I would need one extra sample. Files you provided are ‘spin dumps’. I would like to see Finder.app process sample.

Please

open Activity Monitor.app
filter process list with “Finder” keyword
sample Finder.app (not TotalFinder.app)

Hit the sample button when Finder is eating 100% only with Tabs plugin loaded. Send the sample file to my email. Thanks.

werdy · July 4, 2014, 3:20pm

@darwin Sorry, but I can not send you spin dumps, as the bug is gone. I disabled tab state recovering as you wrote, run activity monitor and realized that TotalFinder and TotalFinderCrashWatcher were running (while icon on dock displayed only Finder). After I closed these processes and restart Finder TotalFinder worked as it should be. I reenabled all the plugins and still working. Did tab state restoring cause the hangs?

reddoorsound · July 4, 2014, 8:12pm

This solved the problem!!

tobenama · July 5, 2014, 11:32am

I can confirm that this fixes the problem with all plugins enabled.

darwin · July 7, 2014, 9:55am

I’m back! Good news is that we have a workaround now and we have isolated the issue pretty well.

I’m looking into my source code and changes which could have caused the problems. But I don’t see any obvious culprit.

It would be great if someone who is able to reproduce the issue could go back and install previous beta versions and tell which version started to exhibit the wrong behaviour:
http://totalfinder.binaryage.com/beta-changes

Erick_Gabriel · July 11, 2014, 8:21pm

Hi,

I installed 10.9.4 this morning and the problems being described started after the update. I have uninstalled TotalFinder and reinstalled and that did not fix the problem 1.6. I have read through the thread above and see that it could be the Tabs causing the issue. I do use the TotalFinder tabs, one of the best parts of the product. Okay, with that being said, what I am seeing in Activity Monitor is Finder is using a lot of RAM, like it has a memory leak. This is with TotalFinder running, sort of running, if you will, it’s started but I cannot open TotalFinder. When I double click the icon it does nothing. Both TotalFinder the Watch process are running and not using much RAM. Seems to be a integration or compatibility issue between native Finder and TotalFinder. Thought may be this information would be helpful to the remediation of the issue being seen.

To add, and almost forgot, after I rebooted at one point with 1.6 installed I was working on something else, and an update did popup to install 1.6.1 and that did not resolve the problem. I get the same results as described above. I have to force quit Totalfinder for my machine to run normally. otherwise it is very slow and it starts using a lot of RAM. Once i force quit Totalfinder I drop back down below 3GB of RAM. My iMac has 12GB installed. With Totalfinder started I find Finder will get to 8GB and then drop back down to over 6GB and climb again.

Hopefully more useful information?

Thanks,
Erick

Erick_Gabriel · July 14, 2014, 1:49am

I also tried uninstalling TotalFinder and reinstalling 1.6.1 without doing the 1.6 to 1.6.1 update and that didn’t help things either. Note after I try to start TotalFinder it just hangs will not open and my CPU and memory for Finder just climbing and Finder ends up showing that it is not responding so I have to relaunch it and then CPU and Memory go back to normal. Plus this time I noticed that User Agent for TotalFinder is not responding either.

More info.

Thanks,
Erick

fymalain · July 16, 2014, 8:32pm

This problem is literally driving me CRAZY. Can we please gets a walk-through of how to solve the issue? My FINDER has been screwed up for nearly two weeks now and its hard to even do work.

fymalain · July 17, 2014, 5:24pm

??? Im imagining that if there are this many posts on this problem that there are exponentially more people effected by this.

Its seems to be the TotalFinderCrashWatcher that is having problems.

darwin · July 17, 2014, 6:57pm

I’m going to release new TotlaFinder 1.6.2 on beta channel this weekend. I hope to solve it, but still without reproducible case, it is just guesswork.

fymalain · July 18, 2014, 3:18pm

I’ll video share my screen with you… tell me what you need to see. I’ve uninstalled TotalFinder and the problem still remains. Seems like TotalFinder screwed up regular finder some how.

darwin · July 21, 2014, 1:54pm

TotalFinder 1.6.2 beta is out:
http://totalfinder.binaryage.com/beta-changes#1.6.2

I did review of the code and made whole process of restoring previous tabs more reliable (changed timing and sequencing of individual operations). But I still don’t know if this could potentially fix the issue.

Please test and report here. Thank you.