screensaver can't be interrupted once fade begins

Description of problem:
With xorg-x11-server-Xorg-1.8.2-1.fc13, it is no longer possible to interrupt fade-out-to-screensaver with either a keypress or mouse movement.

Works OK under xorg-x11-server-Xorg-1.8.0-12.fc13.x86_64.

Version-Release number of selected component (if applicable):
gnome-screensaver-2.30.0-1.fc13.x86_64
gnome-power-manager-2.30.1-1.fc13.x86_64

[I understand this might be a X server bug, but I've filed it under g-ss for the time begin. Please reassign as appropriate.]

I have the same package versions as mentioned in comment 1, but am unable to reproduce this issue.

(In reply to comment #1)
> I have the same package versions as mentioned in comment 1, but am unable to
> reproduce this issue.

Maybe it's hardware dependent. I have Intel X3100 graphics with xorg-x11-drv-intel-2.11.0-5.fc13.x86_64.

Please add drm.debug=0x04 to the kernel command line, restart your computer, reproduce the issue, then attach to following items to the bug report as individual uncompressed file attachments using the bugzilla file attachment link above.

* your X server config file (/etc/X11/xorg.conf, if available),
* X server log file (/var/log/Xorg.*.log)
* output of the dmesg command, and
* system log (/var/log/messages)

Also, is the computer fading out to a screensaver, or to low power mode?

Created attachment 430725
yum.log showing the packages that were update/installed on 2010-07-08

Yesterday I could not reproduce this issue. Today I can.

I have attached a log showing the 80 packages (minus the debuginfo packages) that were installed/updated on my machine yesterday.

Prime suspects are 'libdrm' and 'kernel' and maybe 'xorg-x11-drv-vmmouse'. In my free time, I will try downgrading each to see if that resolves the problem.

(In reply to comment #2)
> (In reply to comment #1)
> > I have the same package versions as mentioned in comment 1, but am unable to
> > reproduce this issue.
>
> Maybe it's hardware dependent. I have Intel X3100 graphics with
> xorg-x11-drv-intel-2.11.0-5.fc13.x86_64.

Sounds reasonable:

00:02.0 VGA compatible controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (rev 0c)

xorg-x11-drv-intel-2.11.0-5.fc13.x86_64

Sorry, I should have mentioned mine is:
   ATI Technologies Inc RS690M [Radeon X1200 Series] [1002:791f]

Created attachment 430743
dmesg output with drm.debug=0x04 after failed attempt to stop a fadeout

Created attachment 430744
Xorg.0.log after failed attempt to stop fadeout

(In reply to comment #3)
> Please add drm.debug=0x04 to the kernel command line, restart your computer,
> reproduce the issue, then attach to following items to the bug report as
> individual uncompressed file attachments using the bugzilla file attachment
> link above.
>
> * your X server config file (/etc/X11/xorg.conf, if available),
> * X server log file (/var/log/Xorg.*.log)
> * output of the dmesg command, and
> * system log (/var/log/messages)
>
> Also, is the computer fading out to a screensaver, or to low power mode?

No xorg.conf. dmesg and Xorg logs attached. Not posting full /v/l/m since it contains IP addresses I don't want announced here; give me a grep cmdline to extract what's needed and I'll do it.

This is fading out to the screensaver. My laptop has no facility for software brightness control.

I also see this bug, with ATI Technologies Inc RV350 AR [Radeon 9600].

FWIW, I've found that it works again now for me since I rebooted in the meantime (Intel video chipset).

(In reply to comment #11)
> FWIW, I've found that it works again now for me since I rebooted in the
> meantime (Intel video chipset).

And now again it doesn't... Not sure if that is because of the time the system/X server is running or something else.

I have also seen this on intel hardware but it doesn't happen every time.

Can you try to reproduce the problem while running "gnome-screensaver --no-daemon --debug" and attach the log from that here?

Created attachment 431279
(NOT INTERRUPTED) Log generated by 'gnome-screensaver --no-daemon --debug'

Attaching the output of 'gnome-screensaver --no-daemon --debug'. During this session I started moving the mouse and pressing keys on the keyboard moments after the 'fade' started. While moving the mouse/pressing keys I noticed that no new debug messages were being printed in the terminal running gnome-screensaver.

A similar log from when the 'fade' was properly interrupted will be attached next.

Created attachment 431281
(PROPERLY INTERRUPTED) Log generated by 'gnome-screensaver --no-daemon --debug'

Log generated by 'gnome-screensaver --no-daemon --debug' showing the screensaver being interrupted by moving the mouse. This log was created just moments after the previous log, using the same PC/terminal/command line/etc.

Same issue here:

gnome-screensaver-2.30.0-1.fc13.x86_64
xorg-x11-server-Xorg-1.8.2-1.fc13.x86_64
xorg-x11-drv-intel-2.11.0-5.fc13.x86_64
>uname -r
2.6.33.6-147.fc13.x86_64

00:02.0 VGA compatible controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (rev 0c)

Created attachment 434132
.config for kernel.org kernel 2.6.34.1

OK, this gets weirder: this problem goes away for me if I use a "vanilla" kernel.org kernel rather than the one from Fedora. Specifically:

  kernel.org 2.6.34.1 -- fine;
  kernel-2.6.34.1-29.fc13.x86_64 -- results in the bug.

I have attached the .config I have been using for the vanilla kernel.

(In reply to comment #17)
> OK, this gets weirder: this problem goes away for me if I use a "vanilla"
> kernel.org kernel rather than the one from Fedora.

Actually scratch that, seems like a fluke. Like Comment 13, I now see it intermittently (even with kernels I've built myself).

I have the same issue and tried to debug it a little bit. I traced calls
to the function gs_fade_set_alpha while running gnome-screensaver with
"--gdk-debug=misc,events --gtk-debug=misc". At each breakpoint I printed the value of the alpha-argument to gs_fade_set_alpha. Albeit gdk receives the
keyboard-events gnome-screensaver keeps on fading.

Excerpt:
$214 = 0.5500000000000046
$215 = 0.5466666666666713
Gdk-Message: key press : window: 44040195 key: Control_L 65507
Gdk-Message: property notify: window: 44040195, atom(337): "_NET_WM_USER_TIME"
$216 = 0.543333333333338
$217 = 0.5400000000000047

I too see this on my Fedora 13 x86-64 desktop with all current updates.

My video card is an Asus EAH3650 Silent Magic. That is a Radeon HD3650.
X is using the radeon driver from xorg-x11-drv-ati-6.13.0-1.fc13.x86_64
The kernel is kernel-2.6.33.6-147.2.4.fc13.x86_64

The uninterruptible fade started happening a couple of months ago (my memory is fuzzy, but it could have been when I installed F13 (in June) or after a subsequent update).

The problem seems to happen every time.

I have two menu entries under System:Preferences identically labelled "Screensaver". The first is "Screensaver Preferences (XScreenSaver 5.11-8.1.fc13.respin1, 25-Jul-2010". The other is the Gnome Screensaver. When I switch between them, they want to stop the other's daemon and start theirs. Neither solves the problem.

Created attachment 437758
Root cause analysis 1

I believe the issue is with Xorg, in Xext/sync.c. Here is the trace.
I saw this issue about 60-80% of the runs, on several F13 with various
(three, that is) video cards.

#1 What is g-ss thinking?
   output from "gnome-screensaver --no-daemon --debug"; see [1] for details

   Good case:
        [_gs_watcher_set_session_idle_notice] gs-watcher-x11.c:202 (12:11:16):
  Changing idle notice state: 1
      <User hit a key>
        [watcher_idle_notice_cb] gs-monitor.c:125 (12:11:19):
  Idle notice signal detected: 0 <=== '0' in good case

   Bad case:
 [_gs_watcher_set_session_idle_notice] gs-watcher-x11.c:202 (12:08:15):
  Changing idle notice state: 1
      <User hit a key>
 [watcher_idle_cb] gs-monitor.c:95 (12:08:25):
  Idle signal detected: 1 <=== '1' in bad case

#2 Does g-ss receive that fading-interruption msg at all?
   output from "strace -tt -e read=all -e write=all -o g-ss.strace
  gnome-screensaver --no-daemon --debug"; see [2] for details.
   Good case:
 write(2, "... Changing idle notice state: 1")
 read (6, "/org/gnome/SessionManager/Presence ... StatusChanged ..."
 write(2, "... Idle notice signal detected: 0")
   Bad case:
 write(2, "... Changing idle notice state: 1")
 write(2, "... Idle signal detected: 1")

   So in bad case, no, g-ss did not receive fading-interruption msg at
   all, which came in at fd 6. Who sent (or should send) this msg?
   Luckily the sender announced its name in msg: SessionManager
   ("gnome-session", "g-s" for short).

#3 Why does g-s not sending the fading-interrupt msg?
   output from "strace -tt -e read=all -e write=all -o g-s.strace
  -p $(pgrep gnome-session)" [3]
   - good case:
     g-s received a msg from fd 3,
 00:23:24.569436 read(3, "`\1\237\1\206\0\300\0\0"..., 4096) = 32
     then wrote "StatusChanged" msg on fd 6, which goes to g-ss (You
     can do strace on both g-s and g-ss at the same time to confirm;
     the msg content will be identical, but the time stamp will be
     slightly off. There is a dbus in the middle acting as event
     channel, thus the delay.).
   - bad case:
     g-s receives no msg from fd 3; instead, at the end of fading, g-ss
     sends "ActiveChanged" to inform g-s "screen saver started already."

#4 Who sent the msg to g-s on fd 3?
   This one took much tracing. Previously (bug566350) I tracked it
   down to Xorg (the X sever), in Xext/sync.c.

   sync.c provides some counter services, one of which is the idle
   counter. The idle counter (in msec) goes up as time passes, and
   resets to 0 upon user activity (mouse, keyboard). (sync.c keeps a
   "last activity time stamp," which is updated with every user
   activity. The idle counter is actually the difference of current
   time and last activity time stamp).

   g-ss uses two "alarms" on idle counter: positive transition
   ("+trans") and negative transition ("-trans"). Eg. with idle time
   set to 60 sec, g-ss registers two alarms: one +trans 60,000ms, the
   other -trans 60,000ms. When the user idles, the idle counter goes
   from 0ms and up. When it reaches 60,000ms or more, the +trans
   alarm is fired. The "transition" means the a...

These 4 bugs seems to be related, or are the same one.
  bug612620 Fade-out to screensaver cannot be interrupted
            with xorg-x11-server-Xorg-1.8.2-1.fc13
  bug615786 As screensaver activates and screen dims cannot intervene
            with mouse/keys
  bug620186 The fading of the screen when GNOME screensaver start is
            not interruptible
  bug620264 gnome-screensaver activates whether or not activity occurs
            once dimming starts

*** Bug 615786 has been marked as a duplicate of this bug. ***

*** Bug 620264 has been marked as a duplicate of this bug. ***

(In reply to comment #21)

Thanks for your analysis. I updated my xserver with your proposed patch and it works well here.

(In reply to comment #25)
> Thanks for your analysis. I updated my xserver with your proposed patch and it
> works well here.

Hm, bad news. I just had a couple of fade-outs that I could not interrupt.

Hannes,
Thanks for your independent verification that Fix #1 (Comment #21 item
#7) works in some cases (Comment #25), and your report of unsolved
cases (Comment #26). Yesterday I started to notice the same unsolved
cases too, and it took me a while to track down the issue.

Here is an example of Issue #2, which is not covered by Fix #1.
    19:44:33.343 #5 SyncChangeCounter newval=60000, oldval=21114,
                                          pIdle<=-1, pIdle>=60000
    19:44:33.344 #4 SyncAlarmTriggerFired alarm id 0x00c00005, counter=60000
    19:44:33.344 #9 SyncComputeBracketVal counte=60000, test = 60000, psci<=0
    19:44:37.441 #7 IdleTimeQueryValue idle = 1, oldval=60000,
                                          pIdle<=-1, pIdle>= -1

sync.c uses "pIdleTimeValueLess", "pIdleTimeValueGreater" (denoted as
"pidle<", "pIdle>" hereafter) to track when alarms should be
triggered. They (pIdle<,pidle>) could be null pointer (denoted as
"-1" in my debug output), or some value (eg. 60000 msec). For +trans
(-trans) alarms, sync.c checks current idle count against pIdle>
(pIdle<), *if* the pointer is not null.

At "19:44:37.441 #7", when idle count goes from 60000 to 1 (idle = 1,
oldval= 60000; caused by user key activity),
    *** the -trans alarm should be triggered, but it is not. ***
Why? Because pIdle< is null (denoted by "-1"), which is wrong; it
should be 60000ms for the -trans alarm from g-ss.

Who sets pIdle<? "#9 SyncComputeBracketValues" does. Look at this
code snippet:
    else if (pTrigger->test_type == XSyncNegativeTransition ...) {
        if (XSyncValueGreaterThan(pCounter->value, pTrigger->test_value) &&
            XSyncValueGreaterThan(pTrigger->test_value, psci->bracket_less))
It also has boundary condition issue. Why this first test?
      pCounter->value > pTrigger->test_value # Test#1
            eg. 60001 > 60000
Because we want to check for -trans, which means the idle counter
(pCounter->value) goes from above test_value to below test_value
(eg. from 60001ms to 1ms, which crosses the 60000ms boundary). We
need this 2nd test
      pTrigger->test_value > psci->bracket_less # Test#2
to handle multiple -trans alarms, in which case we want the trigger
with largest test_value.

What happens to Test#1 in the case of this?
    19:44:33.344 #9 SyncComputeBracketVal counte=60000, test = 60000, psci<=0
It does not pass Test#1 (it should).
      pCounter->value > pTrigger->test_value # Test#1
                60000 > 60000? False.
So issue #2 has the same boundary issue: 60000 should be considered as
"above the threshold", as in Fix #1.

Fix#2:
Change Test#1 to
      pCounter->value >= pTrigger->test_value # Test#1bis

After both Fix #1, Fix #2, I have not seen this issue again. But then
again, the issue always pops up when you think you have it nailed :-).

I searched sync.c for "Negative" and look for similar pattern as in
Fix #1,#2. There are only two occurences, fixed by #1,#2 separately.
So please let me know if you see further occurences.

Fix #1 (Comment #21 item #7)
    SyncCheckTriggerNegativeTransition(SyncTrigger *pTrigger, CARD64 oldval)
    {
        return (pTrigger->pCount...

Some thoughts on this issue.

1. Why 60-80% of the cases are bad? Why not 100%? Where is the
   randomness coming from?
   - Looks like it's from the timing. When alarms are triggered, they
     may or may not be right on the requested moment. It's perfectly
     fine to be late by a few msec. When it's right on time, it
     turned out be a corner case (bug612620 Comment#21) that is not
     handled well by sync.c.

   - people with faster machine (than my 1997 vintage desktop) will
     probably experience higher rate (eg. 95%) of bad cases, because
     faster machines have higher chance to trigger the alarm right on
     time.

2. Why was it not an issue in F12?
   - in F12, the alarms is also triggered right on time, which
     _would_ be the corner case. However in F12 sync.c always invoke
     SyncChangeCounter() a few more times than necessary, after the
     alarm is triggered. The net result is that the counter value is
     never right on the border.
 00:02:11.110 #5 SyncChangeCounter newval=60000, oldval=10003
 00:02:11.110 #4 SyncAlarmTriggerFired alarm id 0x00c0000d,counter=60000
 00:02:11.111 #5 SyncChangeCounter newval=60001, oldval=60000
     Note that "newval= 60001", not 60000 (the border, aka.
     test_value). In F12 the newval always ends up a few msec more
     than the test value.

   - in F13, this extra invocation of SyncChangeCounter is
     eliminated. So when the alarm is triggered, newval remains right
     on the border.
 17:34:58.532 #5 SyncChangeCounter newval=60000, oldval=20010
 17:34:58.533 #4 SyncAlarmTriggerFired alarm id 0x00c00015,counter=60000
 17:35:04.796 #5 SyncChangeCounter newval= 1, oldval=60000
     Note that, after #4 SyncAlarmTriggerFired, newval remains 60000,
     the boundary condition that exposes an existing old bug. Also
     note that the second "#5 SyncChangeCounter" in F13 was 6 sec
     later, unlike F12, which is within 1 msec.

   - so my guess is that sync.c in F13 has some good improvements
     (removing extra calls to SyncChangeCounter), which exposes an
     existing old boundary-condition bug.

Again, thanks a lot! I am using your patch for some hours and have not seen a misbehaving gnome-screensaver so far.

Hannes,
Also thanks for your independent verification! I tried my own fix
#1,#2 all day today, interrupted fading 100+ times without issue.
Looks like we have this issue fixed properly.

Anyone knows how to bring this issue and fix to the attention of Xorg
folks? I filed
    bug622651 Xext/sync.c IDLETIME counter sometimes fails to fire
              negative transition alarms
on the Xorg side, but saw no action on it yet. We need them to review
and approve this two fixes and put into the source tree.

Adam,
Has this bug been fixed already in F13? If so, can we close this bug?

While debugging
    bug612620 Fade-out to screensaver cannot be interrupted with
              xorg-x11-server-Xorg-1.8.2-1.fc13
I tested
    xorg-x11-server-Xorg-1.8.2-3.fc13.i686
with the test case in Comment #3. xorg 1.8.2-3 (with fix#1,#2 in
bug612620 Comment #27) actually performed properly, no missing alarms
as it did in F11, F12. So please close this bug if you agree.

Oops, please ignore Comment #31. It was meant for bug566350.

Change component to xorg-x11-server, assign to ajax.

--
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Adam,
Any news on this issue? Anything we can help? Thanks.

This is how ubuntu fixed this case: http://git.debian.org/?p=pkg-xorg/xserver/xorg-server.git;a=blob;f=debian/patches/204_fix-neg-sync-transition.patch;h=f10fb3237fb9984711832d4fd0ce2ef2a8b1f862;hb=3a2e34b19a0553b5e425eb49e4fed4a2a34ca728

Hannes,
Thanks for info! I checked out their fix just now. It looks
like an awkward solution to a simple issue. I still say the right and
simple solution is in Comment #27.

Adam,
Any news?

Both of those Ubuntu patches have gone to the X mailing list, and have been reviewed by Adam Jackson; once Xserver starts seeing some commits again I expect them to be applied to master.

I think the changes in https://bugzilla.redhat.com/show_bug.cgi?id=612620#c27 , while they will fix the gnome-screensaver issue, are wrong. The SYNC extension defines a negative transition as triggered from a counter strictly *above* the threshold to ≤ the threshold, whereas the changes proposed will trigger from ≥ the threshold to < the threshold.

Gnome-screensaver is separately broken; they shouldn't be setting a positive & negative transition trigger with the same threshold. There's a patch on the upstream GNOME bug for that.

Created attachment 446373
Fig.38 illustration on Def.1 and Def.3 of +/- transition alarms

Chris,
Thanks for replying! Sure, you guys did the work on Xext/sync.c, so
you decide what to do. I am just saying that there is an easier way
(Comment #27) to fix the same issue (and the problematic definition of
negative transition) without jumping through hoops (ie. schedule a 1ms
timer when the counter falls on the threshold, which occurs quite
often). I am of the old school of "keep it simple and stupid."

For this bug, I saw 3 definitions of the transition counters; they
boil down to the following: (th=threshold, oldval=previous value of
counter, newval=new value of counter)

    Def.1 (Before any of these fix)
      +trans: triggers when oldval < th && th <= newval
      -trans: triggers when newval <= th && th < oldval

    Def.2 (from Chris, link in Comment #35)
      +trans: triggers when oldval < th && th <= newval
      -trans: triggers when newval < th && th < oldval

      (Please correct me if I wrongly interpreted your definition; I got
       this interpretation from your comment
           The {Positive,Negative}Transition triggers only fire when the
           counter goes from strictly {below,above} the threshold.
       and your other comment
            * We've been called exactly on the idle time, but we have a
            * NegativeTransition trigger which requires a transition from
            * an idle time greater than this. Schedule a wakeup for the
            * next millisecond so we won't miss a transition.
      )

    Def.3 (from Tim, Comment #27)
      +trans: triggers when oldval < th && th <= newval
      -trans: triggers when newval < th && th <= oldval

Def.1 can be interpreted as follows.
Assume th=60; let th' = th -/+ epsilon (eg. 0.1) = 59.9/60.1.
  +trans: oldval < 59.9 && 59.9 < newval
  -trans: oldval < 60.1 && 60.1 < newval
This view results in the the same behavior as Def.1. But in this view
it is obvious that, given the same th, +trans and -trans actually
occur on different thresholds (th -/+ epsilon, respectively). See
attached Fig.38 for illustration.

From this point of view, Def.3 is more consistent than Def.1: Def.3
uses the same threshold (th - epsilon) for both +/- transition alarms
(see Fig.38). It is also less surprising to the API users, as proven
by the usage of SYNC ext by g-ss and g-p-m (both use the same
threshold for +/- trans. alarms).

> The SYNC extension defines a negative transition as triggered from a
> counter strictly *above* the threshold to ≤ the threshold

If this is the case, why do you need to change anything? The current
implementation (before your change) correctly implemented this
definition. But could you point me to where this is defined? [1]
seems to be the standard about SYNC ext, but it leaves the exact
definition of +/- trans. to the implementation. [2] has concrete
definition, which is same as Def.1. But [2] is a Programmer's Guide,
not a doc defining SYNC ext.

> I think the changes in [Comment #27] ... are wrong.

Yup, it committed the crime of going against a Programmer's Guide,
which is carved in the stone. Reminded me of the guy who was in j...

My commit messages might have mislead you. There are two commits there, neither of which change the definition of a +ve or -ve transition trigger.

The first one adjusts the bounds that the sync implementation is looking for. Currently, if you've got a -ve transition threshold of 60, the sync code will ignore any event over 60 *and not update the current count*. This was the main problem, which the first patch fixes by ensuring the bracket values where the sync code will respond to events are enough to get the current value *past* the thresholds.

This doesn't change the meaning of either a positive or negative transition, just ensures that they'll actually trigger in appropriate circumstances.

The second patch, requiring a wakeup in 1ms if we exactly hit the threshold, is really more for completeness than anything. The server tends to get woken up multiple times in a millisecond anyway.

(In reply to comment #38)
...snip...
> > The SYNC extension defines a negative transition as triggered from a
> > counter strictly *above* the threshold to ≤ the threshold
>
> If this is the case, why do you need to change anything? The current
> implementation (before your change) correctly implemented this
> definition. But could you point me to where this is defined? [1]
> seems to be the standard about SYNC ext, but it leaves the exact
> definition of +/- trans. to the implementation. [2] has concrete
> definition, which is same as Def.1. But [2] is a Programmer's Guide,
> not a doc defining SYNC ext.
>
> > I think the changes in [Comment #27] ... are wrong.
>
> Yup, it committed the crime of going against a Programmer's Guide,
> which is carved in the stone. Reminded me of the guy who was in jail
> for two years, because he failed to put a US. Federal-required label
> on his UPS package.

I'm sorry if I caused offence. I didn't mean to denigrate your work; indeed, your analysis of the problem was very helpful. I meant that I think changing the meaning of the triggers is not the correct way to solve the problem. Other applications using SYNC objects other than IDLETIME might be broken by changing the meaning.

Chris,
Understand, thanks.

> ... changing the meaning of the triggers is not the correct way to
> solve the problem.

This I agree. I made the proposal, not because it's a short cut to
solve the issue at hand, but because I think the current definition of
-ve trigger is questionable. The fact that the proposal happened to
solve this current issue is a bonus.

> Other applications using SYNC objects other than IDLETIME might be
> broken by changing the meaning.

Don't we do this all the time ;-), in open source world. I still have
hard time with gthumb 2.11.x, which is a complete rewrite from 2.10.x.
Many of the old functionalities are still missing.

Fixed in 1.9.0

Adam,
Thanks! Appreciate your effort.

I still have this issue in xorg-x11-server-Xorg-1.9.0-13.fc14.x86_64.

Agree with Nils. I tried xorg-x11-server-1.9.0-15.fc14.src.rpm and
was unable to stop fading 15 out of 367 tries (~4% failure rate).
This is big improvement, compared to >90% in 1.8.2-4 in F13.

Still, this bug is not fixed completely. (I still say the current
definition of negative transition is bad for life (but not wrong), and
could be deprecated after communication with its users. More widely-
used standards evolved in the past (check the IETF standards for
example), and this -ve trans. definition is not even defined in the
standard. But hey, Adam is the owner of the module. I just present
my argument (aka nagging :-) and whatever Adam decides is good for
me.)

For the failed cases, I still saw this (my own) debugging msg:
    10/16 09:15:50.053 #5 SyncChangeCounter newval= 60000
This msg suggests the fix in Comment #35, Comment #39 missed some
scenarios.

That looks like you're hitting the gnome-session problem I alluded to earlier - that's https://bugzilla.gnome.org/show_bug.cgi?id=627903 .

Chris,
I still have this question. Could you point out what is wrong with the
following scenario?
  - set a +ve trans (60000ms) and a -ve trans (60000ms also) alarm.
  - the +ve trans fires at idle_counter=60000
  - 5 sec later (so idle_counter=65000) the user hit a key to
    interrupt fading.
  - idle_counter goes from 65000 to 0.
Any reason why the -ve trans (60000) should not be fired?

That's the bug which *should* have been fixed by the xserver patches. They certainly fix at least one problem which caused that behaviour; there may be other bugs I didn't pick up.

The gnome-session bug is where the +ve transition fires at idle_counter=60000 and in the same tick some input events are generated, so idle_counter never goes above 60000 and the -ve transition (correctly) is never triggered.

I just had this occur 2 out of 3 times on a T410 with Intel HD Graphics running f14 64bit with all updates.

kernel-2.6.35.6-46.fc14
xorg-x11-drv-intel-2.12.0-6.fc14
xorg-x11-server-1.9.0-15.fc14

Re: Comment #47
Chris,
> ... and in the same tick some input events are generated, so
> idle_counter never goes above 60000

Will you believe me if I claim I can generate the input event
(keyboard or mouse), on the same tick (within 1 msec time window) when
idle_counter=60000, with >90% probability in F13 and 4% in F14? I
don't believe such claim; for humans (me included), <0.01% maybe,
definitely not 4% or 90% or 2 out of 3 times.

Here is what I think we overlooked.
  - when determining to trigger an alarm or not, sync.c uses previous
    counter value and new counter value to compare with test_value.

  - This (using previous counter value) is adequate for non-system
    counter, because such counter value change must go through
    SyncChangeCounter(), ie. pCounter->value does not change on its
    own.

  - Unfortunately for idle_counter, the *apparent* value does change
    as time goes by, without invoking SyncChangeCounter(). Why?
    Because idle_counter value is defined as
        idle = GetTimeInMillis() - lastDeviceEventTime.milliseconds;
        /* ie. idle = now - lastEventTime; */
    which changes on its own (GetTimeInMillis() returns different
    value for each milli sec).

  - in view of the above, for idle_counter, we should save
    lastDeviceEventTime.milliseconds in some local variable, eg.
    prevLastDeviceEventTime. When oldval is needed, instead of
        oldval = pCounter->value;
        /* adequate only for non-system counters */
    we should use
        oldval = GetTimeInMillis() - prevLastDeviceEventTime;
        /* for idle_counter */
    so the current idle_counter value is properly updated.

With this change, the different definitions in Comment #38 become
largely irrevelant: they occur only on rare occasions.

(In reply to comment #41)
> Fixed in 1.9.0

I observed this problem continued yesterday, 10/28/2010. Let me know if I can assist with any testing. <email address hidden>

I noticed that the events are sometimes processed out of order: When scrolling with the scroll wheel (well, synaptics touch pad right hand side), _afterwards_ pressing "Control" chromium sometimes zooms in/out of a page, i.e. it recognizes the "Control" key as happening during the scroll-whell action. Is this related to this problem?

*** Bug 629419 has been marked as a duplicate of this bug. ***

Still not fixed in F14, update released. Just observed with:

gnome-screensaver-2.30.2-2.fc14.x86_64
xorg-x11-server-Xorg-1.9.1-2.fc14.x86_64

I'm experiencing this bug on F13 and F14 on my Dell Inspiron 8600 laptop.

Confirm the same in lenovo t510 with f14

*** Bug 643184 has been marked as a duplicate of this bug. ***

Created attachment 460189
Proof-of-concept patch to fix this issue based on Comment #49.

Re: Comment #55, Comment #54, Comment #53, Comment #50
Me too, observed this issue on F14 with 80-90% occurence, about the
same frequency as in F13.

Here is a proof-of-concept patch, based on my Comment #49. Anyone
interested please try it out and see how it goes for you. Thanks.
When I tried it, I was able to break the gamma fading all the time.
As a prototype patch, I also added a flag file
"/tmp/disable.bug612620.fix" so you can enable/disable the proposed
fix on the fly.

Adam,
Chris,
If you don't mind, would you please review the proposed patch?
Thanks.

Created attachment 460190
proof-of-concept patch with debug code.

Here is the same proof-of-concept patch, with debug code. So those
who are interested can observe the behavior of sync.c themselves.

Re: Comment #51
Nils,
No, my opinion was these two are separate issues. Bug612620 is caused
by negative transition alarms not fired properly. Comment #51 is for
apparent out-of-sequence event delivery. I suggest we open another
bug to track Comment #51.

(In reply to comment #58)
> Created attachment 460190 [details]
> proof-of-concept patch with debug code.
>
> Here is the same proof-of-concept patch, with debug code. So those
> who are interested can observe the behavior of sync.c themselves.

Tim, I'm using this patch against xorg-x11-server-Xorg-1.9.1-3.fc14, and it seems to be working (around 6 tests, each one successfully interrupted).

Re: Comment #60
James,
Thanks for testing out the patch! And nice to know it worked for you.
Let's test a bit more and see how the patch holds.

Created attachment 460990
proof-of concept patch v3. (need to undo previous patch first, then apply this patch)

I found some issue with previous patch in Comment #57, Comment #58, so
here is a second try. The issue: when g-p-m (gnome-power-manager)
doubles its timeout to be beyond that of g-ss (eg. g-ss has 60 sec
timeout, and g-p-m has 80 sec timeout; see bug566351 Comment #1),
pIdleTimeValueLess was not updated properly. To test this scenario
without much waiting, do
    k=/apps/gnome-power-manager/backlight/idle_dim_time
    gconftool-2 -g $k # note down this number
    gconftool-2 -s $k -t int 80 # remember to set it back when done

Remember to undo previous patch before applying this one. This patch
is also based on Comment #49.

Adam,
Chris,
James,
Would you please review this patch as well?
Thanks.

Created attachment 460991
proof-of concept patch v3, with debug code. (need to undo previous patch first, then apply this patch)

Here is the same proof-of-concept patch v3, with debug code. So those
who are interested can observe the behavior of sync.c themselves.
The debug output is in /var/log/gdm/:0.log.

Created attachment 461586
proof that the user event is not generated the same tick when idle alarm is triggered

Re: Comment #47
Chris,
> ... and in the same tick some input events are generated, so
> idle_counter never goes above 60000

Here is a proof that the event is NOT generated "in the same
tick."
    00:26:37.032 last user event before idle, last event time=444440660
    00:27:37.032 60 sec later, idle alarm fired, counter= 60000
    00:27:41.631 4 sec later, user hit a key, but the -ve trans. alarm is not
                 triggered. Bad behavior.
                 last event time=444505260
                 time since last user event = 444505260 - 444440660 = 64600 ms

Original log: (see attached file for easier-to-read formatting):
00:26:37.032 #6 IdleTimeQueryValue now=444440660, last event time=444440660, diff= 0
00:26:53.032 #5 SyncChangeCounter newval= 16001, oldval= 4, pIdle<= -1, pIdle>= 16000
00:26:53.032 #4 SyncAlarmTriggerFired alarm id 0x01800003, counter= 16001
00:26:53.035 #1 ProcSyncCreateAlarm alarm id 0x0180006b, type=XSync-Trans, value= 16000
00:27:37.032 #5 SyncChangeCounter newval= 60000, oldval= 16004, pIdle<= 16000, pIdle>= 60000
00:27:37.032 #4 SyncAlarmTriggerFired alarm id 0x0080000b, counter= 60000
00:27:41.631 #6 IdleTimeQueryValue now=444505260, last event time=444505260, diff= 0
00:27:41.631 #5 SyncChangeCounter newval= 0, oldval= 60000, pIdle<= 16000, pIdle>= -1
00:27:41.632 #4 SyncAlarmTriggerFired alarm id 0x0180006b, counter= 0
00:27:41.633 #2 ProcSyncChangeAlarm alarm id 0x01800003, type=XSync+Trans, value= 16000
00:27:41.633 #3 ProcSyncDestroyAlarm alarm id 0x0180006b
00:27:41.770 #6 IdleTimeQueryValue now=444505399, last event time=444505399, diff= 0
00:27:43.270 #6 IdleTimeQueryValue now=444506899, last event time=444506899, diff= 0
00:27:43.405 #6 IdleTimeQueryValue now=444507034, last event time=444507033, diff= 1
00:27:43.549 #6 IdleTimeQueryValue now=444507178, last event time=444507177, diff= 1
00:27:43.652 #6 IdleTimeQueryValue now=444507281, last event time=444507281, diff= 0
00:27:43.789 #6 IdleTimeQueryValue now=444507418, last event time=444507418, diff= 0
00:27:43.883 #6 IdleTimeQueryValue now=444507512, last event time=444507512, diff= 0

*** Bug 626472 has been marked as a duplicate of this bug. ***

(In reply to comment #62)
> Created attachment 460990 [details]
> proof-of concept patch v3. (need to undo previous patch first, then apply this

Still using the older patch, all interruptions working still. Will test new patch.

Using the new patch now. Seems to be working OK so far!

Could we close this?

(In reply to comment #68)
> Could we close this?

Um, no (official) package with this patch is built (yet)?

(In reply to comment #69)
> (In reply to comment #68)
> > Could we close this?
>
> Um, no (official) package with this patch is built (yet)?

Right, leaving it as it is.

(In reply to comment #59)
> I suggest we open another bug to track Comment #51.

I'm pretty sure it's related to the "coasting" feature of the synaptics driver, I opened up bug #656977 for that issue.

I'm now using the patch from Comment #62 and can confirm that I can now interrupt fading reliably. Before that, it was impossible to interrupt the fade 90% of the time. Thank you.

xorg-x11-server-Xorg-1.9.1-3.fc14.i386
gnome-session-2.32.0-1.fc14.i686
gnome-screensaver-2.30.2-2.fc14.i686

System: http://www.smolts.org/client/show/pub_1b5e24f5-9357-4c27-b485-1c332c93e67b

Well I'm happy using a hand-built server with Tim's patch, so is there now any chance of an update for Fedora 14 with this fix included?

James,
Kaare,
Thanks! For trying out the proposed patch and confirming it works
reasonably well.

Nils,
Matej,
James,
Yes, I am still trying to convince Adam and Chris (owners of this
issue) that the issue is in Xext/sync.c and should be fixed in sync.c,
not in other modules (Chris Comment #45). I provided proof in Comment
#64 and patch in Comment #62, waited for Adam or Chris to either
concur or disprove, but got no response so far. The last time I heard
from them was around mid-October (Comment #41, COmment #47).

> ... is there now any chance of an update for Fedora 14 with this fix
> included?

I am curious too. Adam and Chris would know, but they are not
responding.

As a curiosity, if I have a VMWare player running, and release the keyboard from the VMWare client (Windows XP) to the host (Fedora 14) after a period of inactivity, the screen will start fading uninteruptably at that point, with or without the patch.

This may be intended behaviour, since any other behaviour would mean that an active and focused VMWare player would effectively disable the screen lock. However, it's still annoying to have to wait for the fade to complete.

The fading seems to take a very different length of time before completing, though.

These are all just observations that I am unsure whether have anything to do with the bug at hand, I leave that to the maintainers.

Best,
  Kåre

Ah. The reason why this isn't fixed in Xserver 1.9 is that the patches didn't get applied, and I didn't notice because (a) we had applied these in Ubuntu and (b) we hadn't updated the X server until now.

Adam has pinged the upstream xserver maintainer to get those patches applied.

There is still a gnome-session bug, but you're quite unlikely to hit it - it requires microsecond timing to trigger.

xorg-x11-server-1.9.3-3.fc14 has been submitted as an update for Fedora 14.
https://admin.fedoraproject.org/updates/xorg-x11-server-1.9.3-3.fc14

xorg-x11-server-1.9.3-3.fc14 has been pushed to the Fedora 14 testing repository. If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with
 su -c 'yum --enablerepo=updates-testing update xorg-x11-server'. You can provide feedback for this update here: https://admin.fedoraproject.org/updates/xorg-x11-server-1.9.3-3.fc14

The update works for me if I wait for the screensaver timeout (I can interrupt the fade-out now). But I can't interrupt the fade-out if I use 'gnome-screensaver-command -a'. Should that go to a new bug report?

(In reply to comment #79)
> But I can't interrupt the fade-out if I use
> 'gnome-screensaver-command -a'. Should that go to a new bug report?

Is this not the intended behaviour, a-la System/Lock Screen? (In other words, why would you want to interrupt a fade you deliberately invoked?)

(In reply to comment #80)
> (In reply to comment #79)
> > But I can't interrupt the fade-out if I use
> > 'gnome-screensaver-command -a'. Should that go to a new bug report?
>
> Is this not the intended behaviour, a-la System/Lock Screen? (In other words,
> why would you want to interrupt a fade you deliberately invoked?)

Because I can interrupt it as soon as the fade-out finishes. Screen locking is not enabled here, I am just starting the screensaver, not locking the screen.

I don't care about it as I don't use 'gnome-screensaver-command -a', but maybe the developers (or an user who uses gnome-screensaver-command for some reason) see it as a bug.

xorg-x11-server-1.9.3-3.fc14 has been pushed to the Fedora 14 stable repository. If problems still persist, please make note of it in this bug report.

It would be nice to fix this in Fedora 13 too (that's where the original problem was found).

Can this please be fixed in F13?

Fade-out to screensaver (eg blank screen) cannot be interrupted in EL6.3.

(In reply to comment #85)
> Fade-out to screensaver (eg blank screen) cannot be interrupted in EL6.3.

Please open a support case in this case, or at least open a new bug against EL6. Commenting in a closed Fedora bug won't help...

I figured that might be the case and opened a new support case here; https://bugzilla.redhat.com/show_bug.cgi?id=848016