FYI - dithering addition in 0.29.1 had a massive perf cost to our ARM64 app

[mrpathos]

We updated from 0.28.1 to 0.29.1 a bit ago, and only noticed recently that it had dropped our framerate from a rock-solid 60fps to 35fps. This is especially odd because our display is 60Hz refresh so I'm not even sure where 35 is coming from, exactly.

Our app is compiled for an i.MX8 / ARM64 core computer, and we hadn't changed anything else.

I got puffin working (didn't even know it existed before this, btw, and it's really awesome to have a nice instrumenting profiler now, thanks!) and the change was almost entirely in swap_buffers - it shot from 9-10ms to 28+ms. When I see that I just assume it's vsync or some weird timing thing on the swap.

I finally just made an ultra-simple app from the egui "hello world" that just prints the framerate in big letters in the center of a fullscreen. undecorated window, and reproduced the issue. I binary-searched through egui commits, and the offender was this one that added a dithering pass and defaulted it to true:

b283b8a

I haven't dug in more, but I'm still not sure why that addition caused such a massive performance hit. Maybe it has to happen as a post-pass so it complicates the buffer swap timing or something? In any case, it remains the case that our entire render pass, in puffin, takes ~4-5ms tops on the i.MX8, so I just wanted to post this as an FYI that that dithering support can take a pretty straightforward app all of whose rendering completes fast enough to be rendering at 180fps, theoretically, and caps it at the strange number 35 on the i.MX8. Not sure why, not sure I'll investigate more, we don't need or want dithering anyhow so I'll probably just leave it off.

[mrpathos]

I had posted some followups that I've deleted because I had a test app that reproduced the issue, but for a while I was seeing weird performance issues where even at 60fps it was randomly getting extremely long (230ms+) frames. And then in adding more info to the screen to try to figure that out, it randomly went away.

My updated app to reproduce the issue shows an FPS counter, the last 60 frame times, and a rectangle animating sinusoidally up and down the right side of the screen. I'll post info on the dithering perf hit / puffin questions next...

use std::{collections::VecDeque, f32::consts::PI, time::{Duration, Instant}};

use eframe::egui;
use egui::{pos2, vec2, Color32, Rect, RichText, UiBuilder, Vec2};

fn main() -> eframe::Result {
    let options = eframe::NativeOptions {
        viewport: egui::ViewportBuilder::default()
            .with_inner_size([1024.0, 1920.0])
            .with_fullscreen(true)
            .with_decorations(false)
            .with_resizable(false),
        vsync: true,
        dithering: false,
        ..Default::default()
    };

    let _puffin_server = puffin_http::Server::new("0.0.0.0:8585").unwrap();
    puffin::set_scopes_on(true);

    eframe::run_native(
        "My egui App",
        options,
        Box::new(|_cc| {
            Ok(Box::<MyApp>::default())
        }),
    )
}

struct MyApp {
    frame_times: VecDeque<f32>,
    last_render: Option<Instant>,
    start_time: Instant,
    label_offset: usize,
}

impl Default for MyApp {
    fn default() -> Self {
        Self {
            frame_times: Default::default(),
            last_render: None,
            start_time: Instant::now(),
            label_offset: 0,
        }
    }
}

impl eframe::App for MyApp {
    fn update(&mut self, ctx: &egui::Context, _frame: &mut eframe::Frame) {
        puffin::GlobalProfiler::lock().new_frame();
        {
            puffin::profile_scope!("App::update");

            let now = Instant::now();
            if let Some(last_time) = self.last_render {
                let elapsed = now - last_time;
                let elapsed_f32 = elapsed.as_secs_f32();
                self.frame_times.push_back(elapsed_f32);
                while self.frame_times.len() > 60 {
                    self.frame_times.pop_front();
                }

                self.label_offset = match self.label_offset {
                    0 => self.frame_times.len() - 1,
                    _ => self.label_offset - 1,
                }
            }
            self.last_render = Some(now);
            let fps = if self.frame_times.is_empty() { 
                0.0 
            } else {
                1.0 / (self.frame_times.iter().sum::<f32>() / self.frame_times.len() as f32) 
            };

            let rect_pos = pos2(800.0, 960.0) + vec2(0.0, 800.0 * (self.start_time.elapsed().as_secs_f32() / 2.0).sin());

            egui::CentralPanel::default().show(ctx, |ui| {
                ui.painter().rect_filled(Rect::from_center_size(rect_pos, vec2(100.0, 100.0)), 0.0, Color32::WHITE);
                let mut sub_ui = ui.new_child(UiBuilder::new().max_rect(Rect::from_min_max(pos2(100.0,100.0), pos2(800.0, 1920.0)))); 
                sub_ui.label(RichText::new(format!("FPS: {}", fps)).size(30.0).color(Color32::GREEN));

                for i in self.label_offset..self.frame_times.len() {
                    sub_ui.end_row();
                    sub_ui.label(RichText::new(format!("{} ms", (self.frame_times[i] * 1000.0) as u32)).size(18.0).color(Color32::WHITE));
                }
                for i in 0..self.label_offset {
                    sub_ui.end_row();
                    sub_ui.label(RichText::new(format!("{} ms", (self.frame_times[i] * 1000.0) as u32)).size(18.0).color(Color32::WHITE));
                }
               
            });

            ctx.request_repaint_after(Duration::from_millis(16));
        }
    }
}

[mrpathos]

Here's a puffin view of it running without dithering. A few questions:

• Any good reason it would be randomly skipping frames? (The orange-y frames are too long and miss vsync.) The rendering takes next-to-no time, so this is just swap_buffers taking longer these times. It doesn't matter how often I request a repaint (Tried turning it down to 12ms in case 16 was somehow aliasing against 16.667) and the puffin view looks the same - randomly swap_buffers just decides to take too long. I understand I'm asking "Why would my iMX8 running my own Yocto image do this?" and the answer might be "Who knows, it's probably an OpenGL driver issue or Wayland issue or something."

• Any idea why there are so many gaps (what appear to be empty frames) in the Puffin Recent Frames view along the top? Maybe just a puffin_viewer bug? I just call new_frame once per frame; there should be no way to have two of those with no data between them.

[mrpathos]

More importantly, here's the puffin view of it running with dithering on.

Note that the rendering still takes essentially zero time, but now swap_buffers just takes a lot longer, and this little baby app is capped at 35fps on the iMX8 just by turning dithering on.

Still don't understand why the dithering pass would do this. I went to look at the code to see if maybe the swap_buffers profile scope had other stuff in it and needed to be broken up, but it's literally just wrapping the GL buffer swap call. So I'm really not sure why dithering would cause this perf drop and that it would look like this in the profiling view.

[mrpathos]

@emilk I guess my most basic suggestion here would just be that if new features are added that are controlled behind flags in NativeOptions or other construction structs, maybe to just default them to off and document them in the release notes? I still haven't dug in to understand exactly why dithering is hurting our perf this badly, but it wouldn't matter if it hadn't been added and silently turned on (the word "dither" doesn't occur in the 0.29 or 0.29.1 release notes) since it would have been opt-in.

[Wumpf]

Note that the rendering still takes essentially zero time, but now swap_buffers just takes a lot longer, and this little baby app is capped at 35fps on the iMX8 just by turning dithering on.

swap_buffers is rendering. It is waiting for both being able to swap front & backbuffer. In a double buffered environment (as opposed to a triple buffered one) that means that both the rendering has to be finished and the screen has to be ready to get a new picture.

The latter is important the the most likely explanation why you see strong hickups without dithering: Some frames you hit the screen's vblank and some you just miss it and thus skip a frame, meaning you have to wait for the next opportunity to present the frame (which is about every 16ms on a 60hz screen).
(I have no idea about the fully blank ones in puffin's report though)

-> Is triple buffering an option here (and can we even set this in the glow environment? is this something that is configurable? I haven't checked, personally I only ever worked with wgpu here). With triple buffered enabled, this would be less of an issue since frames can queue up to be shown onto the screen. The drawback is that this adds some latency.

Which gets us to the much more interesting question of why this is costly enough to push us over to missing vblanks!
At first reading this was very surprised: The dithering feature that was added was seen as an absolutely trivial extension of the existing (single!) shader that the glow & wgpu backends use for drawing (see b283b8a#diff-53ae5d4427c6f4f74f877eb877fa41ff2b8b81297566b108f007711562c18d95R66). This having a large impact on performance is completely unexpected! But that's from the perspective of mobile & desktop/laptop hardware.
However, if I read that right you're running on an edge device, probably running with 1-2 Vivante GC7000 (I googled for iMX8 ;-)) GPUs each in the ballpark of 32 Gflops (for comparison iPhone 5 from 2012 has 68 Gflops on its gpu). So if you pair that with a high resolution (aforementioned iPhone had less than 720p ;-)) it's not too surprising that reading out additional fragment attributes (gl_FragCoord) as well as additional multiplications & divisions would be poisonous to performance.
This setup probably also answers the question of triple buffering with a clear 'no', since this would take additional memory which might be precious.

So with the information at hand I'd conclude that, yes, this should have been better called out in the release notes! But I'd disagree that this should be an opt-in feature since for the vast majority of egui's usecases the perf impact of this isn't noticeable.

but for a while I was seeing weird performance issues where even at 60fps it was randomly getting extremely long (230ms+) frames.

no clue about that part either

[mrpathos]

Fair point, and humbling - it's clearly been a while since I was writing OpenGL drivers :) And it's the GC7000 Ultra Lite in the imx8mp, so 32gflops.

OK, so we're not so far under the 60fps limit as I'd hoped; alas.

Thanks for the reply!

[mrpathos]

That said, triple-buffering isn't a bad idea, I've gotta check on how the graphics memory gets carved out.