Need help with random delays with folder actions

[hailunix]

I recently posted about how there seem to be issues with folder actions on NFS but I'm seeing issues now with a local folder that has folder actions assigned to it.

Basically I'm just seeing random delays in how long it takes for the folder actions to stall. In the last four file creation test I ran I saw times ranging from 0-60 seconds or more for delays.

Test1 responded instantly
Test2 took maybe 15 seconds and reported this in the console:

11/8/07 11:05:42 PM com.apple.launchd[265] (com.apple.FolderActions.folders) Throttling respawn: Will start in 4 seconds

Test3 responded instantly
Test4 and on all had delays with similar messages:

11/8/07 11:06:39 PM com.apple.launchd[265] (com.apple.FolderActions.folders) Throttling respawn: Will start in 7 seconds

As I type up this message the first four tests all run again on their own (I see four more dialogs from the apple script all at once). The only pattern I can draw from the issues I'm seeing is that it more often than not comes from triggering the folder actions too close to eachother (i.e touching two new files in succession). On the other hand the last couple of times I've just downloaded a file to the folder in question it takes over a minute to see the dialog at all.

I have no idea where to start on trying to debug what is happening. My first step is normally looking at system logs but these re-spawn messages are useless except to tell me that perhaps something is spinning out of control when I trigger fsevent calls and the delay comes from trying to throttle things. Thats still pretty useless as I can't even see what is spinning out of control.

I keep asking myself how this feature has gotten into this state and no one else seems to be having issues with it. This was one of the more interesting features that I love in Tiger and I'm desperate to get it working again but I have no idea where to start.

I'd appreciate any help you folks can offer or any advice on other sites to look at for hints on debugging issues like this.

[hailunix]

Just a quick note. Poking around in system.log I noticed that there is a message about a deprecated function call being generated by AppleScript Runner.

Nov 8 23:23:36 stewie /System/Library/CoreServices/AppleScript Runner.app/Conte
nts/MacOS/AppleScript Runner[2706]: CPSGetFrontProcess(): This call is deprecate
d and should not be called anymore.

Why are apple's own software components using deprecated calls in their own OS? Why do I feel like this has something to do with the apparent failures causing throttling...

As usual any help would be appreciated.

[tw]

I don't know what you're actually doing, but this throttling function is intentional. launchd tries to preserve system resources by keeping applications from rapidly and frequently launching and ending. read the launchd man page; they talk about it briefly. if you were launching directly from launchd there's a way to change the timeout, but I don't know how to do it for folder actions.

[hailunix]

It doesn't really depend too much on what I'm doing with folder actions. Even the stock sample folder actions like notifying me that new files have been created still experience this issue.

I sort of assumed that the purpose of the throttling is to keep things on the system from going out of control. My difficulty is theres not a single message in the logs that indicates any type of point of failure or error message. If this thing is failling over and over again and the system is throttling it it'd be nice to see at least one of the failure messages.

It is possible that the message I posted above from AppleScript runner is one of these failure messages but I can't be sure as it isn't noted in the message itself, but it does fall around the same time frame as the throttling. If I'm interpreting that right the Apple Script runner itself is generating that error. If I'm using Apple supplied AppleScripts for just a simple folder on the local system I can't see why this should be throwing that error. Of course I'm thinking that error isn't really related to the script itself but the runner. Is there any reason to suspect that my AppleScript Runner was left out of the upgrade process somehow?

I guess the core problem here is I am ignorant as to how I get in between the layers where these things are being launched and force it to log more information. My gut tells me that the AppleScript interpreter here might be the one at fault and that its causing the folder action dispatch to barf over and over.

[tw]

can you post the folder action script that you're getting these errors on, so that I can try it on my system?

[Dr. Mario]

I've been having the same issue with Folder Actions, and I don't think it's the script. I attached the following script to a folder and tested it, and received the same result:

on adding folder items to theFolder after receiving theItems
    beep
end adding folder items to

These were the log messages produced:

11/10/07 12:59:07 PM /System/Library/CoreServices/Folder Actions Dispatcher.app/Contents/MacOS/Folder Actions Dispatcher[10145] CPSGetProcessInfo(): This call is deprecated and should not be called anymore. 
11/10/07 12:59:30 PM com.apple.launchd[274] (com.apple.FolderActions.folders) Throttling respawn: Will start in 2 seconds

Effectively, folder actions have been disabled on my machine. They rarely if ever fire, so I can't depend on them. Any thoughts?

[hailunix]

So the action script I am using is likely independent of this issue. I thought maybe, just maybe something went goofy so I did a reformat install of leopard on this machine. The first thing I did after logging in was set up apples stock 'new file added' sample applescript as a folder action for 'Documents'.

The lines below represent the first two consecutive file creations in the directory.

First:

Nov 10 14:54:19 bootstrap-bills-imac /System/Library/CoreServices/AppleScript Runner.app/Contents/MacOS/AppleScript Runner[445]: CPSGetFrontProcess(): This call is deprecated and should not be called anymore.

Second (mere seconds later)

Nov 10 14:54:20 bootstrap-bills-imac com.apple.launchd[192] (com.apple.FolderActions.folders): Throttling respawn: Will start in 8 seconds
--- Dialog actually shows up on screen about here, about 8 seconds off as promised ---
Nov 10 14:54:30 bootstrap-bills-imac /System/Library/CoreServices/AppleScript Runner.app/Contents/MacOS/AppleScript Runner[448]: CPSGetFrontProcess(): This call is deprecated and should not be called anymore.

There are a couple of things to note now:

1.) Bone stock leopard install on a newly formatted install. I've done NOTHING custom to this machine.
2.) _stock_ apple folder action sample 'add - new item alert.scpt'
3.) There are _no_ messages in the system.log _before_ the throttling message that indicate why the daemon is being throttled.
4.) The deprecated function call messages don't seem to be a cause of the issue as those occur even when I have an instant response to the folder action.

So I've isolated my scripts, my install, anything I've done at all from this issue. Nothing custom, nothing fancy, out of the box leopard and folder actions are still acting a bit strange. I'll hesitate to say broken but not exactly 'working' either. Sure my dialog shows up but if I look at how it behaved in Tiger (i.e quick response every time) this is a failure that I think is Apple's fault. I'm just trying to find out if maybe there is some way I can find out what is failing.

I'm not familiar enough with the underlying layers (fsevents, launchd) to understand where I can go to debug what is happening. I'm really just trying to find out what the error is when the folder action exits so rapidly that it gets throttled.

[tw]

ok, here's what's going on. Folder actions have been taken away from the Finder in 10.5 and given to launchd (which I figured would probably happen - it makes sense). the way it works is that when you enable folder action you get two plist files created in your ~/Library/LaunchAgents folder - one called com.apple.FolderActions.enabled.plist and one called com.apple.FolderActions.folder.plist. the first one is a plist that launches a core services application called Folder Actions Dispatcher - that application scans the folders in the second plist; the second plist uses launchd to watch for folder changes, and then prompts the dispatcher app to do something about it.

the only thing I can see obviously wrong (since I get the same errors you do on my system) is that the first plist is using the deprecated OnDemand key. I can't tell whether this is a problem with our particular installs or with new folder action system in its entirety, though, until I can find someone who has a system with working folder actions.

I'll file a bug report at apple, regardless, but if anyone out there can make folder actions work, say so, so I can figure out more precisely what's going on.

EDIT: if folder actions work of your system, please copy a text version of the two plist files mentioned above into your reply.

[hailunix]

Thanks for the additional information. I'll copy in a copy of my .plist files below for reference. To clarify, folder actions eventually trigger, the issue I have is that they just have random delays and it doesn't look like it is intentional. Are you having issues with folder actions working at all?

com.apple.FolderActions.enabled.plist

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/
PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
  <key>Label</key>
  <string>com.apple.FolderActions.enabled</string>
  <key>OnDemand</key>
  <false/>
  <key>Program</key>
  <string>/System/Library/CoreServices/Folder Actions Dispatcher.app/Contents/MacOS/Folder Actions Dispatcher</string>
</dict>
</plist>

com.apple.FolderActions.folders.plist

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/
PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
  <key>Label</key>
  <string>com.apple.FolderActions.folders</string>
  <key>Program</key>
  <string>/usr/bin/osascript</string>
  <key>ProgramArguments</key>
  <array>
    <string>osascript</string>
    <string>-e</string>
    <string>tell application "Folder Actions Dispatcher" to tick</string>
  </array>
  <key>WatchPaths</key>
  <array>
    <string>/Users/<removed>/Downloads</string>
  </array>
</dict>
</plist>

[tw]

well, I'm not sure, because I didn't test them that seriously. using the default 'add - new item...' script attached to the documents folder, I got pretty much the same console responses as you, but I never actually got it to spit out an alert. I suppose if I'd kept trying it would've (it looked like it was trying to - lol) but...

I submitted the bug report - let's see what they have to say about it.

EDIT: your plists look just like mine - not sure if that's good or bad, though.

[hailunix]

Quote: I submitted the bug report - let's see what they have to say about it.

Ah the ballad of the early adopters

[tw]

Quote: Originally Posted by hailunix Ah the ballad of the early adopters

ah, aint it a joy, though.

[tw]

Quote: Originally Posted by hailunix Of course I'm thinking that error isn't really related to the script itself but the runner. Is there any reason to suspect that my AppleScript Runner was left out of the upgrade process somehow?

you know, I've just been having the same question myself. unfortunately, my copy of the install DVD is at home, so I can't check right now (don't ask me why I'm in the office at 130am on veteran's day morning, because I refuse to answer - lol)

[hailunix]

Well if it makes any difference the errors I'm seeing are now on a reformat install so in my case, its there even if you don't do an upgrade.

[tw]

Quote: Originally Posted by hailunix Well if it makes any difference the errors I'm seeing are now on a reformat install so in my case, its there even if you don't do an upgrade.

yeah, I looked through the install dvd with pacifist, and there aren't any differences that I can find between what they were trying to install and what got installed. I think it's a bug...

[tw]

ok, I think I've found a workaround. with folder actions enabled, edit ~/Library/LaunchAgents/FolderActions.folder.plist. add the key "ThrottleInterval" (case sensitive) and give it an integer value of 0 (zero). save it, then unload the plist in launchctl and load it again. this should suppress the throttling activity, and seems to speed up folder actions to a reasonable interval.

down side: as soon as you disable folder actions, log out, or restart, the plist file gets overwritten with a fresh copy that erases the addition. best I can do for the moment...

[drc_007]

Quote: Originally Posted by tw I submitted the bug report - let's see what they have to say about it.

Do you have the Bug number, I also have problems and I'll include it on my bug report.

[tw]

the bug report number is 5592926

[gthing]

Any progress on this? I am having the same issue and it's driving up the wall.

Where exactly are you filing bug reports? I sent a generic feedback form to them, but didn't get a bug # - are these public? Can we see developer feedback?

Here is my much needed script (which sometimes runs great, sometimes after a delay, and sometimes works only partially after a delay):

property auto_open_list : {"qfx", "qif", "nzb", "torrent"}
property auto_delete_list : {"nzb", "torrent"}

on adding folder items to this_folder after receiving these_items
	try
		repeat with i from 1 to number of items in these_items
			set this_item to item i of these_items
			set the item_info to the info for this_item
			if (the name extension of the item_info is in the auto_open_list) then
				tell application "Finder"
					open this_item
				end tell
			end if
			
			if (the name extension of the item_info is in the auto_delete_list) then
				tell application "Finder"
					delete this_item
				end tell
			end if
			
		end repeat
	on error error_message number error_number
		if the error_number is not -128 then
			tell application "Finder"
				activate
				display dialog error_message buttons {"Cancel"} default button 1 giving up after 120
			end tell
		end if
	end try
end adding folder items to

[tw]

gthing,

if you tell me how the folder is used, I might be able to help you work out an alternate approach. in particular, I want to know if you leave stuff in this folder all the time, or if you can empty it out after stuff gets put in it (different launchd formats...)