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

Implement timers for the X11 platform #1096

Merged
merged 9 commits into from
Jul 21, 2020
Merged

Conversation

psychon
Copy link
Contributor

@psychon psychon commented Jul 18, 2020

This fixes half of #934, but does not deal with #934 (comment)

Timers are collected in a BinaryHeap per window, sorted by deadline. The main loop gets the first deadline of each window and uses the minimum of that for the timeout used in the call to poll. I am least comfortable with my changes to poll_with_timeout(). Hopefully, this function can be simplified a lot when someone (else) handles #934 (comment).

This was tested with cargo run --example invalidate --no-default-features --features x11 (and with nothing else). The result looks similar to the version without --features x11, which should be GTK. Before this PR, --features x11 lead to an empty window instead.

@luleyleo luleyleo added S-needs-review waits for review shell/x11 concerns the X11 backend labels Jul 18, 2020
Copy link
Collaborator

@jneem jneem left a comment

Choose a reason for hiding this comment

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

Indeed, I think the timeouts in poll_with_timeout aren't quite right. It looks good otherwise, though!

druid-shell/src/platform/x11/application.rs Outdated Show resolved Hide resolved
druid-shell/src/platform/x11/application.rs Outdated Show resolved Hide resolved
druid-shell/src/platform/x11/util.rs Outdated Show resolved Hide resolved
@luleyleo
Copy link
Collaborator

I did not yet have a look at the code, but I tried it with the timer example and noticed two problems:

  • The square seems to move slower than in the GTK example
  • The square accelerates when I move the cursor to roughly GTK speed

@luleyleo luleyleo added S-waiting-on-author waits for changes from the submitter and removed S-needs-review waits for review labels Jul 19, 2020
Signed-off-by: Uli Schlachter <psychon@znc.in>
This makes the following command work correctly (as far as I can see):

  cargo run --example invalidate --no-default-features --features x11

Fixes-half-of: linebender#934
Signed-off-by: Uli Schlachter <psychon@znc.in>
Signed-off-by: Uli Schlachter <psychon@znc.in>
Signed-off-by: Uli Schlachter <psychon@znc.in>
Signed-off-by: Uli Schlachter <psychon@znc.in>
Thanks to @jneem for catching this.

Signed-off-by: Uli Schlachter <psychon@znc.in>
@psychon
Copy link
Contributor Author

psychon commented Jul 19, 2020

The square seems to move slower than in the GTK example

Yup. No idea yet what happens. I'll investigate.

To make this a bit less subjective, I did:

diff --git a/druid/examples/timer.rs b/druid/examples/timer.rs
index f31637a..5949fed 100644
--- a/druid/examples/timer.rs
+++ b/druid/examples/timer.rs
@@ -15,6 +15,7 @@
 //! An example of a timer.
 
 use std::time::Duration;
+use std::time::Instant;
 
 use druid::widget::prelude::*;
 use druid::widget::BackgroundBrush;
@@ -24,6 +25,7 @@ static TIMER_INTERVAL: Duration = Duration::from_millis(10);
 
 struct TimerWidget {
     timer_id: TimerToken,
+    timeout_requested: Instant,
     simple_box: WidgetPod<u32, SimpleBox>,
     pos: Point,
 }
@@ -49,12 +51,20 @@ impl Widget<u32> for TimerWidget {
         match event {
             Event::WindowConnected => {
                 // Start the timer when the application launches
+                self.timeout_requested = Instant::now();
                 self.timer_id = ctx.request_timer(TIMER_INTERVAL);
             }
             Event::Timer(id) => {
                 if *id == self.timer_id {
+                    let elapsed = self.timeout_requested.elapsed();
+                    if elapsed < TIMER_INTERVAL {
+                        println!("Timeout is {:?} early", TIMER_INTERVAL - elapsed);
+                    } else {
+                        println!("Timeout is {:?} late", elapsed - TIMER_INTERVAL);
+                    }
                     self.adjust_box_pos(ctx.size());
                     ctx.request_layout();
+                    self.timeout_requested = Instant::now();
                     self.timer_id = ctx.request_timer(TIMER_INTERVAL);
                 }
             }
@@ -119,6 +129,7 @@ impl Widget<u32> for SimpleBox {
 pub fn main() {
     let window = WindowDesc::new(|| TimerWidget {
         timer_id: TimerToken::INVALID,
+        timeout_requested: Instant::now(),
         simple_box: WidgetPod::new(SimpleBox),
         pos: Point::ZERO,
     })

Output is:
Gtk:

Timeout is 89.263µs early
Timeout is 563.821µs early
Timeout is 360.599µs early
Timeout is 338.149µs early
Timeout is 587.387µs early
Timeout is 77.686µs early
Timeout is 621.249µs early
Timeout is 234.995µs early
Timeout is 408.812µs early
Timeout is 41.96µs late
Timeout is 414.332µs early
Timeout is 748.723µs early
Timeout is 528.43µs early
Timeout is 780.295µs early

X11:

Timeout is 129.242µs late
Timeout is 1.397298ms late
Timeout is 1.619458ms late
Timeout is 6.540825ms late
Timeout is 6.784348ms late
Timeout is 164.414µs late
Timeout is 1.38442ms late
Timeout is 1.589043ms late
Timeout is 6.516359ms late
Timeout is 6.808551ms late
Timeout is 132.782µs late
Timeout is 1.398832ms late
Timeout is 1.599091ms late
Timeout is 6.582464ms late
Timeout is 6.730138ms late
Timeout is 131.859µs late

@psychon
Copy link
Contributor Author

psychon commented Jul 19, 2020

Something is being slow and I do not know what. I also added

diff --git a/druid-shell/src/platform/x11/application.rs b/druid-shell/src/platform/x11/application.rs
index 8d879eb..a1cc61f 100644
--- a/druid-shell/src/platform/x11/application.rs
+++ b/druid-shell/src/platform/x11/application.rs
@@ -569,6 +569,9 @@ fn poll_with_timeout(conn: &Rc<XCBConnection>, idle: RawFd, timer_timeout: Optio
                 .contains(PollFlags::POLLIN)
         };
 
+        let before = Instant::now();
+        let p = poll(poll_fds, poll_timeout);
+        println!("Poll for {} returned {:?} in time {:?}", poll_timeout, p, before.elapsed());
         match poll(poll_fds, poll_timeout) {
             Ok(_) => {
                 if readable(poll_fds[0]) {

Output is:

Poll for 9 returned Ok(0) in time 9.121401ms
Timeout is 6.617062ms late
Poll for 9 returned Ok(0) in time 9.117681ms
Timeout is 6.450287ms late
Poll for 9 returned Ok(0) in time 9.123917ms
Timeout is 6.895794ms late
Poll for 9 returned Ok(0) in time 9.124663ms
Timeout is 6.599921ms late
Poll for 9 returned Ok(0) in time 9.125751ms

The timer example uses a timeout of 10 ms. This ends up as a 9 ms timeout for poll() and poll() seems to be obey this request quite well. No idea where the other 6 ms are spent. The output above also suggests that there is exactly one call to poll() before the timer is run, so this is also not due to something "forgetting" to run the timeouts.

No idea what to make of this.

@psychon
Copy link
Contributor Author

psychon commented Jul 19, 2020

Found it. It's something like a rounding issue.

When the timer_timeout is 9.5 ms in the future, poll() is called with a timeout of 9 ms. It then wakes up before the timeout, thus poll() is called again. However, this new call still uses the old timeout.

Recomputing the timeout in each loop iteration "does the trick".

Signed-off-by: Uli Schlachter <psychon@znc.in>
@luleyleo luleyleo added S-needs-review waits for review and removed S-waiting-on-author waits for changes from the submitter labels Jul 19, 2020
if deadline < now {
0
} else {
c_int::try_from(deadline.duration_since(now).as_millis())
Copy link
Contributor Author

Choose a reason for hiding this comment

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

I guess it would be best if this would round up instead of round down (in as_millis()). Since that does not seem to be easily possible: How about adding a +1 to the result? That way, poll should sleep until "something interesting" happens. Otherwise, it is possible that Instant::now() is less than 1 ms before "something interesting" and the code here would busy loop with poll() with a timeout of zero...

Copy link
Collaborator

Choose a reason for hiding this comment

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

I think adding 1 ms is a good approach.

if deadline < now {
0
} else {
c_int::try_from(deadline.duration_since(now).as_millis())
Copy link
Collaborator

Choose a reason for hiding this comment

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

I think adding 1 ms is a good approach.

// ...and convert the deadline into an argument for poll()
let poll_timeout = if let Some(deadline) = deadline {
if deadline < now {
0
Copy link
Collaborator

Choose a reason for hiding this comment

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

Why not just break here?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

A combination of "historic reasons" and "I do not follow understand the idle drawing code". The previous code definitely did not return early and might have went into a short busy loop. I think. I am not sure.

I'll just change it to a break (and also to <= instead of <, but that shouldn't make much of a difference).

Duration::as_millis() seems to round down. This means that a timeout of
e.g. 5.5 ms results in a call to poll() with a timeout of 5 ms. Thus, we
wake up too early. This results in a short spike of CPU usage where
poll() is called with a timeout of 0 ms until "it is time".

Fix this by adding one to the timeout that is passed to poll().

Signed-off-by: Uli Schlachter <psychon@znc.in>
Signed-off-by: Uli Schlachter <psychon@znc.in>
@jneem jneem merged commit cffde32 into linebender:master Jul 21, 2020
@psychon psychon deleted the x11_timers branch July 22, 2020 12:55
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
S-needs-review waits for review shell/x11 concerns the X11 backend
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants