[Defy Android Development] YetAnotherForumUser:
wakeup delay: Excessive delay in autosuspend_disable() / setting light

While I've seen many reports on the wakeup delay being fixed, I still experience a noticeable lag between pressing the button and the screen coming on. The device itself seems to agree as it produces the following in logcat:

05-26 14:17:14.337 I/WindowManager( 535): Lock screen displayed!
05-26 14:17:14.344 W/SSM ( 134): no ack
05-26 14:17:15.141 D/PowerManagerService-JNI( 535): Excessive delay in autosuspend_disable() while turning screen on: 755ms
05-26 14:17:15.141 D/SurfaceFlinger( 124): Screen acquired, type=0 flinger=0x41d5c450

The actual delay varies between ca. 750 ms and 780 ms. These messages are emitted when the delay exceeds 100 ms, so clearly something is amiss.

At the same time, /proc/kmsg produces the following:

<6>[ 7664.854156] cpcap spi2.0: Power key press, value = 1
<6>[ 7665.025634] request_suspend_state: wakeup (3->0) at 7665009155220 (2014-05-26 12:17:58.200819492 UTC)
<6>[ 7665.025695] panel resume.
<6>[ 7665.086761] cpcap spi2.0: Power key press, value = 0
<6>[ 7665.541351] done EDISCO CTRL ENABLE
<6>[ 7665.767089] Panel is turned on
<6>[ 7665.783630] Mapphone Display is ENABLE
<6>[ 7665.783752] DSSCOMP: dsscomp_late_resume
<6>[ 7665.783782] panel resume.
<4>[ 7665.783813] panel state is not suspended, returns
<6>[ 7665.783874] [smartreflex]: start calibration again
<6>[ 7665.784027] qtouch_force_reset: Forcing HW reset
<6>[ 7665.919952] qtouch_do_cmd_proc_msg:EEPROM checksum matches
<6>[ 7665.920593] qtouch_force_calibration: Forcing calibration
<6>[ 7665.921234] qtouch_do_cmd_proc_msg: Reset done.
<6>[ 7665.921264] qtouch_do_cmd_proc_msg: Self-calibration started.
<6>[ 7665.984100] qtouch_do_cmd_proc_msg: Self-calibration started.

Sometimes the log looks like this instead when I press the power button to show the lock screen and allow it to time out, causing the screen to go dark again:

05-26 14:25:57.626 I/WindowManager( 535): Lock screen displayed!
05-26 14:25:57.641 W/SSM ( 134): no ack
05-26 14:25:58.454 D/PowerManagerService-JNI( 535): Excessive delay in autosuspend_disable() while turning screen on: 761ms
05-26 14:25:58.454 D/SurfaceFlinger( 124): Screen acquired, type=0 flinger=0x41d5c450
05-26 14:26:07.532 I/PowerManagerService( 535): Going to sleep due to screen timeout...
05-26 14:26:08.024 E/KeyguardHostView( 900): Error when trying to bind default AppWidget: java.lang.IllegalArgumentException: not a appwidget provider: ComponentInfo{com.cyanogenmod.lockclock/com.cyanogenmod.lockclock.ClockWidgetProvider}
05-26 14:26:08.047 I/art ( 900): Heap trim of managed (duration=6.805420ms, advised=404KB) and native (duration=17.547607ms, advised=64KB) heaps. Managed heap utilization of 64%.
05-26 14:26:08.079 D/LightsService( 535): Excessive delay setting light: 4455ms <<<<<<<<<<<<<<<<<<<<<<<<<< LOOK HERE
05-26 14:26:08.087 D/SurfaceFlinger( 124): Screen released, type=0 flinger=0x41d5c450
05-26 14:26:08.477 I/Choreographer( 900): Skipped 35 frames! The application may be doing too much work on its main thread.
05-26 14:26:08.501 W/SSM ( 134): no ack

Notice that it complains about a delay of more than 4 seconds ('D/LightsService( 535): Excessive delay setting light: 4455ms'). These complaints are emitted when it takes more that 50 ms to change the light settings. While the delay itself is always present, the log messages vary - sometimes it complains about a delay in autosuspend_disable(), sometimes about one in setting light, sometimes both, sometimes neither.

During screen wakeup the display first quickly displays some noise (like a detuned old analog black and white television, just to give an example which the youngest generation will find hard to understand :).

BTW: Defy+ (mb526)

------------------8<----------------

Just got this gem:

05-26 17:28:34.438 I/WindowManager( 535): Lock screen displayed!
05-26 17:28:34.446 W/SSM ( 134): no ack
05-26 17:28:35.274 D/PowerManagerService-JNI( 535): Excessive delay in autosuspend_disable() while turning screen on: 5065ms
05-26 17:28:35.274 D/SurfaceFlinger( 124): Screen acquired, type=0 flinger=0x41d5c450

Look at the reported times versus the reported delay... It took the usual 0.7 second to switch on the screen, but the thing complains about a 5065ms delay. Where it got that from is a good question, the device had been quiescent for about half an hour before this.