powerd is making a synchronous D-Bus call to Chrome to turn the displays on, and that's presumably taking two seconds to complete, which blocks powerd seeing the button-up event.

I'll looking into making this call asynchronous. There's some trickiness around this due to us needing some calls to be synchronous during suspend/resume.

Stephane, I'd love to hear your thoughts on this. Here's the relevant code in powerd:

  if (set_display_power) {
    // For instant transitions, this call blocks until Chrome confirms that it
    // has made the change.
    SetDisplayPower(display_power, TransitionToTimeDelta(display_transition));
  }
  
  // Apply the brightness after toggling the display power. If we do it the
  // other way around, then the brightness set here has a potential to get
  // interleaved with the display power toggle operation in some drivers
  // resulting in this request being dropped and the brightness being set to its
  // previous value instead. See chrome-os-partner:31186 and :35662 for more
  // details.
  ApplyBrightnessPercent(brightness_percent, brightness_transition,
                         BrightnessChangeCause::AUTOMATED);

That was ~2015. Is it still necessary for powerd to wait for the display power change to finish before changing the backlight brightness? If so, at the expense of some more complexity in powerd, I could probably switch this to an async call and have powerd wait until the D-Bus call finishes to set the brightness. That would make powerd not block here, which seems desirable anyway.

Note that this would be a risky change, though, and I'd need to make it quickly to be comfortable with asking for a merge to M57. If there's an easier way to work around this in the short term, that'd be better.

Another idea: powerd doesn't currently forward on timestamps from kernel input events, instead adding its own notion of "now" when it processes the event. Possibly it should use timestamps from events instead. This will probably be an easier change, although we need to check that it doesn't have other negative effects.

I am pretty sure that's still needed, since this is a limitation that came from the kernel, and the kernel hasn't changed in that respect.

Re powerd reading timestamps from the input_event struct: that's probably still a good thing, and I have a mostly-done change that should do that, but I realized that it probably won't help at all here. Chrome starts an internal timer when it sees the button-down report from powerd. Including a correct timestamp on the delayed button-up report won't help, since Chrome's timer will have already fired when it shows up.

The only way to fix this will likely be to make powerd not block... which is scary, because we intentionally block right now since the kernel interface that we're using is racy. :-(

I think the change to make powerd's calls async is still worthwhile, but I'm wondering if we can have a safer workaround in the M57 timeframe. Joe, can you test whether https://codereview.chromium.org/2651313004 helps here? I'm going with a 3-second delay, but we may need to avoid starting the timer entirely in this case, as you suggested earlier.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/97f83d816742eef5677384925fd92d10eaa7dc9a

commit 97f83d816742eef5677384925fd92d10eaa7dc9a
Author: derat <derat@chromium.org>
Date: Fri Jan 27 23:43:04 2017

chromeos: Avoid shutdown for delayed power button events.

powerd makes blocking D-Bus calls to Chrome to turn the display on or
off. When a power-button-down event turns the display on, this can
result in the corresponding power-button-up event being delayed, which
can then cause the system to be shut down prematurely.

As a hopefully low-risk workaround for this, make
TabletPowerButtonController wait 2000 (rather than 500) milliseconds
before starting the shutdown animation if the screen was off when the
power button was pressed.

BUG=685734

Review-Url: https://codereview.chromium.org/2651313004
Cr-Commit-Position: refs/heads/master@{#446832}

[modify] https://crrev.com/97f83d816742eef5677384925fd92d10eaa7dc9a/ash/system/chromeos/power/tablet_power_button_controller.cc

Merge requested for https://codereview.chromium.org/2651313004.

+ketakid

Approving merge to M57 Chrome OS.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/85d16735d1bdb59df1a1c229e8d381aa1a1a92f5

commit 85d16735d1bdb59df1a1c229e8d381aa1a1a92f5
Author: derat <derat@chromium.org>
Date: Mon Jan 30 21:33:20 2017

chromeos: Avoid shutdown for delayed power button events.

powerd makes blocking D-Bus calls to Chrome to turn the display on or
off. When a power-button-down event turns the display on, this can
result in the corresponding power-button-up event being delayed, which
can then cause the system to be shut down prematurely.

As a hopefully low-risk workaround for this, make
TabletPowerButtonController wait 2000 (rather than 500) milliseconds
before starting the shutdown animation if the screen was off when the
power button was pressed.

BUG=685734
NOTRY=true
NOPRESUBMIT=true

Review-Url: https://codereview.chromium.org/2651313004
Cr-Commit-Position: refs/heads/master@{#446832}
(cherry picked from commit 97f83d816742eef5677384925fd92d10eaa7dc9a)

Review-Url: https://codereview.chromium.org/2662903002
Cr-Commit-Position: refs/branch-heads/2987@{#188}
Cr-Branched-From: ad51088c0e8776e8dcd963dbe752c4035ba6dab6-refs/heads/master@{#444943}

[modify] https://crrev.com/85d16735d1bdb59df1a1c229e8d381aa1a1a92f5/ash/system/chromeos/power/tablet_power_button_controller.cc

I'm going to keep this open to track making powerd's D-Bus calls async. The release-blocking issue should be worked around now, though.