Any idea why running ~empty Finder calls could time out with "Finder got an error: AppleEvent timed out"

[eugenesvk]

I'm using your crate to get Finder to do a few simple things while being able to parse its output.

This is the full test code I'm running (src), all it does is invokes a short script 10 times, which asks Finder to save the selection to a variable, and return the same string.
So there is no work happening to timeout for 2 mins. And locally this runs mostly fine, but then from time to time it would bug on some iteration (maybe even the first 1, maybe the 9th)

Same thing with CI, though it seems to fail more frequently? For example, here the logs tell that loop 9 failed

(I don't think the previous version of using osascript command had such issues, but haven't tested that one much, it anyway doesn't quote the output properly to parse list of files with arbitrary names)

use crate::tests::init_logging;
use crate::Error;
use serial_test::serial;

fn test_run_as_with_finder() -> Result<(), Error> {
    use osakit::{Language, Script};
    let script_text = format!(r#"
        tell application "Finder"
            set Trash_items to selection
        end tell
        return "empty string"
    "#);

    let mut script = Script::new_from_source(Language::AppleScript, &script_text);

    // Compile and Execute script
    println!("  ? script starting...");
    match script.compile() {
        Ok(_) => {
            println!("  ✓ script compiled");
            match script.execute() {
                Ok(res) => println!("  ✓ script run res={:?}", &res),
                Err(e) => {
                    println!("  ✗ script failed to run");
                    return Err(Error::Unknown { description: format!("The AppleScript failed with error: {}", e) });
                }
            }
        }
        Err(e) => {
            println!("  ✗ script failed to compile");
            return Err(Error::Unknown { description: format!("The AppleScript failed to compile with error: {}", e) });
        }
    }
    Ok(())
}

use std::{thread, time};
#[test]
#[serial]
fn test_x1() {
    init_logging();
    let ten_millis = time::Duration::from_millis(1000);
    for i in 0..10 {
        println!("{i} sleeping");
        thread::sleep(ten_millis);
        test_run_as_with_finder().unwrap();
    }
}

[mdevils]

Hello @eugenesvk. Thanks for reporting this issue, I'll take a look into it.

[eugenesvk]

Thanks, meanwhile I've sprinkeld a few prints in the script, and when it bugs it seems to always bug before setting to selection

            tell application "Finder"
                tell me to dlog("  tell Finder pre") -- this prints OK
                set Trash_items to selection
                tell me to dlog("  tell Finder pos") -- this does NOT
            end tell

[mdevils]

@eugenesvk

After some experimentation I'm really confused :)

So when calling OSAKit API via rust, Finder sometimes timeouts. I've even write an alternative approach using Carbon directly, but it had the same behavior.

I've tried it with osascript and it works fine.

I've tried the same using mono / C# via Carbon API and it also works just fine.

[eugenesvk]

Yeah, the cli osascript seems to work every time.

No idea, but could this in any way be tied to the deprecated icrate that's replaced by https://crates.io/crates/objc2-osa-kit?

Or maybe thread issues??? https://stackoverflow.com/questions/46972115/objective-c-and-applescript-timeout-events-threads

[mdevils]

@eugenesvk yeah, the threads were the correct guess!

Here is the main.rs:

use std::{thread, time};
use osakit::{Language, Script};

pub fn main() {
    let script_text = format!(
        r#"
        tell application "Finder"
            set Trash_items to selection
        end tell
        return "empty string"
    "#
    );

    let mut script = Script::new_from_source(Language::AppleScript, &script_text);
    script.compile().unwrap();
    let ten_millis = time::Duration::from_millis(10);
    for i in 0..1000 {
        println!("{i} sleeping");
        println!("{:?}", script.execute().unwrap());
        thread::sleep(ten_millis);
    }
}

It runs all 1000 iterations without problems.

Looks like the main requirement for OSAKit is to be on the main thread. And tests are run on separate threads, therefore they fail sometimes.

[eugenesvk]

Oh, so it's purely a testing issue! Thanks for finding out!

Do you know of any way to force the main thread for tests? It seems that there is a Rust issue rust-lang/rust#104053 suggesting the defaults don't support that

[mdevils]

Looks like this problem was many times discussed within the context of cargo test and never got fixed.

I've created a feature request in nextest, maybe we will be more lucky there: nextest-rs/nextest#1959

[eugenesvk]

I've tried with the mentioned libtest-mimic directly, and it seems to work with the extra arg, but would be nice if it's also added to the nextest

[mdevils]

Several additions:

1. I've added a check for main thread: 15abae4
2. Tests are now run in the main thread: 2041f07
3. Created a crate to simplify running tests using libtest-mimic: https://crates.io/crates/libtest-mimic-collect