Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Poll system information in separate tasks #13693

Merged
merged 4 commits into from
Jun 10, 2024

Conversation

Brezak
Copy link
Contributor

@Brezak Brezak commented Jun 5, 2024

Objective

Reading system information severely slows down the update loop.
Fixes #12848.

Solution

Read system info in a separate thread.

Testing

  • Open the scene 3d example
  • Add FrameTimeDiagnosticsPlugin, SystemInformationDiagnosticsPlugin and LogDiagnosticsPlugin to the app.
  • Add this system to the update schedule to disable Vsync on the main window
fn change_window_mode(mut windows: Query<&mut Window, Added<Window>>) {
    for mut window in &mut windows {
        window.present_mode = PresentMode::AutoNoVsync;
    }
}
  • Read the fps values in the console before and after this PR.

On my PC I went from around 50 fps to around 1150 fps.


Changelog

Changed

  • The SystemInformationDiagnosticsPlugin now reads system data separate of the update cycle.

Added

  • The EXPECTED_SYSTEM_INFORMATION_INTERVAL constant which defines how often we read system diagnostic data.

src/main.rs Outdated Show resolved Hide resolved
Copy link
Contributor

@IceSentry IceSentry left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think this should be implemented with a thread only used for that. I feel like it should use bevy's task system and create a new task based on the polling rate.

@IceSentry
Copy link
Contributor

The sleep also doesn't take into account the time it took to get the info so it will sleep for longer than necessary. Which is another reason why using a thread + sleep isn't great.

@IceSentry IceSentry added A-Diagnostics Logging, crash handling, error reporting and performance analysis C-Performance A change motivated by improving speed, memory usage or compile times A-Dev-Tools Tools used to debug Bevy applications. labels Jun 5, 2024
@Brezak
Copy link
Contributor Author

Brezak commented Jun 5, 2024

I don't think this should be implemented with a thread only used for that. I feel like it should use bevy's task system and create a new task based on the polling rate.

Do we have a equivalent of smol's unblock or tokio's spawn_blocking? sysinfo doesn't support async and from my understanding spawning a blocking task could block the whole task pool.

@IceSentry
Copy link
Contributor

IceSentry commented Jun 5, 2024

Here's more or less what I had in mind. I tested it and it works like I would expect.

 pub(crate) fn diagnostic_system(
        mut diagnostics: Diagnostics,
        mut sysinfo: Local<Option<Arc<Mutex<System>>>>,
        mut tasks: Local<Vec<Task<SysinfoRefreshData>>>,
        mut last_refresh: Local<Option<Instant>>,
    ) {
        if sysinfo.is_none() {
            *sysinfo = Some(Arc::new(Mutex::new(System::new_with_specifics(
                RefreshKind::new()
                    .with_cpu(CpuRefreshKind::new().with_cpu_usage())
                    .with_memory(MemoryRefreshKind::everything()),
            ))));
        }
        let Some(sys) = sysinfo.as_mut() else {
            error!("sysinfo should have been created at this point");
            return;
        };
        if last_refresh.is_none() {
            *last_refresh = Some(Instant::now());
        }
        let Some(last_refresh) = last_refresh.as_mut() else {
            error!("last_refresh should have been created at this point");
            return;
        };

        let thread_pool = AsyncComputeTaskPool::get();

        // Only queue a new system refresh task when necessary
        // Queueing earlier than that will not give new data
        if last_refresh.elapsed() > sysinfo::MINIMUM_CPU_UPDATE_INTERVAL {
            let sys = sys.clone();
            let task = thread_pool.spawn(async move {
                let mut sys = sys.lock().unwrap();

                sys.refresh_cpu_specifics(CpuRefreshKind::new().with_cpu_usage());
                sys.refresh_memory();
                let current_cpu_usage = sys.global_cpu_info().cpu_usage();
                // `memory()` fns return a value in bytes
                let total_mem = sys.total_memory() as f64 / BYTES_TO_GIB;
                let used_mem = sys.used_memory() as f64 / BYTES_TO_GIB;
                let current_used_mem = used_mem / total_mem * 100.0;

                SysinfoRefreshData {
                    current_cpu_usage,
                    current_used_mem,
                }
            });
            tasks.push(task);
            *last_refresh = Instant::now();
        }

        let mut tasks_completed = vec![];
        for (i, mut task) in tasks.iter_mut().enumerate() {
            let Some(refresh_data) = block_on(future::poll_once(&mut task)) else {
                continue;
            };
            tasks_completed.push(i);

            diagnostics.add_measurement(&SystemInformationDiagnosticsPlugin::CPU_USAGE, || {
                refresh_data.current_cpu_usage as f64
            });
            diagnostics.add_measurement(&SystemInformationDiagnosticsPlugin::MEM_USAGE, || {
                refresh_data.current_used_mem
            });
        }
        for task_completed in tasks_completed {
            drop(tasks.remove(task_completed));
        }
    }

There might be a better way to do this without Arc<Mutex<System>> and all those Local, but that's the rough outline of what I meant.

The idea is to queue a small task every time you want to refresh the system data. I don't think it will block the main thread using this approach, but I'm not entirely sure. At least it doesn't poll every frame though. It might be better to do the polling and task clean up in a separate system too, not sure.

This also takes advantage of the fact that bevy is already running in a loop so no need to have another loop for that.

@Brezak
Copy link
Contributor Author

Brezak commented Jun 6, 2024

I've tough about it a don't think launching multiple tasks will work. If a task gets stuck reading data for at least the time it takes to generate one + margin (e.g. the system took to long to get the data) we're likely to violate the minimum cpu update interval.

1. Task0 is spawned and takes a while to finish

Task0 ~~~

2. Task1 gets spawned but Task0 hasn't finished

Task0 ~~~ Task1

3. Task0 finishes a while after Task1 was spawned.

Task0 ~~~ Task1 ~|
                 ^
 Task0 has finished, Task1 has started immediately after

4. worst case Task1 finishes before another task can spawn

Task0 ~~~ Task1 ~|~| Task2 
                 ^ |
      Task0 has finished, Task1 has started
                   |
                   ^
           Task1 has finished
                       
5. Task2 gets to start immediately

Task0 ~~~ Task1 ~|~| Task2 
                 ^ |   |
      Task0 has finished, Task1 has started
                 | |   |
                 | ^   |
             Task1 has finished
                 |     |
                 |     ^
            Task2 has started
                 |     |
                 ^~~~~~^
            The time it took Task2 to start after Task1 started is less than MINIMUM_CPU_UPDATE_INTERVAL.
            It's output will be garbage.
            

@IceSentry
Copy link
Contributor

The minimum time interval is 100ms on linux and 200ms on everything else. I doubt it would ever take more than that to get the cpu info, but if we want to protect against it we could add a timestamp to the task and check that it hasn't been longer than the minimum and drop it if it has. We could also just hardcode it to 200ms to stay on the safer side.

@IceSentry
Copy link
Contributor

Another solution could be to not spawn any task and just do it at a fixed interval in a regular system. The system will run in parallel so it won't block any work, the only issue is if it takes longer than the duration of a frame to sample the cpu. We could detect that and start logging errors if it happen or maybe even stop sampling the cpu if it does it multiple times

@IceSentry
Copy link
Contributor

IceSentry commented Jun 6, 2024

Okay, nevermind, it takes 5ms on my machine to refresh the cpu data so we probably shouldn't do that in a system. At least it's 5ms that doesn't block anything else in the frame, but that's still really long and could create stutters on games that run fast enough.

@Brezak Brezak changed the title Poll system information in separate thread Poll system information in separate tasks Jun 6, 2024
Copy link
Contributor

@IceSentry IceSentry left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not sure about the exposed constant, but everything else LGTM

@IceSentry IceSentry added this to the 0.15 milestone Jun 10, 2024
@IceSentry IceSentry added C-Bug An unexpected or incorrect behavior S-Needs-Review Needs reviewer attention (from anyone!) to move forward labels Jun 10, 2024
Copy link
Member

@alice-i-cecile alice-i-cecile left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agreed on the exposed constant: remove it and optionally try and document this more in the plugin docs. Once that's done this LGTM and I'll merge.

@alice-i-cecile alice-i-cecile modified the milestones: 0.15, 0.14 Jun 10, 2024
@Brezak Brezak force-pushed the system-info-slowdown branch 4 times, most recently from 6c4f9cc to 5095ba0 Compare June 10, 2024 18:44
@alice-i-cecile
Copy link
Member

Once CI is green I'll merge this :)

@alice-i-cecile alice-i-cecile added S-Ready-For-Final-Review This PR has been approved by the community. It's ready for a maintainer to consider merging it and removed S-Needs-Review Needs reviewer attention (from anyone!) to move forward labels Jun 10, 2024
Co-authored-by: IceSentry <IceSentry@users.noreply.github.com>
@alice-i-cecile alice-i-cecile added this pull request to the merge queue Jun 10, 2024
Merged via the queue into bevyengine:main with commit f187d9c Jun 10, 2024
31 checks passed
mockersf pushed a commit that referenced this pull request Jun 10, 2024
Reading system information severely slows down the update loop.
Fixes #12848.

Read system info in a separate thread.

- Open the scene 3d example
- Add `FrameTimeDiagnosticsPlugin`, `SystemInformationDiagnosticsPlugin`
and `LogDiagnosticsPlugin` to the app.
- Add this system to the update schedule to disable Vsync on the main
window
```rust
fn change_window_mode(mut windows: Query<&mut Window, Added<Window>>) {
    for mut window in &mut windows {
        window.present_mode = PresentMode::AutoNoVsync;
    }
}
```
- Read the fps values in the console before and after this PR.

On my PC I went from around 50 fps to around 1150 fps.

---

- The `SystemInformationDiagnosticsPlugin` now reads system data
separate of the update cycle.

- The `EXPECTED_SYSTEM_INFORMATION_INTERVAL` constant which defines how
often we read system diagnostic data.

---------

Co-authored-by: IceSentry <IceSentry@users.noreply.github.com>
@Brezak Brezak deleted the system-info-slowdown branch June 10, 2024 20:50
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-Dev-Tools Tools used to debug Bevy applications. A-Diagnostics Logging, crash handling, error reporting and performance analysis C-Bug An unexpected or incorrect behavior C-Performance A change motivated by improving speed, memory usage or compile times S-Ready-For-Final-Review This PR has been approved by the community. It's ready for a maintainer to consider merging it
Projects
None yet
Development

Successfully merging this pull request may close these issues.

SystemInformationDiagnosticsPlugin is slow due to sysinfo crate
5 participants