mali-400 mp r3p2 driver failed when captureScreen under android 4.4

We used mali-400 mp r3p2 driver. When captureScreen under android 4.4,  eglClientWaitSyncKHR() always report timeout.

Actually we capture android screen successfully, and the image can be opened, and exactly what android showing.

We enable all debug printing, and find the log report some strange thing about ""Adding a callback to an unmodified frame! \n"" in m200_gp_frame_builder_inlines.h @_mali_frame_add_callback().

How can we fix this bug?

Code and the log information as following:

1) code of SurfaceFlinger.cpp

status_t SurfaceFlinger::captureScreenImplLocked(...)

{

    ...

    EGLSyncKHR sync = eglCreateSyncKHR(mEGLDisplay, EGL_SYNC_FENCE_KHR, NULL);

    ALOGD( "captureScreen: guan, eglCreateSyncKHR(), sync=0x%x\n", (unsigned int)sync);

    if (sync != EGL_NO_SYNC_KHR) {

        EGLint result = eglClientWaitSyncKHR(mEGLDisplay, sync,

                EGL_SYNC_FLUSH_COMMANDS_BIT_KHR, 500000000 /*2 sec*/);

        EGLint eglErr = eglGetError();

        eglDestroySyncKHR(mEGLDisplay, sync);

        ALOGD( "captureScreen: eglClientWaitSyncKHR(), guan, result=0x%x, eglGetError(), eglErr=0x%x\n",

                result, eglErr);

        if (result == EGL_TIMEOUT_EXPIRED_KHR) {

            ALOGW("captureScreen: fence wait timed out");

        } else {

            ALOGW_IF(eglErr != EGL_SUCCESS,

                    "captureScreen: error waiting on EGL fence: %#x", eglErr);

        }

    } else {

        ALOGW("captureScreen: error creating EGL fence: %#x", eglGetError());

        // not fatal

    }

    ...

}

2) debug information of mali driver.

   We add comment with //.  And some information with red color. We also add some print for import var.

D/SurfaceFlinger(  937): captureScreen: w=1280, h=720, layer=[0x0-0xffffffff]

D/gralloc (  937): alloc_device_alloc(),        guan, handle=0x42f19f50, hnd->pid=937, cur_pid=937, ump_id=0x1, base=0x43a27000

[   73.680000] UMP<2>: New session opened

D/gralloc ( 1859): gralloc_register_buffer(),   guan, handle=0x400eaa90, hnd->pid=1859, cur_pid=1859, ump_id=0x1, base=0x41a90000

D/gralloc (  937): alloc_device_free(),         guan, handle=0x42f19f50, hnd->pid=937, cur_pid=937, ump_id=0x1, ref=1, base=0x43a27000

D/gralloc (  937): gralloc_register_buffer(),   guan, handle=0x437da958, hnd->pid=937, cur_pid=937, ump_id=0x1, base=0x43a27000

I/        (  937): For size 3932160 we need order 22 (4194304)

I/        (  937): Checking freelist 0x40145E28 for order 22

I/        (  937): Found an entry on the freelist for order 22

I/        (  937): Lock released

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x41778C00, endian safe routine

I/        (  937): ----- write 20 bytes @ 0x400bec00, endian safe routine

I/        (  937): Writing to Mali memory @ 0x41778BC0, endian safe routine

I/        (  937): ----- write 64 bytes @ 0x400bebc0, endian safe routine

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): F[0]

I/        (  937): _gles_fbo_attachment_resolve_completeness_dirty: frame builder 0x42f19450: setting output 0 to NULL

I/        (  937): _gles_fbo_attachment_resolve_completeness_dirty: frame builder 0x42f19450: setting output 0 of to 0x42f19a70

I/        (  937): _gles_fbo_attachment_resolve_completeness_dirty: frame builder 0x42f19450: setting output 1 to NULL

I/        (  937): _gles_fbo_attachment_resolve_completeness_dirty: frame builder 0x42f19450: setting output 2 to NULL

I/        (  937): For size 262144 we need order 18 (262144)

I/        (  937): Checking freelist 0x40145E08 for order 18

I/        (  937): Checking freelist 0x40145E10 for order 19

I/        (  937): Checking freelist 0x40145E18 for order 20

I/        (  937): Found an entry on the freelist for order 20

I/        (  937): Splitting slot 0x41720038

I/        (  937): Splitting slot 0x41720038

I/        (  937): Lock released

I/        (  937): No guard pages possible

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x43A26880, endian safe routine

I/        (  937): ----- write 20 bytes @ 0x400ff880, endian safe routine

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): +++++ _gles_fb_commit_rsw: allocated 64 bytes @ 0x40130200

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x41778C40, endian safe routine

I/        (  937): ----- write 16 bytes @ 0x400bec40, endian safe routine

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x43A26900, endian safe routine

I/        (  937): ----- write 36 bytes @ 0x400ff900, endian safe routine

I/        (  937): Trying to map memory

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x41778F80, endian safe routine

I/        (  937): ----- write 64 bytes @ 0x400bef80, endian safe routine

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x41778FC0, endian safe routine

I/        (  937): ----- write 64 bytes @ 0x400befc0, endian safe routine

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x41779000, endian safe routine

I/        (  937): ----- write 64 bytes @ 0x400bf000, endian safe routine

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): +++++ _gles_gb_allocate_and_fill_temp_memory: allocated 64 bytes @ 0x40130540

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  93[   74.130000] binder: release 937:1115 transaction 8373 in, still active

[   74.130000] UMP<2>: Session closed

[   74.130000] Mali<2>: Session ending

[   74.130000] Mali<2>: Core: session_close: for Mali-400 GP

[   74.130000] Mali<2>: Core: session_close: for Mali-400 PP

[   74.130000] Mali<2>: MMU session end

[   74.130000] Mali<1>: Cleanup of descriptor 1 mapping to 0xeaf84f20 in descriptor table

[   74.130000] Mali<1>: Cleanup of descriptor 2 mapping to 0xe0e5a860 in descriptor table

[   74.130000] Mali<1>: Cleanup of descriptor 3 mapping to 0xeafb9d20 in descriptor table

[   74.130000] Mali<1>: Cleanup of descriptor 7 mapping to 0xe1b04d20 in descriptor table

[   74.130000] Mali<1>: Cleanup of descriptor 8 mapping to 0xe1b04ea0 in descriptor table

[   74.130000] Mali<1>: Cleanup of descriptor 9 mapping to 0xe1b04b20 in descriptor table

[   74.132000] binder: send failed reply for transaction 8373 to 1859:1859

7): _mali_frame_add_callback(), frame->state=2

[   74.133000] OSDFB(info): OSDFB: [FB0] opened. in_use = 6

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback[   74.155000] Mali<1>: (), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x41778C80, endian safe routine

I/        (  937): ----- write 64 bytes @ 0x400bec80, endian safe routine

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x41778CC0, endian safe routine

I/        (  937): ----- write 64 bytes @ 0x400becc0, endian safe routine

I/        (  937): Trying to map memory

I/        (  937): Writing to Mali memory @ 0x41778D00, endian safe routine

I/        (  937): ----- write 64 bytes @ 0x400bed00, endian safe routine

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): +++++ _gles_gb_allocate_and_fill_temp_memory: allocated 64 bytes @ 0x40130880

I/        (  937): F[0]

I/        (  937): Trying to map memory

I/        (  937): For size 262144 we need order 18 (262144)

I/        (  937): Checking freelist 0x40145E08 for order 18

I/        (  937): Found an entry on the freelist for order 18

I/        (  937): Lock released

I/        (  937): No guard pages possible

I/        (  937): Trying to map memory

I/        (  937): Trying to map memory

I/        (  937): _mali_frame_builder_add_callback(), frame->state=2

I/        (  937): _mali_frame_add_callback(), frame->state=2

I/        (  937): Trying to map memory

I/        (  937): GPS[1]

I/        (  937): Mali gp job returned, OK!

I/        (  937): GPE[1]

I/        (  937): PPS[1]

I/        (  937): Calling _mali_uku_wait_for_notification()

I/        (  937): Mali pp job returned, OK!

I/        (  937): Starting PP post processing

I/        (  937): Internal frame 1121837128, job render_time: 31031 usec

I/        (  937): PPE[1]

I/        (  937): Freeing job

//  mali driver change frame state from 2(FRAME_DIRTY) to 1(FRAME_UNMODIFIED),

// but _mali_frame_add_callback(),  check as following:

//MALI_DEBUG_ASSERT( frame->state != FRAME_UNMODIFIED , ("Adding a callback to an unmodified frame! \n"));

I/        (  937): Calling _mali_uku_wait_for_notification()

I/        (  937): _mali_frame_builder_add_callback(), frame->state=1

I/        (  937): _mali_frame_add_callback(), frame->state=1

I/        (  937): *********************************************************************

I/        (  937): ASSERT EXIT:

I/        (  937): In file: hardware/zte/zx296702/mali/src/shared/m200_gp_frame_builder_inlines.h  function: _mali_frame_add_callback()   line:  39

I/        (  937): Adding a callback to an unmodified frame!

I/        (  937):

F/libc    (  937): Fatal signal 11 (SIGSEGV) at 0x00000000 (code=1), thread 937 (surfaceflinger)

I/DEBUG   (  936): *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

I/DEBUG   (  936): Build fingerprint: 'unknown'

I/DEBUG   (  936): Revision: '32'

I/DEBUG   (  936): pid: 937, tid: 937, name: surfaceflinger  >>> /system/bin/surfaceflinger <<<

I/DEBUG   (  936): signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 00000000

W/NativeCrashListener( 1289): Couldn't find ProcessRecord for pid 937

I/DEBUG   (  936):     r0 be864830  r1 00000000  r2 00000000  r3 00000000

I/DEBUG   (  936): AM write failure (32 / Broken pipe)

I/DEBUG   (  936):     r4 43103250  r5 40005df8  r6 00000001  r7 400e7690

I/DEBUG   (  936):     r8 00000000  r9 10000001  sl be86487c  fp be864830

I/DEBUG   (  936):     ip 40480e04  sp be8647b0  lr 404773f8  pc 412439d0  cpsr 600f0010

I/DEBUG   (  936):     d0  6e696c2020202928  d1  5f6464615f656d61

I/DEBUG   (  936):     d2  0000000000000000  d3  0000000000000000

I/DEBUG   (  936):     d4  00000000bf800000  d5  3f8000003f800000

I/DEBUG   (  936):     d6  43b4000043b40000  d7  0000050043b40000

I/DEBUG   (  936):     d8  0000000000000000  d9  0000000000000000

I/DEBUG   (  936):     d10 0000000000000000  d11 0000000000000000

I/DEBUG   (  936):     d12 0000000000000000  d13 0000000000000000

I/DEBUG   (  936):     d14 0000000000000000  d15 0000000000000000

I/DEBUG   (  936):     d16 280001cb400bf140  d17 0400bf140400bf14

I/DEBUG   (  936):     d18 280001cb00000000  d19 000002cf000002cf

I/DEBUG   (  936):     d20 00000000000002cf  d21 0000000001678000

I/DEBUG   (  936):     d22 0000000000000000  d23 0000000000000000

I/DEBUG   (  936):     d24 7000000000000000  d25 7000000001678000

I/DEBUG   (  936):     d26 0000000000000000  d27 7000000001678000

I/DEBUG   (  936):     d28 009fe00000000000  d29 709fe00001678000

I/DEBUG   (  936):     d30 0000000000000000  d31 4000000000000000

I/DEBUG   (  936):     scr 60000010

I/DEBUG   (  936):

I/DEBUG   (  936): backtrace:

I/DEBUG   (  936):     #00  pc 0002a9d0  /system/lib/libMali.so (_mali_osu_abort+8)

I/DEBUG   (  936):     #01  pc 000163f4  /system/lib/egl/libEGL_mali.so (_egl_create_sync_KHR+740)

I/DEBUG   (  936):     #02  pc 0000de9c  /system/lib/egl/libEGL_mali.so (eglCreateSyncKHR+60)

I/DEBUG   (  936):     #03  pc 0000e2c1  /system/lib/libEGL.so (eglCreateSyncKHR+52)

I/DEBUG   (  936):     #04  pc 00019135  /system/lib/libsurfaceflinger.so

I/DEBUG   (  936):     #05  pc 0001debb  /system/lib/libsurfaceflinger.so

I/DEBUG   (  936):     #06  pc 00017009  /system/lib/libsurfaceflinger.so

I/DEBUG   (  936):     #07  pc 00010b35  /system/lib/libutils.so (android::Looper::pollInner(int)+412)

I/DEBUG   (  936):     #08  pc 00010c29  /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92)

I/DEBUG   (  936):     #09  pc 000171e5  /system/lib/libsurfaceflinger.so

I/DEBUG   (  936):     #10  pc 00018241  /system/lib/libsurfaceflinger.so (android::SurfaceFlinger::run()+8)

I/DEBUG   (  936):     #11  pc 0000096b  /system/bin/surfaceflinger

I/DEBUG   (  936):     #12  pc 0000e647  /system/lib/libc.so (__libc_init+50)

I/DEBUG   (  936):     #13  pc 00000a20  /system/bin/surfaceflinger

I/DEBUG   (  936):

I/DEBUG   (  936): stack:

I/DEBUG   (  936):          be864770  41306090  /system/lib/libMali.so

I/DEBUG   (  936):          be864774  43103250 

I/DEBUG   (  936):          be864778  40005df8 

I/DEBUG   (  936):          be86477c  00000001 

I/DEBUG   (  936):          be864780  400e7690 

I/DEBUG   (  936):          be864784  00000000 

I/DEBUG   (  936):          be864788  10000001 

I/DEBUG   (  936):          be86478c  be86487c  [stack]

I/DEBUG   (  936):          be864790  be864830  [stack]

I/DEBUG   (  936):          be864794  4122d3d0  /system/lib/libMali.so (_mali_sys_printf+28)

I/DEBUG   (  936):          be864798  41739980 

I/DEBUG   (  936):          be86479c  be8647ac  [stack]

I/DEBUG   (  936):          be8647a0  43103250 

I/DEBUG   (  936):          be8647a4  404773f4  /system/lib/egl/libEGL_mali.so (_egl_create_sync_KHR+740)

I/DEBUG   (  936):          be8647a8  4047b7e8  /system/lib/egl/libEGL_mali.so

I/DEBUG   (  936):          be8647ac  00000000 

I/DEBUG   (  936):     #00  be8647b0  41306090  /system/lib/libMali.so

I/DEBUG   (  936):          be8647b4  404773f8  /system/lib/egl/libEGL_mali.so (_egl_create_sync_KHR+744)

I/DEBUG   (  936):     #01  be8647b8  40005df8 

I/DEBUG   (  936):          be8647bc  40005df8 

I/DEBUG   (  936):          be8647c0  00000000 

I/DEBUG   (  936):          be8647c4  000030f9 

I/DEBUG   (  936):          be8647c8  00000001 

I/DEBUG   (  936):          be8647cc  4046eea0  /system/lib/egl/libEGL_mali.so (eglCreateSyncKHR+64)

I/DEBUG   (  936):     #02  be8647d0  ffffffbc 

I/DEBUG   (  936):          be8647d4  4026ee0c  /system/lib/libEGL.so

I/DEBUG   (  936):          be8647d8  be8647ec  [stack]

I/DEBUG   (  936):          be8647dc  4046ee60  /system/lib/egl/libEGL_mali.so (eglCreateSyncKHR)

I/DEBUG   (  936):          be8647e0  000030f9 

I/DEBUG   (  936):          be8647e4  4022c2c3  /system/lib/libEGL.so (eglCreateSyncKHR+54)