search

radekp / qtmoko

QtExtended, formerly known as Qtopia from TrollTech, discontinued by Nokia
http://qtmoko.org
Other
70 stars 39 forks source link

Suspend button not responsive enough on Freerunner #69

Closed ydirson closed 12 years ago

ydirson commented 12 years ago

Most of the time it takes several seconds to get the FR to suspend, but sometimes it takes even more time, and sometimes it even fails to suspend at all. Looks like when the button press has been taken into account the time in the top bar gets hidden (surprising... but useful here), and in some cases the time does not even get removed on press. I could also observe that when the delay is long, touching the screen can cause instant suspend or return of the time display.

Activated some logs I go the following lines in a case when the time disappears, and finally reappears when I touch the screen:

Jan 5 21:38:51 neo Qtopia: Input : keypressed: type= 1 , code= 116 , value= 1 Jan 5 21:38:51 neo Qtopia: Input : keypressed: type= 1 , code= 116 , value= 0 Jan 5 21:39:01 neo Qtopia: PowerManagement : QtopiaPowerManager: setBacklight => -3 Jan 5 21:39:01 neo Qtopia: Input : PkIM::mouseHandler( int -1 , int 3 )

Now adding logs in systemsuspend to get more info about the called hooks.

ydirson commented 12 years ago

So after a couple of traces added (patch to be submitted), here is a sample of what I get. Looks like while operationCompleted() clears waitingOn, processEvents() does not return immediately. That will have to be the next focus, unless someone already knows what's going on.

Mar 12 00:40:34 Input : keypressed: type= 1 , code= 116 , value= 1 Mar 12 00:40:35 Input : keypressed: type= 1 , code= 116 , value= 0 Mar 12 00:40:35 PowerManagement : ModemSuspend(0x6e7268) checking whether canSuspend... Mar 12 00:40:35 PowerManagement : SystemSuspendHandler(0xb749e0) checking whether canSuspend... Mar 12 00:40:35 PowerManagement : ModemSuspend(0x6e7268) suspending... Mar 12 00:40:35 PowerManagement : ...waiting for completion... Mar 12 00:40:35 Modem : NeoModemService::suspend() Mar 12 00:40:35 Modem : done NeoModemService::suspend() Mar 12 00:40:35 PowerManagement : ...processEvents done Mar 12 00:40:35 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...processEvents done Mar 12 00:40:36 PowerManagement : ...operationCompleted for ModemSuspend(0x6e7268) Mar 12 00:40:50 PowerManagement : ...processEvents done Mar 12 00:40:50 PowerManagement : SystemSuspendHandler(0xb749e0) suspending... Mar 12 00:40:50 PowerManagement : virtual bool NeoSuspend::suspend()

ydirson commented 12 years ago

Pushed bc695d9d as a workaround in branch suspend. Not sure at 100% we want it, but the suspend delay is down to something like ~2s and regular, when running over nfs. I'd still like to understand the root problem.

well, accurding to QEventLoop::processEvents, this patch may well be nearly correct after all. Probably requires to dive into the Qt eventloop itself to find out more anyway.
ydirson commented 12 years ago

Some tracing in QtopiaServerApplication::notify reveals that after SystemSuspendPrivate::operationCompleted gets called, we are really waiting for an event to come in: we only ever get a single event, which is usually a timer event, and then we return. Could it be that the Qt signal that gets operationCompleted() called is not really an event, so we must wait for a real one ?

So what do we see from the code and the following traces ?

Mar 13 23:33:40 UI : notify QSingleShotTimer(0xcc6068) 0xbede678c type: 1 spont: false Mar 13 23:33:40 UI : notify QEventDispatcherQWS(0x3a2730) 0xbede5f8c type: 71 spont: false Mar 13 23:33:40 UI : /notify 0xbede5f8c Mar 13 23:33:40 UI : /notify 0xbede678c Mar 13 23:33:40 PowerManagement : ...processEvents done Mar 13 23:33:40 PowerManagement : ...operationCompleted for ModemSuspend(0xcc6c88) Mar 13 23:33:44 UI : notify NeoBattery(0x3d9698) 0xbede678c type: 1 spont: false Mar 13 23:33:44 UI : notify QEventDispatcherQWS(0x3a2730) 0xbede5f54 type: 68 spont: false Mar 13 23:33:44 UI : /notify 0xbede5f54 Mar 13 23:33:44 UI : /notify 0xbede678c Mar 13 23:33:44 PowerManagement : ...processEvents done Mar 13 23:33:44 PowerManagement : SystemSuspendHandler(0xcf2f38) suspending...

The QTimer::singleShot gets handled by processEvents(), but the latter returns before operationCompleted() is actually executed, which forces another, unwanted, iteration of the loop.

Not really sure how that can happen - things running in different threads ?

ydirson commented 12 years ago

Merged with 91ad1de7