Inconsistent Response Time Measurements in Bevy App on Both WASM and Desktop

I'm trying to develop a simple psychology experiment using the Bevy engine, which runs on both WASM and desktop. I measure the response times from when ellipses are displayed until a user provides input.

The experiment measures response times, but I've noticed that sometimes the results are logarithmic and incorrect (In other words, this issue doesn't always occur, making it challenging to reproduce consistently. Both the WASM and desktop versions exhibit this behavior.)

Here is the online demo: https://altunenes.github.io/weber_fechner/ you can get your simple CSV output for the experiment (it has 5 trials).

here is how I handle time in my experiment:

#[derive(Resource)]
struct TrialState {
    start_time: Instant,
}

impl Default for TrialState {
    fn default() -> Self {
        TrialState {
            start_time: Instant::now(),
        }
    }
}

fn refresh_ellipses(
    // ... some code ...
) {
    if experiment_state.ellipses_drawn && (keys.just_pressed(KeyCode::Key1) || keys.just_pressed(KeyCode::Key0) || keys.just_pressed(KeyCode::Space)) {
        trial_state.start_time = Instant::now();
    }
    // ... code ...
}

fn update_user_responses(
    // ... other parameters ...
) {
    if keys.just_pressed(KeyCode::Key1) || keys.just_pressed(KeyCode::Key0) || keys.just_pressed(KeyCode::Space) {
        let elapsed = trial_state.start_time.elapsed().as_secs_f32();
        // ... rest of the function ...
    }
}

I've double-checked the logic for capturing the start time and calculating the elapsed time, but couldn't find any obvious issues. I've also ensured that the Instant::now() function is being called at the correct moments in the code.

Would you be able to provide insights into why the response times might be calculated incorrectly?

other code for how I take information for the writing as csv:

#[derive(Default, Resource)]
struct ExperimentState {
    final_result: Vec<(usize, usize, String, f32)>,
    // ... other ...
}

fn update_user_responses(
    keys: Res<Input<KeyCode>>,
    mut experiment_state: ResMut<ExperimentState>,
    trial_state: Res<TrialState>,
    mut app_state: ResMut<AppState>,
) {
    // ... code ...

    if keys.just_pressed(KeyCode::Key1) || keys.just_pressed(KeyCode::Key0) || keys.just_pressed(KeyCode::Space) {
        let elapsed = trial_state.start_time.elapsed().as_secs_f32();
        experiment_state.final_result.push((num_left, num_right, result, elapsed));
        // ... rest of the function ...
    }

    if experiment_state.num_trials == TOTAL_TRIAL {
        print_final_results(&experiment_state.final_result);
    }
}

fn print_final_results(final_results: &Vec<(usize, usize, String, f32)>) {
    // ... previous code ...

    let mean_correct_rt: f32 = final_results
    .iter()
    .filter(|(_, _, is_correct, _)| is_correct == "Correct") 
    .map(|(_, _, _, response_time)| response_time)
    .sum::<f32>() / final_results.len() as f32;

I tried the best of my can to simplify my problem still I feel it's so long even in its current form, I really appreciate your time. :(

here is the full code: https://github.com/altunenes/weber_fechner/blob/master/src/main.rs

OS: Windows 11 (latest version)

Solution

After diving deeper into the issue and considering the insightful suggestions provided by @kmdreko, I've identified and resolved the problem. The root cause was indeed related to the order of Bevy system execution.

In my original code, both refresh_ellipses and update_user_responses systems were checking for key presses. This introduced a potential race condition where, depending on the non-deterministic order of system execution in Bevy, refresh_ellipses could reset the start_time just after update_user_responses had calculated the elapsed time. This led to the occasional incorrect and near-instantaneous response times.

To address this, I rearranged the systems in the App::new() function to ensure that update_user_responses always runs before refresh_ellipses. Here's the modified order:

fn main() {
    App::new()
        .add_plugins(DefaultPlugins.set(WindowPlugin {
            primary_window: Some(Window {
                fit_canvas_to_parent: true,
                ..default()
            }), 
            ..default()
        }))
        .insert_resource(AppState::Instruction)
        .insert_resource(ExperimentState::default())
        .insert_resource(TrialState::default()) 
        .insert_resource(FixationTimer::default())

        .add_systems(Startup, setup_camera)
        .add_systems(Update, remove_text_system.before(display_instruction_system))
        .add_systems(Update, display_instruction_system)
        .add_systems(Update, start_experiment_system.after(display_instruction_system))
        .add_systems(Update, display_fixation_system)
        .add_systems(Update, transition_from_fixation_system)
        .add_systems(Update, update_background_color_system)
        .add_systems(Update, update_user_responses) 
        .add_systems(Update, refresh_ellipses.after(update_user_responses)) 
        .run();
}