Ideas for assessing and mitigating invocation lag

[NickR]

When I began using Alfred, I never experienced any lag in calling up the search box once the app was running. One of the version updates within the last couple of years (either of Alfred or macOS itself) appears to have changed this, and now I will quite frequently experience lag before the search box is displayed in the first time I call up the search box after sitting down to use my machine, or occasionally at a later time within the same usage session. After this initial laggy call, subsequent callups do not have any lag, but the invocation lag can return before Alfred or macOS is restarted. My suspicion is that this pattern is consistent with a cache warming issue, somewhere within the stack of calls between pressing `cmd-space` and having the search box paint to the screen.

 

The reason I use Alfred at all is because search results appear synchronously with keystrokes, as opposed to Spotlight, where search results appear asynchronously after waiting for the spotlight service to process the query. If Alfred must wait for underlying resources like a filesystem access, then it is acceptable to delay the first search result, however, the apparent behavior of waiting before displaying the search box is not acceptable since this loses keyboard entry.

 

I am interested in two approaches: one is to figure out a way to instrument the system and/or Alfred to learn the root cause of the delay between my keypress and the presentation of the Alfred search box, when it occurs, or at least to measure what that delay is. The second approach is to try to "warm the cache" on a regular basis, either by automating a keypress to the system or by sending an apple event to Alfred itself.

 

As I was writing this post I decided to explore both of these approaches and set up an hourly LaunchAgent which runs an AppleScript that calls up and dismisses the Alfred search box, and then logs how much time this takes. I am not yet sure if this will work when there is a delay since I am currently relying on an assumption that the script will block on waiting for the search box to display before trying to dismiss it and it's not possible for me to reproduce the delay case yet, but I will be watching this with interest to see if I can capture the timing of a delay, as well as whether or not calling up the search window periodically (and automatically) will prevent the delay from occurring.

 

A couple of other notes:

 

I am not syncing alfred settings between machines, and while I am using command-space, I have remapped spotlight and am confident that there are no other processes watching that keystroke.

 

I think some critical feedback is warranted, as it seems I am not the only one reporting this issue, and the support response always seems to be (for lack of a better term) "blaming the user". In my view, the observed behavior of the delays occurring after inactivity and then no longer being present until a further period of inactivity points towards a root cause inside Alfred itself as opposed to other factors, and warrants a deeper level of concern.

 

For example, a minor step that could potentially help a lot would be to ship a lightweight instrumentation of how long it takes between when Alfred receives its activation keystroke from the operating system and when the search field is ready to receive input. If these metrics were included in diagnostics and/or otherwise available to retrieve or observe in logs, this would unambiguously clarify whether the delay occurs inside or outside of Alfred's code path.

 

That said, as I mentioned above, if it is already known that Alfred's code will block before displaying UI in case of things like filesystem access or swap, etc, then I think it is arguable that this is already a bug and the wait should be moved in front of the first search result so as not to lose the user's keyboard input. (The traditional mechanism of displaying results synchronously with keystrokes would need to be attached to the keystroke event after the load completes.)

 

P.S. I just experienced the delay issue (organically) not 50 minutes since the last time Alfred was invoked. This makes me confident that I will be able to tune my LaunchAgent to get a more reliable sense of how much delay is needed to repro the issue. I'll do my best to keep this topic updated with my findings.

[Vero]

@NickR Could you please provide your Diagnostics file, which you can get by typing "?diagnostics" into Alfred? You can then email our info@ address with the file.

 

This will allow me to at least shed some light on why this may be happening in your particular case. There are always ways to mitigate any delays you're experiencing.

[NickR]

My response time measuring tool is catching delays of ~2000ms after periods of inactivity. Here's the AppleScript that is being run to capture response times:

 

-- Subroutine to get the current time in milliseconds
on nowMillis()
	return (do shell script "perl -MTime::HiRes=time -e 'print int(time()*1000)'") as integer
end nowMillis

set startTime to nowMillis()

tell application "Alfred 5"
	activate
end tell

set actTime to nowMillis()

tell application "Alfred 5"
	search ""
end tell

set searchTime to nowMillis()

delay 0.25

tell application "System Events"
	tell application process "Alfred 5"
		key code 53 -- Escape
	end tell
end tell

-- Calculate the duration in seconds
set activation to actTime - startTime
set search to searchTime - actTime

set responseTime to searchTime - startTime

-- Function to log messages to a file
on logMessage(message, logFilePath)
	try
		set logFile to open for access file logFilePath with write permission
		write message & (ASCII character 10) to logFile starting at eof
		close access logFile
	on error errMsg
		try
			close access logFile
		end try
		display dialog "Error: " & errMsg
	end try
end logMessage

-- Specify the log file path
set logFilePath to (path to desktop as text) & "ApplicationResponseLog.txt"

set currentTime to (current date) as string

-- Log the response time
set logEntry to currentTime & " - Application response time: " & (responseTime / 1000) & " seconds (" & activation & " ms, " & search & " ms)"
logMessage(logEntry, logFilePath)

 

The stage where the delay occurs is at the `activate` call. This delay is only measured after inactivity -- if I run the script manually a few times, this 2000ms is reduced to about 20ms. Then, the search field is called up using `search ""` -- this circumvents any issues that could arise from invoking the search window with command-space.

 

One element of this measurement script that I do not fully understand yet is that the automatic dismissal of the search window (by sending Esc) is not working reliably. I don't believe this is germane to the delay measurements happening earlier in the script, but it is notable that I was expecting the activation and search to block until they are complete, and noting that this appears not to be the case, I added a `delay 0.25` to wait before sending the Esc. However this does not work 100% reliably either, so it's possible there is lag occurring elsewhere that I am not yet able to measure.

[Stephen_C]

On 11/20/2024 at 3:17 PM, Vero said:

Could you please provide your Diagnostics file, which you can get by typing "?diagnostics" into Alfred? You can then email our info@ address with the file.

Have you done that?

 

Stephen

[NickR]

@Stephen_C yes, of course

[Vero]

@NickR I responded to your email on Thursday with a few steps to follow but haven't heard back. Could you check your spam/filtered folders? 

[NickR]

@Vero Thanks -- I indeed had missed that email. Replied!