Ticket #2401 (closed defect: fixed)

Opened 2 years ago

Last modified 17 months ago

Wakeup event is repeated continuously

Reported by: cjb Owned by: rsmith
Priority: blocker Milestone: Update.1
Component: embedded controller Version: Git as of bug date
Keywords: power i8042 acpi Cc: philipmac, rsmith, dilinger, jg, dgilmore
Action Needed: Verified: no
Deployments affected: Blocked By:
Blocking:

Description

B4/latest kernel/latest build/Q2C18.

If we wakeup using a game key, with the latest kernel that supports wakeup events, that game key is repeated instead of stopping after a single press.

Steps to reproduce: 1. Load Read activity and a PDF 2. Suspend with power button 3. Press down game key 4. Page will scroll to the bottom of the whole document

Attachments

dmesg (24.9 kB) - added by chihyu 18 months ago.
messages (24.0 kB) - added by chihyu 18 months ago.
rainbow (23.4 kB) - added by chihyu 18 months ago.
Xorg.0.log (38.7 kB) - added by chihyu 18 months ago.

Change History

  Changed 2 years ago by dilinger

I can't reproduce this on a b3 or b4 while suspending/resuming with smithbone's new firmware (q2cdb9.rom). However, I *can* make the gamekey down happen repeatedly without suspending; that is, open up the ebook reader, hit the down gamekey, and watch it scroll without stop.. It's tough to reproduce, though.

I suspect a race somewhere in the input stack; that is, either the EC spitting the gamekey out over the 8042, the i8042 driver processing it, the X input driver that's grabbing it from the kernel's input device, or the ebook reader. Unfortunately, I haven't managed to reproduce it while simultaneously watching /proc/interrupts, so I don't know whether we're actually getting repeated 8042 interrupts.

  Changed 2 years ago by dilinger

Alright, got it. Hit the down gamekey repeatedly and pull the battery out; if timed correctly, the gamekey gets "stuck". However, we only get 1 or 2 SCIs and a few i8042 (keyboard) interrupts. My suspicion is either: a) the kernel is losing the 'up' gamekey press due to the SCI we're getting somehow conflicting, or b) the ebook reader or Xorg is somehow getting stuck when we get an SCI; possibly the input device ending up with the wrong data in it?

  Changed 2 years ago by dilinger

Oh, and serial console to the rescue; here's what it looks like: 

  1:       2206    XT-PIC-XT        i8042                                       
  3:         90    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
[ 1576.649670] olpm-pm:  SCI 0x2 received                                       
[ 1576.657467] olpm-pm:  SCI 0x0 received                                       
[ 1577.430818] olpm-pm:  SCI 0x4 received                                       
[ 1577.437606] olpm-pm:  SCI 0x0 received                                       
  1:       2206    XT-PIC-XT        i8042                                       
  3:         92    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
[ 1577.691034] atkbd.c: Unknown key released (translated set 2, code 0xe0 on isa
0060/serio0).                                                                   
[ 1577.699323] atkbd.c: Use 'setkeycodes e060 <keycode>' to make it known.      
  1:       2238    XT-PIC-XT        i8042                                       
  3:         92    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         92    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         92    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         92    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
[ 1582.247218] olpm-pm:  SCI 0x2 received                                       
[ 1582.254105] olpm-pm:  SCI 0x0 received                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         93    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
[ 1582.898091] olpm-pm:  SCI 0x4 received                                       
[ 1582.904992] olpm-pm:  SCI 0x0 received                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         94    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
[ 1584.150223] olpm-pm:  SCI 0x2 received                                       
[ 1584.157017] olpm-pm:  SCI 0x0 received                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         95    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         95    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         95    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         95    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042                                       
  1:       2256    XT-PIC-XT        i8042                                       
  3:         95    XT-PIC-XT        SCI                                         
 12:      16578    XT-PIC-XT        i8042

Towards the end there, the ebook reader got stuck scrolling down. The SCI events seen were from me pulling and putting the battery back in. The unknown key error is anyone's guess..

  Changed 2 years ago by dilinger

Here's an interesting one.. 

  1:       2646    XT-PIC-XT        i8042                                       
  3:        109    XT-PIC-XT        SCI                                         
 12:      22602    XT-PIC-XT        i8042                                       
[ 1900.010550] olpm-pm:  SCI 0x2 received                                       
[ 1900.017463] olpm-pm:  SCI 0x0 received                                       
[ 1900.188473] Waited 106 ms for IBF during cmd 0x15!                           
[ 1900.300724] Waited 104 ms for IBF during cmd 0x15!                           
[ 1900.305667] atkbd.c: Unknown key released (translated set 2, code 0xe0 on isa
0060/serio0).                                                                   
[ 1900.313946] atkbd.c: Use 'setkeycodes e060 <keycode>' to make it known.      
[ 1900.653479] olpm-pm:  SCI 0x4 received                                       
[ 1900.660372] olpm-pm:  SCI 0x2 received                                       
[ 1900.667233] olpm-pm:  SCI 0x0 received                                       
[ 1900.798616] Waited 105 ms for IBF during cmd 0x15!                           
[ 1900.919994] Waited 103 ms for IBF during cmd 0x15!                           
[ 1900.924927] atkbd.c: Unknown key released (translated set 2, code 0xe0 on isa
0060/serio0).                                                                   
[ 1900.933206] atkbd.c: Use 'setkeycodes e060 <keycode>' to make it known.      
[ 1901.078750] Waited 103 ms for IBF during cmd 0x84!                           
[ 1901.083683] olpm-pm:  SCI 0x0 received                                       
  1:       2657    XT-PIC-XT        i8042                                       
  3:        112    XT-PIC-XT        SCI                                         
 12:      22602    XT-PIC-XT        i8042                                       
[ 1902.123486] atkbd.c: Unknown key released (translated set 2, code 0xe0 on isa
0060/serio0).                                                                   
[ 1902.131774] atkbd.c: Use 'setkeycodes e060 <keycode>' to make it known.      
  1:       2659    XT-PIC-XT        i8042                                       
  3:        112    XT-PIC-XT        SCI                                         
 12:      22602    XT-PIC-XT        i8042

Is having interrupts disabled for too long screwing us?

  Changed 2 years ago by cjb

This is still present with latest kernel/EC: 

+r[    0.024575] olpm-pm:  SCI 0x1 received
[    0.029346] olpm-pm:  SCI 0x0 received
[    0.461995] Restarting tasks ... done.
[    3.234445] olpm-pm:  PM_PWRBTN event received
[    3.247985] Stopping tasks ... done.
[    3.282322] olpc_do_sleep!
+r[    0.099613] Waited 84 ms for IBF during cmd 0x24!
[    0.109482] olpm-pm:  SCI 0x1 received
[    0.114252] olpm-pm:  SCI 0x0 received
[    0.424191] Restarting tasks ... done.
[    2.112217] olpm-pm:  PM_PWRBTN event received
[    2.125719] Stopping tasks ... done.
[    2.140536] olpc_do_sleep!
+r[    0.029540] olpm-pm:  SCI 0x1 received
[    0.035320] olpm-pm:  SCI 0x0 received
[    0.133771] Restarting tasks ... done.
[    0.203819] atkbd.c: Unknown key released (translated set 2, code 0xe0 on is.
[    0.212106] atkbd.c: Use 'setkeycodes e060 <keycode>' to make it known.

  Changed 2 years ago by cjb

Here's an evbug log of the failure mode with "unknown key released", although I don't think it's exhibiting the repeated key problem right now: 

[    0.455320] OLPC-DCON 0-000d: resuming
[    0.456206] platform dcon: resuming
[    0.456233] ac97 0-0:AD1888: resuming
[    0.456251] ov7670 1-0042: resuming
[    0.456269] platform olpc-battery.0: resuming
[    0.456293] Restarting tasks ... done.
[    0.481923] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 1, Code: 330, Value: 1
[    0.481949] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 1, Code: 325, Value: 1
[    0.481977] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.482005] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 1
[    0.482035] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.486001] olpc-dcon: The CPU has control
[    0.503091] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.503134] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.515101] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.515139] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.527238] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.527276] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.551285] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 2
[    0.551320] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.563005] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 7
[    0.563041] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 1, Value: 266
[    0.563068] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.575064] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.575096] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 3
[    0.575126] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.587184] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.587222] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.598762] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.598795] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 4
[    0.598823] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 1, Value: 267
[    0.598850] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.610682] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 7
[    0.610714] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 5
[    0.610744] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.622856] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 6
[    0.622890] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.634190] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 6
[    0.634222] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 7
[    0.634252] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.646137] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 7
[    0.646169] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 8
[    0.646199] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.658461] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 10
[    0.658490] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 10
[    0.658521] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.669856] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.669888] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 11
[    0.669919] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.682419] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.682451] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 12
[    0.682481] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.694360] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 6
[    0.694398] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.717930] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 5
[    0.717968] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.730119] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 7
[    0.730151] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 13
[    0.730181] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.741800] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 11
[    0.741838] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.777638] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 10
[    0.777676] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.789011] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.789049] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.801323] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.801355] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 12
[    0.801383] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 1, Value: 268
[    0.801411] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.824549] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.824582] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 11
[    0.824612] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.836953] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 11
[    0.836985] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 9
[    0.837015] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.849157] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.849190] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 8
[    0.849220] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.860300] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.860331] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 7
[    0.860361] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.873166] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 6
[    0.873201] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.885113] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.885151] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.896868] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.896900] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 5
[    0.896930] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.908337] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    0.908375] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.920343] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 1, Value: 267
[    0.920374] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.932641] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 0, Value: 4
[    0.932676] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.944197] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.944234] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.968010] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 7
[    0.968048] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.979499] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    0.979537] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    0.991700] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 7
[    0.991738] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    1.004379] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 9
[    1.004417] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    1.015412] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 8
[    1.015450] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    1.051715] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 6
[    1.051751] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 1, Value: 266
[    1.051779] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    1.053939] evbug.c: Event. Dev: isa0060/serio0/input0, Type: 4, Code: 4, Value: 224
[    1.053969] atkbd.c: Unknown key released (translated set 2, code 0xe0 on isa0060/serio0).
[    1.094196] atkbd.c: Use 'setkeycodes e060 <keycode>' to make it known.
[    1.117944] evbug.c: Event. Dev: isa0060/serio0/input0, Type: 0, Code: 0, Value: 0
[    1.121978] evbug.c: Event. Dev: isa0060/serio0/input0, Type: 4, Code: 4, Value: 72
[    1.122022] evbug.c: Event. Dev: isa0060/serio0/input0, Type: 1, Code: 72, Value: 1
[    1.122051] evbug.c: Event. Dev: isa0060/serio0/input0, Type: 0, Code: 0, Value: 0
[    1.129272] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 1, Code: 330, Value: 0
[    1.129303] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 1, Code: 325, Value: 0
[    1.129327] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    1.129358] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 1, Code: 330, Value: 1
[    1.129383] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 1, Code: 325, Value: 1
[    1.129411] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 7
[    1.129444] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 0, Code: 0, Value: 0
[    1.146522] evbug.c: Event. Dev: isa0060/serio1/input1, Type: 3, Code: 24, Value: 6

  Changed 2 years ago by dilinger

Here's what the i8042 driver sees. Normally when you hit a gamekey, you get 4 interrupts: 

Aug  1 19:59:35 localhost kernel: [  671.864765] drivers/input/serio/i8042.c: e0
 <- i8042 (interrupt, 0, 1) [65598]                                             
Aug  1 19:59:35 localhost kernel: [  671.864879] drivers/input/serio/i8042.c: 66 <- i8042 (interrupt, 0, 1) [65598]                                             
Aug  1 19:59:35 localhost kernel: [  671.906417] drivers/input/serio/i8042.c: e0 <- i8042 (interrupt, 0, 1) [65602]                                             
Aug  1 19:59:35 localhost kernel: [  671.906520] drivers/input/serio/i8042.c: e6 <- i8042 (interrupt, 0, 1) [65602]

e0, 66 <- key down e0, e6 <- key up

When we get those errors, we're losing bytes: 

e0 <- i8042 (interrupt, 0, 1) [88540]                                           
Aug  1 20:03:25 xo-03-55-81 kernel: [  901.215424] drivers/input/serio/i8042.c: 
66 <- i8042 (interrupt, 0, 1) [88540]                                           
Aug  1 20:03:25 xo-03-55-81 kernel: [  901.256872] drivers/input/serio/i8042.c: 
e0 <- i8042 (interrupt, 0, 1) [88543]                                           
Aug  1 20:03:25 xo-03-55-81 kernel: [  901.256985] drivers/input/serio/i8042.c: 
66 <- i8042 (interrupt, 0, 1) [88543]                                           
Aug  1 20:03:25 xo-03-55-81 kernel: [  901.274913] drivers/input/serio/i8042.c: 
e0 <- i8042 (interrupt, 0, 1) [88546]                                           
Aug  1 20:03:25 xo-03-55-81 kernel: [  901.275025] drivers/input/serio/i8042.c: 
e6 <- i8042 (interrupt, 0, 1) [88546]                                           
[  904.391887] olpm-pm:  SCI 0x2 received                                       
[  904.396672] olpm-pm:  SCI 0x0 received                                       
[  904.580782] Waited 100 ms for IBF during cmd 0x11!                           
[  904.867934] atkbd.c: Unknown key released (translated set 2, code 0xe0 on isa
0060/serio0).                                                                   
[  904.876214] atkbd.c: Use 'setkeycodes e060 <keycode>' to make it known.      
Aug  1 20:03:28 xo-03-55-81 kernel: [  904.391887] olpm-pm:  SCI 0x2 received   
Aug  1 20:03:28 xo-03-55-81 kernel: [  904.396672] olpm-pm:  SCI 0x0 received   
Aug  1 20:03:28 xo-03-55-81 kernel: [  904.580782] Waited 100 ms for IBF during 
cmd 0x11!                                                                       
Aug  1 20:03:28 xo-03-55-81 kernel: [  904.587786] drivers/input/serio/i8042.c: 
e0 <- i8042 (interrupt, 0, 1) [88877]                                           
Aug  1 20:03:28 xo-03-55-81 kernel: [  904.867864] drivers/input/serio/i8042.c: 
e0 <- i8042 (interrupt, 0, 1) [88905]                                           
Aug  1 20:03:28 xo-03-55-81 kernel: [  904.867934] atkbd.c: Unknown key released
 (translated set 2, code 0xe0 on isa0060/serio0).                               
Aug  1 20:03:28 xo-03-55-81 kernel: [  904.876214] atkbd.c: Use 'setkeycodes e06
0 <keycode>' to make it known.                                                  
Aug  1 20:03:28 xo-03-55-81 kernel: [  904.882985] drivers/input/serio/i8042.c: 
66 <- i8042 (interrupt, 0, 1) [88907]                               
...
e0 <- i8042 (interrupt, 0, 1) [88944]                                           
Aug  1 20:03:29 xo-03-55-81 kernel: [  905.256612] drivers/input/serio/i8042.c: 
66 <- i8042 (interrupt, 0, 1) [88944]                                           
Aug  1 20:03:29 xo-03-55-81 kernel: [  905.305713] drivers/input/serio/i8042.c: 
e0 <- i8042 (interrupt, 0, 1) [88949]                                           
Aug  1 20:03:29 xo-03-55-81 kernel: [  905.305825] drivers/input/serio/i8042.c: 
e6 <- i8042 (interrupt, 0, 1) [88949]                                           
Aug  1 20:03:29 xo-03-55-81 kernel: [  905.562273] olpm-pm:  SCI 0x2 received   
Aug  1 20:03:29 xo-03-55-81 kernel: [  905.568435] olpm-pm:  SCI 0x0 received

At that point, the ebook reader is continuing to scroll down without any interrupts showing up.

e0, 66, e0, 66 <- holding the gamekey down e0, e6 <- key up SCIs received, 100ms of interrupts being disabled atkbd complains about unknown key press; e0 another SCI, another 100ms of interrupts being disabled e0, 66 <- key down ... e0, 66 <- key down e0, e6 <- key up

We've lost some key presses there. That is somehow confusing the ebook reader. The ebook reader probably should not get confused (since we *do* end on a key down event); it should skip the mangled bits and properly process the final keypress(es).

We also need to not be dropping key presses. Either we're losing interrupts due to the EC cmd function keeping interrupts disabled for so long, or the EC is mangling the bytes that it's sending up to us when it attempts to both stuff bytes into the LPC bus and respond to EC commands.

  Changed 2 years ago by dilinger

  • owner changed from dilinger to rsmith

Richard has looked into this; he has discovered one problem, and we have a theory about the *real* problem.

The theory is as follows. The EC will not complete an EC command while it is waiting for its keyboard buffer to be emptied. If it times out waiting for the OS to read the keyboard buffer (after 100ms), it clears the buffer and re-enters its state machine (at which point, it finishes processing the EC command). From the kernel, when we run an EC command, we disable interrupts. When a gamekey is pressed, that generates 4 8042 interrupts total (2 for key down, 2 for key up).

So, we press a key; the EC stuffs byte #1 into the keyboard buffer. Linux's i8042 interrupt handler reads that byte and sends it to the input layer. At this point, the battery is inserted, it does some SCI processing, and schedules some EC commands to run. The EC command starts; we disable interrupts, send out the EC command, and wait for the EC to read the byte. meanwhile, the EC stuffs byte #2 into the keyboard buffer. This would normally trigger an interrupt, but the cpu has interrupts disabled. The kernel is waiting for the EC to read the command byte; the EC is waiting for the kernel to read the key from the 8042 buffer. The EC spins for 100ms, gives up, and flushes the byte from the 8042 buffer. It reenters its state machine, processes the EC command, and sends back a reply. The kernel gets the reply, finishes the EC command, and re-enables interrupts. The EC then goes back to dealing with key presses, but a byte has been lost. Since we're also waiting for 100ms with interrupts disabled, we could also be losing *more* keypresses; however, at that point we're pretty hosed anyways.

The first problem (which has been verified) which Richard has identified is that we should not be dropping keys from the 8042 buffer when we get a timeout. The second problem is the deadlock; this has not been verified, there needs to be more attention paid to it.

Reassigning to Richard

  Changed 2 years ago by jg

  • keywords power added

  Changed 2 years ago by jg

  • milestone changed from Trial-2 to Trial-3

From talking to Richard and Andres, this is now understood, and we have both a short term patch and a longer term strategy...

Richard, can you release a patched version, even though not the long term fix, please? Ebook mode is really important.

  Changed 22 months ago by jg

  • status changed from new to closed
  • resolution set to fixed

  Changed 22 months ago by philipmac

  • status changed from closed to reopened
  • resolution deleted

I'm using Build 598, Firmware Q2C27 and I still have the problem exactly as described in the original ticket.

  Changed 22 months ago by philipmac

  • cc philipmac added

  Changed 21 months ago by jg

  • cc rsmith added
  • milestone changed from Untriaged to First Deployment, V1.0

  Changed 21 months ago by MitchellNCharity

616 q2c28j B4. The following simpler script triggers the same effect.

Open Browse. Select books / literature. Press power button. On the 8-way game pad, press the down button.

I'm seeing it happen about 80% of reps. Of the remaining, some things which feel like clean single-button clicks don't trigger it. >20 reps.

Pressing the 8-way up key behaves similarly. Pressing space does not. Nor keyboard down-arrow.

If the button is held until restore is complete, things behave normally.

Keys which stop the free scrolling: any 8-way button; arrow keys; space. Keys which don't: enter; letters.

I believe all of the above are consistent with a key release event being lost.

  Changed 20 months ago by jg

  • cc dilinger, jg added
  • component changed from kernel to embedded controller

Mitch can reproduce this according to the recipe.

  Changed 20 months ago by jg

  • milestone changed from Update.2 to Update.1

  Changed 20 months ago by jg

  • milestone changed from Update.1 to Update.2

  Changed 20 months ago by legolas558

  • keywords i8042 acpi added

Hi all,

you might be interested to this bug being addressed upstream (on the linux kernel bugzilla):

http://bugzilla.kernel.org/show_bug.cgi?id=9147

and to this LKML thread:

http://lkml.org/lkml/2007/11/22/2

I hope you can contribute to the bug addressing/discussion - since I can see that you are way more expert than me.

Thanks

follow-up: ↓ 23   Changed 19 months ago by cjb

  • milestone changed from Update.2 to Retriage, Please!

I believe this should be an Update.1 bug; it greatly hinders ebook mode.

follow-up: ↓ 22   Changed 19 months ago by jg

  • milestone changed from Retriage, Please! to Update.1

I thought this was fixed in current kernels and firmware????

in reply to: ↑ 21   Changed 18 months ago by cjb

Replying to jg:

I thought this was fixed in current kernels and firmware????

See #5788 for another report of this with latest joyride.

in reply to: ↑ 20 ; follow-up: ↓ 24   Changed 18 months ago by rsmith

Replying to cjb:

I believe this should be an Update.1 bug; it greatly hinders ebook mode.

Appears to have been an EC bug. Please test.

http://dev.laptop.org/~rmsith/q205v.rom

55b6f75bb6d9e12ed0addee9ef8f1e4a q205v.rom

And see if its fixed.

in reply to: ↑ 23   Changed 18 months ago by rsmith

Replying to rsmith:

http://dev.laptop.org/~rmsith/q205v.rom

Crap. Typo

http://dev.laptop.org/~rsmith/q205v.rom

follow-up: ↓ 27   Changed 18 months ago by jg

  • cc dgilmore added

If it appears fixed, please smoke test on a number of machines, and get a Q2D08? into the build as soon as you can....

  Changed 18 months ago by rsmith

  • status changed from reopened to closed
  • resolution set to fixed

in reply to: ↑ 25   Changed 18 months ago by chihyu

  • status changed from closed to reopened
  • resolution deleted

Tested on a MP machine with update.1 (689), q2d08, and a similar problem remains.

reproduction steps

  • Launch a pdf file in Read.
  • Hold the "down" or "up" directional key for about 3 seconds.
  • The power indicator will blink slowly after 5 more seconds.
  • Press the "down" or "up" directional key once, and the pdf document will be scrolled all the way to down/up to the end/beginning, instead of just a few rows.

Sometimes the power indicator would turn back on (non-blinking) without any keypress or mouse movement. In that case, pressing the directional key would scroll the document a few rows down/up.

Replying to jg:

If it appears fixed, please smoke test on a number of machines, and get a Q2D08? into the build as soon as you can....

Changed 18 months ago by chihyu

Changed 18 months ago by chihyu

Changed 18 months ago by chihyu

Changed 18 months ago by chihyu

  Changed 18 months ago by cjb

Thanks, Chih-yu. Please try with newer firmware?

  Changed 17 months ago by cjb

  • status changed from reopened to closed
  • resolution set to fixed

Tested fixed with 10a here.

Note: See TracTickets for help on using tickets.