Black screen when first opening ScummVM

Subforum for discussion and help with ScummVM's Android port

Moderator: ScummVM Team

Post Reply
anakondarh
Posts: 4
Joined: Wed Jul 10, 2013 7:33 pm

Black screen when first opening ScummVM

Post by anakondarh »

Hey guys,

I've been using ScummVM on Android for quite a while and on different devices, with no problems whatsoever. It's truly a wonderful app!!

However, I am experiencing a small problem on the newest addition to my ever-growing Android family :) a Galaxy Note 8.0 tablet.

The Market version: ScummVM starts and shows the loading bar, after which it goes to a black screen for about 30-40 seconds. Afterwards, the UI shows and everything works as expected, loading games quickly and without a problem.

Only installed plugin is the "scumm" one, also Market version.

Here's a logcat of the app opening, hoping someone can give me a hand with this pesky bug...

Code: Select all

07-10 21:17:30.395: I/dalvikvm(6827): Turning on JNI app bug workarounds for target SDK version 10...
07-10 21:17:30.685: D/ProgressBar(6827): setProgressDrawable mProgressDrawable = null, d = android.graphics.drawable.LayerDrawable@424e7430needUpdate = false
07-10 21:17:30.685: D/ProgressBar(6827): setProgress = 0
07-10 21:17:30.685: D/ProgressBar(6827): setProgress = 0, fromUser = false
07-10 21:17:30.685: D/ProgressBar(6827): mProgress = 0mIndeterminate = false, mMin = 0, mMax = 100
07-10 21:17:30.840: D/ProgressBar(6827): setProgress = 0
07-10 21:17:30.840: D/ProgressBar(6827): setProgress = 0, fromUser = false
07-10 21:17:30.840: D/ProgressBar(6827): mProgress = 0mIndeterminate = false, mMin = 0, mMax = 4164052
07-10 21:17:30.880: D/ProgressBar(6827): setProgress = 1803628
07-10 21:17:30.880: D/ProgressBar(6827): setProgress = 1803628, fromUser = false
07-10 21:17:30.880: D/ProgressBar(6827): mProgress = 0mIndeterminate = false, mMin = 0, mMax = 4164052
07-10 21:17:30.880: D/ProgressBar(6827): setProgress = 4164052
07-10 21:17:30.880: D/ProgressBar(6827): setProgress = 4164052, fromUser = false
07-10 21:17:30.880: D/ProgressBar(6827): mProgress = 1803628mIndeterminate = false, mMin = 0, mMax = 4164052
07-10 21:17:30.880: I/ScummVM(6827): Starting next activity with intent Intent { flg=0x1000000 cmp=org.scummvm.scummvm/.ScummVMActivity (has extras) }
07-10 21:17:30.960: D/dalvikvm(6827): Trying to load lib /data/data/org.scummvm.scummvm/cache/libscummvm.so 0x42474490
07-10 21:17:30.975: D/dalvikvm(6827): Added shared lib /data/data/org.scummvm.scummvm/cache/libscummvm.so 0x42474490
07-10 21:17:30.980: D/ScummVM(6827): onStart
07-10 21:17:30.980: D/ScummVM(6827): onResume
07-10 21:17:30.985: I/ScummVM(6827): Using 16384 bytes buffer for 44100Hz audio
07-10 21:17:30.990: D/libEGL(6827): loaded /system/lib/egl/libEGL_mali.so
07-10 21:17:30.995: D/libEGL(6827): loaded /system/lib/egl/libGLESv1_CM_mali.so
07-10 21:17:30.995: D/libEGL(6827): loaded /system/lib/egl/libGLESv2_mali.so
07-10 21:17:31.000: D/(6827): Device driver API match
07-10 21:17:31.000: D/(6827): Device driver API version: 10
07-10 21:17:31.000: D/(6827): User space API version: 10 
07-10 21:17:31.000: D/(6827): mali: REVISION=Linux-r2p4-02rel0 BUILD_DATE=Tue Oct 16 15:37:13 KST 2012 
07-10 21:17:31.000: D/ScummVM(6827): EGL configs:
07-10 21:17:31.005: D/ScummVM(6827): [29] RGB565 W P X (10060)
07-10 21:17:31.005: D/ScummVM(6827): [30] RGBA8888 W P X (10034)
07-10 21:17:31.010: D/ScummVM(6827): [31] RGB888 W P X (10052)
07-10 21:17:31.015: D/ScummVM(6827): surfaceCreated
07-10 21:17:31.015: D/ScummVM(6827): surfaceChanged: 1280x800 (4)
07-10 21:17:31.015: D/ScummVM(6827): [32] RGB888 D24 S8 W P X (10000)
07-10 21:17:31.020: D/ScummVM(6827): [33] RGBA8888 D24 S8 W P X (9982)
07-10 21:17:31.020: D/ScummVM(6827): [5] RGB565 D24 S8 W P X (10008)
07-10 21:17:31.020: D/ScummVM(6827): [3] RGB565 D24 S8 MSAAx4 W P X (9608)
07-10 21:17:31.025: D/ScummVM(6827): [4] RGB565 D24 S8 MSAAx16 W P X NON_CONFORMANT unknown CAVEAT 0x3051 (7408)
07-10 21:17:31.030: D/ScummVM(6827): [19] RGBA5551 D24 S8 W P (9988)
07-10 21:17:31.030: D/ScummVM(6827): [18] RGBA5551 D24 S8 MSAAx4 W P (9588)
07-10 21:17:31.035: D/ScummVM(6827): [20] RGBA5551 D24 S8 MSAAx16 W P NON_CONFORMANT unknown CAVEAT 0x3051 (7388)
07-10 21:17:31.035: D/ScummVM(6827): [21] RGBA4444 D24 S8 W P (9968)
07-10 21:17:31.040: D/ScummVM(6827): [22] RGBA4444 D24 S8 MSAAx4 W P (9568)
07-10 21:17:31.040: D/ScummVM(6827): [23] RGBA4444 D24 S8 MSAAx16 W P NON_CONFORMANT unknown CAVEAT 0x3051 (7368)
07-10 21:17:31.045: D/ScummVM(6827): [9] RGBA8888 D24 S8 W P X (9982)
07-10 21:17:31.050: D/ScummVM(6827): [38] RGB888 D24 S8 W P X NON_CONFORMANT unknown CAVEAT 0x3051 (9000)
07-10 21:17:31.050: D/ScummVM(6827): [12] RGBA8888 D24 S8 MSAAx4 W P X (9582)
07-10 21:17:31.050: D/ScummVM(6827): [15] RGBA8888 D24 S8 MSAAx16 W P X NON_CONFORMANT unknown CAVEAT 0x3051 (7382)
07-10 21:17:31.050: D/ScummVM(6827): [29] RGB565 W P X (10060)
07-10 21:17:31.055: D/ScummVM(6827): [30] RGBA8888 W P X (10034)
07-10 21:17:31.055: D/ScummVM(6827): [31] RGB888 W P X (10052)
07-10 21:17:31.055: D/ScummVM(6827): [32] RGB888 D24 W P X (10018)
07-10 21:17:31.055: D/ScummVM(6827): Chosen EGL config: [29] RGB565 W P X
07-10 21:17:31.055: I/ScummVM(6827): ScummVM 1.5.0 (Jul 31 2012 13:28:39)
07-10 21:17:31.065: I/ScummVM(6827): Running on: [samsung] [GT-N5110] [samsung] [samsung/konawifixx/konawifi:4.1.2/JZO54K/N5110UEEMF2:user/release-keys] [JZO54K.N5110UEEMF2] SDK:16 ABI:armeabi-v7a
07-10 21:17:31.065: I/ScummVM(6827): Entering scummvm_main with 5 args
07-10 21:17:31.080: D/ScummVM(6827): Using configuration file: /data/data/org.scummvm.scummvm/files/scummvmrc
07-10 21:17:31.090: E/SpannableStringBuilder(6827): SPAN_EXCLUSIVE_EXCLUSIVE spans cannot have a zero length
07-10 21:17:31.090: E/SpannableStringBuilder(6827): SPAN_EXCLUSIVE_EXCLUSIVE spans cannot have a zero length
07-10 21:17:31.105: W/ScummVM(6827): WARNING: Failed loading symbol 'PLUGIN_getVersion' from plugin '/data/data/org.scummvm.scummvm/cache/libscummvm.so' (Symbol not found: )!
07-10 21:17:31.105: D/ScummVM(6827): initializing surface
07-10 21:17:31.130: I/ScummVM(6827): Using EGL 1.4 Android META-EGL (Android); GL OpenGL ES-CM 1.1/Mali-400 MP (ARM)
07-10 21:17:31.130: I/ScummVM(6827): Extensions: GL_EXT_debug_marker GL_OES_byte_coordinates GL_OES_fixed_point GL_OES_single_precision GL_OES_matrix_get GL_OES_read_format GL_OES_compressed_paletted_texture GL_OES_point_size_array GL_OES_point_sprite GL_OES_texture_npot GL_OES_query_matrix GL_OES_matrix_palette GL_OES_extended_matrix_palette GL_OES_compressed_ETC1_RGB8_texture GL_OES_EGL_image GL_OES_draw_texture GL_OES_depth_texture GL_OES_packed_depth_stencil GL_EXT_texture_format_BGRA8888 GL_OES_framebuffer_object GL_OES_stencil8 GL_OES_depth24 GL_ARM_rgba8 GL_OES_EGL_image_external GL_OES_EGL_sync GL_OES_rgb8_rgba8 GL_EXT_multisampled_render_to_texture GL_OES_texture_cube_map GL_EXT_discard_framebuffer 
07-10 21:17:31.130: D/ScummVM(6827): initializing viewport
07-10 21:17:31.130: I/ScummVM(6827): overlay size is 640x400

Today's (Jul/10/2013) daily build: The black screen is only on for about 10 seconds. daily "scumm" plugin installed. Here's the logcat for the daily version:

Code: Select all

07-10 21:48:08.875: I/dalvikvm(9888): Turning on JNI app bug workarounds for target SDK version 8...
07-10 21:48:08.910: D/dalvikvm(9888): Debugger has detached; object registry had 1 entries
07-10 21:48:09.150: D/ProgressBar(9888): setProgressDrawable mProgressDrawable = null, d = android.graphics.drawable.LayerDrawable@424e7330needUpdate = false
07-10 21:48:09.155: D/ProgressBar(9888): setProgress = 0
07-10 21:48:09.155: D/ProgressBar(9888): setProgress = 0, fromUser = false
07-10 21:48:09.155: D/ProgressBar(9888): mProgress = 0mIndeterminate = false, mMin = 0, mMax = 100
07-10 21:48:09.295: D/ProgressBar(9888): setProgress = 0
07-10 21:48:09.295: D/ProgressBar(9888): setProgress = 0, fromUser = false
07-10 21:48:09.295: D/ProgressBar(9888): mProgress = 0mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.295: I/ScummVM(9888): Extracting mylib/armeabi/libscumm.so from /data/app/org.scummvm.scummvm.plugin.scumm-1.apk to /data/data/org.scummvm.scummvm/cache/libscumm.so
07-10 21:48:09.355: D/ProgressBar(9888): setProgress = 4096
07-10 21:48:09.355: D/ProgressBar(9888): setProgress = 4096, fromUser = false
07-10 21:48:09.355: D/ProgressBar(9888): mProgress = 0mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.355: D/ProgressBar(9888): setProgress = 94208
07-10 21:48:09.355: D/ProgressBar(9888): setProgress = 94208, fromUser = false
07-10 21:48:09.355: D/ProgressBar(9888): mProgress = 4096mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.355: D/ProgressBar(9888): setProgress = 183049
07-10 21:48:09.355: D/ProgressBar(9888): setProgress = 183049, fromUser = false
07-10 21:48:09.355: D/ProgressBar(9888): mProgress = 94208mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.355: D/ProgressBar(9888): setProgress = 273161
07-10 21:48:09.355: D/ProgressBar(9888): setProgress = 273161, fromUser = false
07-10 21:48:09.355: D/ProgressBar(9888): mProgress = 183049mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.360: D/ProgressBar(9888): setProgress = 363273
07-10 21:48:09.360: D/ProgressBar(9888): setProgress = 363273, fromUser = false
07-10 21:48:09.360: D/ProgressBar(9888): mProgress = 273161mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.360: D/ProgressBar(9888): setProgress = 457278
07-10 21:48:09.360: D/ProgressBar(9888): setProgress = 457278, fromUser = false
07-10 21:48:09.360: D/ProgressBar(9888): mProgress = 363273mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.360: D/ProgressBar(9888): setProgress = 547390
07-10 21:48:09.360: D/ProgressBar(9888): setProgress = 547390, fromUser = false
07-10 21:48:09.360: D/ProgressBar(9888): mProgress = 457278mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 636556
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 636556, fromUser = false
07-10 21:48:09.395: D/ProgressBar(9888): mProgress = 547390mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 726283
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 726283, fromUser = false
07-10 21:48:09.395: D/ProgressBar(9888): mProgress = 636556mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 817146
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 817146, fromUser = false
07-10 21:48:09.395: D/ProgressBar(9888): mProgress = 726283mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 911354
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 911354, fromUser = false
07-10 21:48:09.395: D/ProgressBar(9888): mProgress = 817146mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 1001417
07-10 21:48:09.395: D/ProgressBar(9888): setProgress = 1001417, fromUser = false
07-10 21:48:09.395: D/ProgressBar(9888): mProgress = 911354mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.410: D/ProgressBar(9888): setProgress = 1091529
07-10 21:48:09.410: D/ProgressBar(9888): setProgress = 1091529, fromUser = false
07-10 21:48:09.410: D/ProgressBar(9888): mProgress = 1001417mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.410: D/ProgressBar(9888): setProgress = 1184028
07-10 21:48:09.410: D/ProgressBar(9888): setProgress = 1184028, fromUser = false
07-10 21:48:09.410: D/ProgressBar(9888): mProgress = 1091529mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.410: D/ProgressBar(9888): setProgress = 1273313
07-10 21:48:09.410: D/ProgressBar(9888): setProgress = 1273313, fromUser = false
07-10 21:48:09.410: D/ProgressBar(9888): mProgress = 1184028mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.410: D/ProgressBar(9888): setProgress = 1363425
07-10 21:48:09.410: D/ProgressBar(9888): setProgress = 1363425, fromUser = false
07-10 21:48:09.415: D/ProgressBar(9888): mProgress = 1273313mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.415: D/ProgressBar(9888): setProgress = 1453125
07-10 21:48:09.415: D/ProgressBar(9888): setProgress = 1453125, fromUser = false
07-10 21:48:09.415: D/ProgressBar(9888): mProgress = 1363425mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.425: D/ProgressBar(9888): setProgress = 1543237
07-10 21:48:09.425: D/ProgressBar(9888): setProgress = 1543237, fromUser = false
07-10 21:48:09.425: D/ProgressBar(9888): mProgress = 1453125mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.430: D/ProgressBar(9888): setProgress = 1634149
07-10 21:48:09.430: D/ProgressBar(9888): setProgress = 1634149, fromUser = false
07-10 21:48:09.430: D/ProgressBar(9888): mProgress = 1543237mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.430: D/ProgressBar(9888): setProgress = 1725961
07-10 21:48:09.430: D/ProgressBar(9888): setProgress = 1725961, fromUser = false
07-10 21:48:09.430: D/ProgressBar(9888): mProgress = 1634149mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.430: D/ProgressBar(9888): setProgress = 1816073
07-10 21:48:09.430: D/ProgressBar(9888): setProgress = 1816073, fromUser = false
07-10 21:48:09.430: D/ProgressBar(9888): mProgress = 1725961mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.430: I/ScummVM(9888): Extracting mylib/armeabi/libscummvm.so from /data/app/org.scummvm.scummvm-1.apk to /data/data/org.scummvm.scummvm/cache/libscummvm.so
07-10 21:48:09.445: D/ProgressBar(9888): setProgress = 1906185
07-10 21:48:09.445: D/ProgressBar(9888): setProgress = 1906185, fromUser = false
07-10 21:48:09.445: D/ProgressBar(9888): mProgress = 1816073mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.445: D/ProgressBar(9888): setProgress = 1930356
07-10 21:48:09.445: D/ProgressBar(9888): setProgress = 1930356, fromUser = false
07-10 21:48:09.445: D/ProgressBar(9888): mProgress = 1906185mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.445: D/ProgressBar(9888): setProgress = 1934452
07-10 21:48:09.445: D/ProgressBar(9888): setProgress = 1934452, fromUser = false
07-10 21:48:09.445: D/ProgressBar(9888): mProgress = 1930356mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.445: D/ProgressBar(9888): setProgress = 2024564
07-10 21:48:09.445: D/ProgressBar(9888): setProgress = 2024564, fromUser = false
07-10 21:48:09.445: D/ProgressBar(9888): mProgress = 1934452mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2114800
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2114800, fromUser = false
07-10 21:48:09.460: D/ProgressBar(9888): mProgress = 2024564mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2204912
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2204912, fromUser = false
07-10 21:48:09.460: D/ProgressBar(9888): mProgress = 2114800mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2295024
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2295024, fromUser = false
07-10 21:48:09.460: D/ProgressBar(9888): mProgress = 2204912mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2385136
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2385136, fromUser = false
07-10 21:48:09.460: D/ProgressBar(9888): mProgress = 2295024mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2478749
07-10 21:48:09.460: D/ProgressBar(9888): setProgress = 2478749, fromUser = false
07-10 21:48:09.460: D/ProgressBar(9888): mProgress = 2385136mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.475: D/ProgressBar(9888): setProgress = 2566466
07-10 21:48:09.475: D/ProgressBar(9888): setProgress = 2566466, fromUser = false
07-10 21:48:09.475: D/ProgressBar(9888): mProgress = 2478749mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.475: D/ProgressBar(9888): setProgress = 2656578
07-10 21:48:09.475: D/ProgressBar(9888): setProgress = 2656578, fromUser = false
07-10 21:48:09.475: D/ProgressBar(9888): mProgress = 2566466mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.475: D/ProgressBar(9888): setProgress = 2749371
07-10 21:48:09.475: D/ProgressBar(9888): setProgress = 2749371, fromUser = false
07-10 21:48:09.475: D/ProgressBar(9888): mProgress = 2656578mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.480: D/ProgressBar(9888): setProgress = 2839483
07-10 21:48:09.480: D/ProgressBar(9888): setProgress = 2839483, fromUser = false
07-10 21:48:09.480: D/ProgressBar(9888): mProgress = 2749371mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.480: D/ProgressBar(9888): setProgress = 2932360
07-10 21:48:09.480: D/ProgressBar(9888): setProgress = 2932360, fromUser = false
07-10 21:48:09.480: D/ProgressBar(9888): mProgress = 2839483mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.480: D/ProgressBar(9888): setProgress = 3021364
07-10 21:48:09.480: D/ProgressBar(9888): setProgress = 3021364, fromUser = false
07-10 21:48:09.480: D/ProgressBar(9888): mProgress = 2932360mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.495: D/ProgressBar(9888): setProgress = 3111476
07-10 21:48:09.495: D/ProgressBar(9888): setProgress = 3111476, fromUser = false
07-10 21:48:09.495: D/ProgressBar(9888): mProgress = 3021364mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.495: D/ProgressBar(9888): setProgress = 3203883
07-10 21:48:09.495: D/ProgressBar(9888): setProgress = 3203883, fromUser = false
07-10 21:48:09.495: D/ProgressBar(9888): mProgress = 3111476mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.495: D/ProgressBar(9888): setProgress = 3293424
07-10 21:48:09.495: D/ProgressBar(9888): setProgress = 3293424, fromUser = false
07-10 21:48:09.495: D/ProgressBar(9888): mProgress = 3203883mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.495: D/ProgressBar(9888): setProgress = 3383536
07-10 21:48:09.495: D/ProgressBar(9888): setProgress = 3383536, fromUser = false
07-10 21:48:09.495: D/ProgressBar(9888): mProgress = 3293424mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.510: D/ProgressBar(9888): setProgress = 3475597
07-10 21:48:09.510: D/ProgressBar(9888): setProgress = 3475597, fromUser = false
07-10 21:48:09.510: D/ProgressBar(9888): mProgress = 3383536mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.510: D/ProgressBar(9888): setProgress = 3568176
07-10 21:48:09.510: D/ProgressBar(9888): setProgress = 3568176, fromUser = false
07-10 21:48:09.510: D/ProgressBar(9888): mProgress = 3475597mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.510: D/ProgressBar(9888): setProgress = 3658288
07-10 21:48:09.510: D/ProgressBar(9888): setProgress = 3658288, fromUser = false
07-10 21:48:09.510: D/ProgressBar(9888): mProgress = 3568176mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.510: D/ProgressBar(9888): setProgress = 3746321
07-10 21:48:09.510: D/ProgressBar(9888): setProgress = 3746321, fromUser = false
07-10 21:48:09.510: D/ProgressBar(9888): mProgress = 3658288mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 3840383
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 3840383, fromUser = false
07-10 21:48:09.525: D/ProgressBar(9888): mProgress = 3746321mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 3930495
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 3930495, fromUser = false
07-10 21:48:09.525: D/ProgressBar(9888): mProgress = 3840383mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4020607
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4020607, fromUser = false
07-10 21:48:09.525: D/ProgressBar(9888): mProgress = 3930495mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4111668
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4111668, fromUser = false
07-10 21:48:09.525: D/ProgressBar(9888): mProgress = 4020607mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4201780
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4201780, fromUser = false
07-10 21:48:09.525: D/ProgressBar(9888): mProgress = 4111668mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4290955
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4290955, fromUser = false
07-10 21:48:09.525: D/ProgressBar(9888): mProgress = 4201780mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4385163
07-10 21:48:09.525: D/ProgressBar(9888): setProgress = 4385163, fromUser = false
07-10 21:48:09.525: D/ProgressBar(9888): mProgress = 4290955mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.540: D/ProgressBar(9888): setProgress = 4474958
07-10 21:48:09.540: D/ProgressBar(9888): setProgress = 4474958, fromUser = false
07-10 21:48:09.540: D/ProgressBar(9888): mProgress = 4385163mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.540: D/ProgressBar(9888): setProgress = 4538524
07-10 21:48:09.540: D/ProgressBar(9888): setProgress = 4538524, fromUser = false
07-10 21:48:09.540: D/ProgressBar(9888): mProgress = 4474958mIndeterminate = false, mMin = 0, mMax = 4538524
07-10 21:48:09.540: I/ScummVM(9888): Starting next activity with intent Intent { flg=0x1000000 cmp=org.scummvm.scummvm/.ScummVMActivity (has extras) }
07-10 21:48:09.620: D/dalvikvm(9888): Trying to load lib /data/data/org.scummvm.scummvm/cache/libscummvm.so 0x42474058
07-10 21:48:09.625: D/dalvikvm(9888): Added shared lib /data/data/org.scummvm.scummvm/cache/libscummvm.so 0x42474058
07-10 21:48:09.625: D/ScummVM(9888): Hover available: true
07-10 21:48:09.625: D/ScummVM(9888): onStart
07-10 21:48:09.630: D/ScummVM(9888): onResume
07-10 21:48:09.630: I/ScummVM(9888): Using 16384 bytes buffer for 44100Hz audio
07-10 21:48:09.635: D/libEGL(9888): loaded /system/lib/egl/libEGL_mali.so
07-10 21:48:09.645: D/libEGL(9888): loaded /system/lib/egl/libGLESv1_CM_mali.so
07-10 21:48:09.645: D/libEGL(9888): loaded /system/lib/egl/libGLESv2_mali.so
07-10 21:48:09.655: D/(9888): Device driver API match
07-10 21:48:09.655: D/(9888): Device driver API version: 10
07-10 21:48:09.655: D/(9888): User space API version: 10 
07-10 21:48:09.655: D/(9888): mali: REVISION=Linux-r2p4-02rel0 BUILD_DATE=Tue Oct 16 15:37:13 KST 2012 
07-10 21:48:09.660: D/ScummVM(9888): EGL configs:
07-10 21:48:09.660: D/ScummVM(9888): surfaceCreated
07-10 21:48:09.660: D/ScummVM(9888): surfaceChanged: 1280x800 (4)
07-10 21:48:09.660: D/ScummVM(9888): [29] RGB565 W P X (10060)
07-10 21:48:09.665: D/ScummVM(9888): [30] RGBA8888 W P X (10034)
07-10 21:48:09.665: D/ScummVM(9888): [31] RGB888 W P X (10052)
07-10 21:48:09.665: D/ScummVM(9888): [32] RGB888 D24 S8 W P X (10000)
07-10 21:48:09.665: D/ScummVM(9888): [33] RGBA8888 D24 S8 W P X (9982)
07-10 21:48:09.670: D/ScummVM(9888): [5] RGB565 D24 S8 W P X (10008)
07-10 21:48:09.670: D/ScummVM(9888): [3] RGB565 D24 S8 MSAAx4 W P X (9608)
07-10 21:48:09.675: D/ScummVM(9888): [4] RGB565 D24 S8 MSAAx16 W P X NON_CONFORMANT unknown CAVEAT 0x3051 (7408)
07-10 21:48:09.680: D/ScummVM(9888): [19] RGBA5551 D24 S8 W P (9988)
07-10 21:48:09.680: D/ScummVM(9888): [18] RGBA5551 D24 S8 MSAAx4 W P (9588)
07-10 21:48:09.690: D/ScummVM(9888): [20] RGBA5551 D24 S8 MSAAx16 W P NON_CONFORMANT unknown CAVEAT 0x3051 (7388)
07-10 21:48:09.690: D/ScummVM(9888): [21] RGBA4444 D24 S8 W P (9968)
07-10 21:48:09.695: D/ScummVM(9888): [22] RGBA4444 D24 S8 MSAAx4 W P (9568)
07-10 21:48:09.695: D/ScummVM(9888): [23] RGBA4444 D24 S8 MSAAx16 W P NON_CONFORMANT unknown CAVEAT 0x3051 (7368)
07-10 21:48:09.700: D/ScummVM(9888): [9] RGBA8888 D24 S8 W P X (9982)
07-10 21:48:09.705: D/ScummVM(9888): [38] RGB888 D24 S8 W P X NON_CONFORMANT unknown CAVEAT 0x3051 (9000)
07-10 21:48:09.705: D/ScummVM(9888): [12] RGBA8888 D24 S8 MSAAx4 W P X (9582)
07-10 21:48:09.705: D/ScummVM(9888): [15] RGBA8888 D24 S8 MSAAx16 W P X NON_CONFORMANT unknown CAVEAT 0x3051 (7382)
07-10 21:48:09.710: D/ScummVM(9888): [29] RGB565 W P X (10060)
07-10 21:48:09.710: D/ScummVM(9888): [30] RGBA8888 W P X (10034)
07-10 21:48:09.715: D/ScummVM(9888): [31] RGB888 W P X (10052)
07-10 21:48:09.715: D/ScummVM(9888): [32] RGB888 D24 W P X (10018)
07-10 21:48:09.715: D/ScummVM(9888): Chosen EGL config: [29] RGB565 W P X
07-10 21:48:09.715: I/ScummVM(9888): ScummVM 1.7.0git690-g685c42b (Jul 10 2013 06:58:33)
07-10 21:48:09.715: I/ScummVM(9888): Running on: [samsung] [GT-N5110] [samsung] [samsung/konawifixx/konawifi:4.1.2/JZO54K/N5110UEEMF2:user/release-keys] [JZO54K.N5110UEEMF2] SDK:16 ABI:armeabi-v7a
07-10 21:48:09.720: I/ScummVM(9888): Entering scummvm_main with 4 args
07-10 21:48:09.720: W/ScummVM(9888): WARNING: File::open: '/data/data/org.scummvm.scummvm/files/scummvmrc' does not exist!
07-10 21:48:09.720: D/ScummVM(9888): Creating configuration file: /data/data/org.scummvm.scummvm/files/scummvmrc
07-10 21:48:09.725: W/ScummVM(9888): WARNING: Failed loading symbol 'PLUGIN_getVersion' from plugin '/data/data/org.scummvm.scummvm/cache/libscummvm.so' (Symbol not found: )!
07-10 21:48:09.725: D/ScummVM(9888): initializing surface
07-10 21:48:09.750: I/ScummVM(9888): Using EGL 1.4 Android META-EGL (Android); GL OpenGL ES-CM 1.1/Mali-400 MP (ARM)
07-10 21:48:09.750: I/ScummVM(9888): Extensions: GL_EXT_debug_marker GL_OES_byte_coordinates GL_OES_fixed_point GL_OES_single_precision GL_OES_matrix_get GL_OES_read_format GL_OES_compressed_paletted_texture GL_OES_point_size_array GL_OES_point_sprite GL_OES_texture_npot GL_OES_query_matrix GL_OES_matrix_palette GL_OES_extended_matrix_palette GL_OES_compressed_ETC1_RGB8_texture GL_OES_EGL_image GL_OES_draw_texture GL_OES_depth_texture GL_OES_packed_depth_stencil GL_EXT_texture_format_BGRA8888 GL_OES_framebuffer_object GL_OES_stencil8 GL_OES_depth24 GL_ARM_rgba8 GL_OES_EGL_image_external GL_OES_EGL_sync GL_OES_rgb8_rgba8 GL_EXT_multisampled_render_to_texture GL_OES_texture_cube_map GL_EXT_discard_framebuffer 
07-10 21:48:09.750: D/ScummVM(9888): initializing viewport
07-10 21:48:09.750: I/ScummVM(9888): overlay size is 640x400
07-10 21:48:09.760: E/SpannableStringBuilder(9888): SPAN_EXCLUSIVE_EXCLUSIVE spans cannot have a zero length
07-10 21:48:09.760: E/SpannableStringBuilder(9888): SPAN_EXCLUSIVE_EXCLUSIVE spans cannot have a zero length
07-10 21:48:57.590: D/GestureDetector(9888): [Surface Touch Event] mSweepDown False, mLRSDCnt : -1 mTouchCnt : 3 mFalseSizeCnt:0
07-10 21:48:59.465: D/GestureDetector(9888): [Surface Touch Event] mSweepDown False, mLRSDCnt : -1 mTouchCnt : 87 mFalseSizeCnt:0
07-10 21:48:59.665: D/GestureDetector(9888): [Surface Touch Event] mSweepDown False, mLRSDCnt : -1 mTouchCnt : 6 mFalseSizeCnt:0
07-10 21:48:59.740: I/ScummVM(9888): scummvm_main exited with code 0
07-10 21:48:59.780: D/ScummVM(9888): Destroying texture 1
07-10 21:48:59.780: D/ScummVM(9888): Destroying texture 2
07-10 21:48:59.780: D/ScummVM(9888): Destroying texture 3
07-10 21:48:59.780: D/ScummVM(9888): deinitializing surface
07-10 21:48:59.815: I/AndroidRuntime(9888): VM exiting with result code 0, cleanup skipped.

Thanks to everyone in advance!!
digitall
ScummVM Developer
Posts: 1172
Joined: Thu Aug 02, 2012 1:40 pm

Post by digitall »

anakondarh: Thank you for reporting this...

This is a known problem on some devices (including my HTC One). Our Android developers have not been able to track down and work out a fix for the delay on startup or work out why it occurs only some of the time. It was suspected to be related to loading the theme data from zip, but that doesn't seem to be the case...

I would suggest filing this as an official bug on the tracker so this isn't lost:
http://sourceforge.net/tracker/?group_i ... tid=418820
digitall
ScummVM Developer
Posts: 1172
Joined: Thu Aug 02, 2012 1:40 pm

Post by digitall »

The question is what is happening in the 30-50 second interval here:
<snip>
07-10 21:48:09.750: D/ScummVM(9888): initializing viewport
07-10 21:48:09.750: I/ScummVM(9888): overlay size is 640x400
07-10 21:48:09.760: E/SpannableStringBuilder(9888): SPAN_EXCLUSIVE_EXCLUSIVE spans cannot have a zero length
07-10 21:48:09.760: E/SpannableStringBuilder(9888): SPAN_EXCLUSIVE_EXCLUSIVE spans cannot have a zero length

<Big Delay Here - Note timestamps>

07-10 21:48:57.590: D/GestureDetector(9888): [Surface Touch Event] mSweepDown False, mLRSDCnt : -1 mTouchCnt : 3 mFalseSizeCnt:0
07-10 21:48:59.465: D/GestureDetector(9888): [Surface Touch Event] mSweepDown False, mLRSDCnt : -1 mTouchCnt : 87 mFalseSizeCnt:0
07-10 21:48:59.665: D/GestureDetector(9888): [Surface Touch Event] mSweepDown False, mLRSDCnt : -1 mTouchCnt : 6 mFalseSizeCnt:0
07-10 21:48:59.740: I/ScummVM(9888): scummvm_main exited with code 0
</snip>
anakondarh
Posts: 4
Joined: Wed Jul 10, 2013 7:33 pm

Post by anakondarh »

Thanks for the reply! I believe that pause you are seeing is the time between ScummVM loading and me exiting the app. I will however fill out a bug report on this.

Thanks again!
digitall
ScummVM Developer
Posts: 1172
Joined: Thu Aug 02, 2012 1:40 pm

Post by digitall »

Some of the time is that... but look at the timestamps from the ScummVM activity starting... There is only a few seconds, so your 30s+ delay with dark screen is between the intial loading and when the themed launcher appears on screen... which is why we thought it was due to the loading of the theme, but yes, there are then 5-10s of you waiting before hitting the Quit button... We just lack debug/profiling for this period to work out what is the cause of this delay.
anakondarh
Posts: 4
Joined: Wed Jul 10, 2013 7:33 pm

Post by anakondarh »

You are correct. I dont think I waited 40 seconds to exit, since I was just testing. Good call... what can we do to know what is happening there?
anakondarh
Posts: 4
Joined: Wed Jul 10, 2013 7:33 pm

Post by anakondarh »

digitall
ScummVM Developer
Posts: 1172
Joined: Thu Aug 02, 2012 1:40 pm

Post by digitall »

Thanks for filing the bug.

The debugging HOWTO, specifically for Android can be found here: http://wiki.scummvm.org/index.php/Debug ... VM#Android

However, this is mainly limited to getting the logs currently. I am not very familiar with Android Development and thus not sure how easy it is to run a remote debugging on native code or otherwise get more detailed debug output... though the links on that page to adb documentation talk about profiling so this should be possible.

Any work you can do on this should enable our Android developer(s) to sort this issue out much quicker.
digitall
ScummVM Developer
Posts: 1172
Joined: Thu Aug 02, 2012 1:40 pm

Post by digitall »

If you are familar with C/C++ and Java, you should be fine to work on this. The documentation at http://wiki.scummvm.org/index.php/Developer_Central should help you get started in getting our code, compiling and basic debugging on Unix/Win32 platforms. The specific instructions for building for Android are here: http://wiki.scummvm.org/index.php/Compi ... VM/Android and the backend code for this platform can be found at: https://github.com/scummvm/scummvm/tree ... rm/android

Good luck...
fuzzie
ScummVM Developer
Posts: 178
Joined: Mon May 24, 2010 3:02 pm

Post by fuzzie »

I think the problem is that the list() function provided by Android's AssetManager is *incredibly, incredibly slow* on some devices.

I pushed a change in mid-May which makes it faster (ef39ca88) by only calling it once (which is why the latest version is better), but it looks like even that is way too slow, and we should probably fall back to something like shipping a .txt file with the names in it.
digitall
ScummVM Developer
Posts: 1172
Joined: Thu Aug 02, 2012 1:40 pm

Post by digitall »

fuzzie: Thanks for the response and fix, but it sounds like something else is going on as well.

According to these references:
http://stackoverflow.com/questions/1691 ... dibly-slow
http://stackoverflow.com/questions/1263 ... st-so-slow

A single call to list() shouldn't be _that_ astronomically slow i.e. worst case is 1sec, not 10-20sec! :)

If profiling shows that this is the cause of the slowdown, we may have to avoid this completely using an asset list autogenerated at compile time as you have indicated... However, I wondered if the solution of copying out to the SD card is an option as discussed on this thread (which seems to mention us!):
http://comments.gmane.org/gmane.comp.ha ... d.ndk/5133
fuzzie
ScummVM Developer
Posts: 178
Joined: Mon May 24, 2010 3:02 pm

Post by fuzzie »

digitall wrote:A single call to list() shouldn't be _that_ astronomically slow i.e. worst case is 1sec, not 10-20sec! :)
I wouldn't be so sure, honestly: if they manage to make it 1sec at all (for an operation which should take 1ms or less) then 10sec on some devices isn't out of the question (and it really isn't that bad on all devices, obviously).
digitall wrote:However, I wondered if the solution of copying out to the SD card is an option as discussed on this thread (which seems to mention us!):
http://comments.gmane.org/gmane.comp.ha ... d.ndk/5133
It seems to me worse than the asset list idea since we'd have to write code to keep it in-sync when the installed version is updated, and the file *access* time is not a problem.
User avatar
LordHoto
ScummVM Developer
Posts: 1029
Joined: Sun Oct 30, 2005 3:58 pm
Location: Germany

Post by LordHoto »

digitall wrote:If profiling shows that this is the cause of the slowdown, we may have to avoid this completely using an asset list autogenerated at compile time as you have indicated... However, I wondered if the solution of copying out to the SD card is an option as discussed on this thread (which seems to mention us!):
http://comments.gmane.org/gmane.comp.ha ... d.ndk/5133
The mail mentioning us is actually a mail by our (initial) Android porter ;-).
digitall
ScummVM Developer
Posts: 1172
Joined: Thu Aug 02, 2012 1:40 pm

Post by digitall »

LordHoto: AH... LOL.

fuzzie: OK. Can I suggest that we try switching to an asset list for now and committing the relevant changes to master? That way, the buildbot builds produced could be tested by myself, anakondarh and other affected users to see if the change resolves the observed problem.
Post Reply