[SOLVED] jmeSurfaceView for android api-31+ not working properly

Ali_RS · February 17, 2023, 9:46am

Yes, it works for me, but I have not looked at logs generated when using DataType.Stream, I will take a look at it and let you know if I found something.

But I noticed the audio performance was very bad, I do not know if it was because of the slow stream or something.

Edit:
Though the bad performance could be because of this also.

WARNING | Not all modern X86 virtualization features supported, which introduces problems with slowdown when running Android on multicore vCPUs. Setting AVD to run with 1 vCPU core only.

The emulator runs slow on my machine

Pavl_G · February 17, 2023, 10:06am

Okay, thanks for trying, i will see what i can do, but first i need to know what is the difference between AudioData.Stream and AudioData.Buffer, i checked the AudioStream and the AudioBuffer classes documentation, but they seem to be misleading regarding the jni implementation on android, so if you have any tips regarding this let me know, i still have to examine the difference between both on android…

Ali_RS · February 17, 2023, 10:13am

We can first try the solution you proposed earlier to see if it fixes the issue.

Pavl_G · February 17, 2023, 10:15am

I agree, but i fear if we didn’t understand the difference, we might introduce a memory leak…

Ali_RS · February 17, 2023, 10:42am

Here is the log I gathered when playing ogg with DataType.Stream:

02-17 13:54:51.921 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_UP, actionButton=0, id[0]=0, x[0]=733.95996, y[0]=62.98828, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1962680, downTime=1962585, deviceId=4, source=0x5002, displayId=0, eventId=71173437 }
02-17 13:54:52.656 D/EGL_emulation(4334): app_time_stats: avg=11.71ms min=2.83ms max=27.06ms count=59
02-17 13:54:54.275 D/EGL_emulation(4334): app_time_stats: avg=179.71ms min=15.24ms max=1482.33ms count=9
02-17 13:54:55.168 D/TaplEvents(975): Main / Touch event: MotionEvent { action=ACTION_DOWN, actionButton=0, id[0]=0, x[0]=526.97754, y[0]=28.981934, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1965930, downTime=1965930, deviceId=4, source=0x5002, displayId=0, eventId=1009360630 }
02-17 13:54:55.177 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_DOWN, actionButton=0, id[0]=0, x[0]=526.97754, y[0]=568.98193, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1965930, downTime=1965930, deviceId=4, source=0x5002, displayId=0, eventId=1009360630 }
02-17 13:54:55.190 D/EGL_emulation(975): app_time_stats: avg=271.38ms min=6.26ms max=7908.97ms count=31
02-17 13:54:55.278 D/TaplEvents(975): Main / Touch event: MotionEvent { action=ACTION_UP, actionButton=0, id[0]=0, x[0]=526.97754, y[0]=28.981934, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1966040, downTime=1965930, deviceId=4, source=0x5002, displayId=0, eventId=338025421 }
02-17 13:54:55.279 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_UP, actionButton=0, id[0]=0, x[0]=526.97754, y[0]=568.98193, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1966040, downTime=1965930, deviceId=4, source=0x5002, displayId=0, eventId=338025421 }
02-17 13:54:55.280 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_HOVER_ENTER, actionButton=0, id[0]=0, x[0]=526.97754, y[0]=567.97485, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1966040, downTime=1965930, deviceId=4, source=0x5002, displayId=0, eventId=275372231 }
02-17 13:54:55.280 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_HOVER_MOVE, actionButton=0, id[0]=0, x[0]=526.97754, y[0]=567.97485, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1966040, downTime=1965930, deviceId=4, source=0x5002, displayId=0, eventId=652689280 }
02-17 13:54:55.281 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_HOVER_EXIT, actionButton=0, id[0]=0, x[0]=526.97754, y[0]=567.97485, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1966040, downTime=1965930, deviceId=4, source=0x5002, displayId=0, eventId=167885974 }
02-17 13:54:55.281 D/EGL_emulation(4334): app_time_stats: avg=125.30ms min=11.33ms max=885.19ms count=8
02-17 13:54:55.342 D/CoreBackPreview(550): Window{9809ec6 u0 Taskbar All Apps}: Setting back callback OnBackInvokedCallbackInfo{mCallback=android.window.IOnBackInvokedCallback$Stub$Proxy@2a8aed9, mPriority=0}
02-17 13:54:55.378 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fa10b000 0x3fa2e0000]
02-17 13:54:55.392 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fb098000 0x3fb26d000]
02-17 13:54:55.394 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fb8f0000 0x3fbac5000]
02-17 13:54:55.462 W/Parcel  (975): Expecting binder but got null!
02-17 13:54:55.514 I/GoogleInputMethodService(1226): GoogleInputMethodService.onFinishInput():3220 
02-17 13:54:55.519 I/GoogleInputMethodService(1226): GoogleInputMethodService.updateDeviceLockedStatus():2114 repeatCheckTimes = 0, unlocked = true
02-17 13:54:55.519 I/GoogleInputMethodService(1226): GoogleInputMethodService.onStartInput():1919 onStartInput(EditorInfo{inputType=0x0(NULL) imeOptions=0x0 privateImeOptions=null actionName=UNSPECIFIED actionLabel=null actionId=0 initialSelStart=-1 initialSelEnd=-1 initialCapsMode=0x0 hintText=null label=null packageName=com.google.android.apps.nexuslauncher fieldId=-1 fieldName=null extras=null}, false)
02-17 13:54:55.520 I/GoogleInputMethodService(1226): GoogleInputMethodService.updateDeviceLockedStatus():2114 repeatCheckTimes = 2, unlocked = true
02-17 13:54:56.369 D/AutofillManager(975): Fill dialog is enabled:false, hints=[password, passwordAuto, creditCardNumber, creditCardSecurityCode, creditCardExpirationDate]
02-17 13:54:56.372 D/TaplEvents(975): Main / Touch event: MotionEvent { action=ACTION_DOWN, actionButton=0, id[0]=0, x[0]=260.98633, y[0]=305.98755, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1967129, downTime=1967129, deviceId=4, source=0x5002, displayId=0, eventId=838787741 }
02-17 13:54:56.375 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_DOWN, actionButton=0, id[0]=0, x[0]=260.98633, y[0]=305.98755, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1967129, downTime=1967129, deviceId=4, source=0x5002, displayId=0, eventId=838787741 }
02-17 13:54:56.415 D/EGL_emulation(4334): app_time_stats: avg=54.80ms min=3.43ms max=645.86ms count=19
02-17 13:54:56.436 W/System  (975): A resource failed to call release. 
02-17 13:54:56.437 W/System  (975): A resource failed to call release. 
02-17 13:54:56.437 W/System  (975): A resource failed to call release. 
02-17 13:54:56.469 D/TaplEvents(975): Main / Touch event: MotionEvent { action=ACTION_UP, actionButton=0, id[0]=0, x[0]=260.98633, y[0]=306.97632, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1967232, downTime=1967129, deviceId=4, source=0x5002, displayId=0, eventId=339174166 }
02-17 13:54:56.470 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_UP, actionButton=0, id[0]=0, x[0]=260.98633, y[0]=306.97632, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1967232, downTime=1967129, deviceId=4, source=0x5002, displayId=0, eventId=339174166 }
02-17 13:54:56.495 D/TaplEvents(975): Main / start: taskbarAppIcon
02-17 13:54:56.496 D/CompatibilityChangeReporter(550): Compat change id reported: 161252188; UID 10159; state: ENABLED
02-17 13:54:56.497 I/ActivityTaskManager(550): START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.mycompany.mygame/.MainActivity bnds=[225,307][312,396]} from uid 10137
02-17 13:54:56.498 D/CompatibilityChangeReporter(550): Compat change id reported: 194480991; UID 10159; state: ENABLED
02-17 13:54:56.505 D/CompatibilityChangeReporter(550): Compat change id reported: 174042980; UID 10159; state: DISABLED
02-17 13:54:56.511 D/CompatibilityChangeReporter(550): Compat change id reported: 184838306; UID 10159; state: DISABLED
02-17 13:54:56.512 D/CompatibilityChangeReporter(550): Compat change id reported: 185004937; UID 10159; state: DISABLED
02-17 13:54:56.512 D/CompatibilityChangeReporter(550): Compat change id reported: 181136395; UID 10159; state: DISABLED
02-17 13:54:56.513 D/CompatibilityChangeReporter(550): Compat change id reported: 174042936; UID 10159; state: DISABLED
02-17 13:54:56.513 D/CompatibilityChangeReporter(550): Compat change id reported: 197654537; UID 10159; state: ENABLED
02-17 13:54:56.524 V/SplashScreenExceptionList(550): SplashScreen checking exception for package com.mycompany.mygame (target sdk:33) -> false
02-17 13:54:56.524 D/CompatibilityChangeReporter(550): Compat change id reported: 205907456; UID 10159; state: ENABLED
02-17 13:54:56.531 D/AudioFlinger(375): mixer(0x781eedfa39a0) throttle end: throttle time(38)
02-17 13:54:56.549 D/CompatibilityChangeReporter(550): Compat change id reported: 194833441; UID 10159; state: ENABLED
02-17 13:54:56.554 V/ShadeControllerImpl(2405): NotificationShadeWindow: com.android.systemui.shade.NotificationShadeWindowView{cd4c3ea I.E...... ......ID 0,0-800,600} canPanelBeCollapsed(): false
02-17 13:54:56.556 D/CompatibilityChangeReporter(550): Compat change id reported: 168419799; UID 10159; state: DISABLED
02-17 13:54:56.559 D/EGL_emulation(975): app_time_stats: avg=48.51ms min=4.75ms max=688.42ms count=28
02-17 13:54:56.561 D/CoreBackPreview(550): Window{b144576 u0 Splash Screen com.mycompany.mygame}: Setting back callback OnBackInvokedCallbackInfo{mCallback=android.window.IOnBackInvokedCallback$Stub$Proxy@1a18fe4, mPriority=0}
02-17 13:54:56.574 D/EGL_emulation(975): app_time_stats: avg=44.19ms min=5.13ms max=604.22ms count=23
02-17 13:54:56.576 I/BpBinder(378): onLastStrongRef automatically unlinking death recipients: <uncached descriptor>
02-17 13:54:56.576 D/CompatibilityChangeReporter(550): Compat change id reported: 135634846; UID 10159; state: DISABLED
02-17 13:54:56.580 D/CompatibilityChangeReporter(550): Compat change id reported: 143937733; UID 10159; state: ENABLED
02-17 13:54:56.602 D/SplashScreenView(2405): Build android.window.SplashScreenView{81cb6ea V.E...... ......ID 0,0-0,0}
02-17 13:54:56.602 D/SplashScreenView(2405): Icon: view: android.widget.ImageView{6f15ddb V.ED..... ......I. 0,0-0,0 #10204dc android:id/splashscreen_icon_view} drawable: com.android.wm.shell.startingsurface.SplashscreenIconDrawableFactory$ImmobileIconDrawable@1bfe078 size: 160
02-17 13:54:56.602 D/SplashScreenView(2405): Branding: view: android.view.View{9e75351 G.ED..... ......I. 0,0-0,0 #10204db android:id/splashscreen_branding_view} drawable: null size w: 0 h: 0
02-17 13:54:56.606 D/Zygote  (336): Forked child process 4399
02-17 13:54:56.627 W/ActivityManager(550): Slow operation: 57ms so far, now at startProcess: done updating battery stats
02-17 13:54:56.627 W/ActivityManager(550): Slow operation: 58ms so far, now at startProcess: building log message
02-17 13:54:56.628 I/ActivityManager(550): Start proc 4399:com.mycompany.mygame/u0a159 for next-top-activity {com.mycompany.mygame/com.mycompany.mygame.MainActivity}
02-17 13:54:56.628 W/ActivityManager(550): Slow operation: 58ms so far, now at startProcess: starting to update pids map
02-17 13:54:56.628 W/ActivityManager(550): Slow operation: 59ms so far, now at startProcess: done updating pids map
02-17 13:54:56.631 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fbac5000 0x3fbc9a000]
02-17 13:54:56.660 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fbc9a000 0x3fbe6f000]
02-17 13:54:56.664 W/Parcel  (2405): Expecting binder but got null!
02-17 13:54:56.697 I/ycompany.mygame(4399): Late-enabling -Xcheck:jni
02-17 13:54:56.712 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fb6e5000 0x3fb8ba000]
02-17 13:54:56.870 W/ycompany.mygame(4399): Unexpected CPU variant for x86: x86_64.
02-17 13:54:56.870 W/ycompany.mygame(4399): Known variants: atom, sandybridge, silvermont, kabylake, default
02-17 13:54:56.881 D/BoundBrokerSvc(1306): onBind: Intent { act=com.google.android.gms.measurement.START pkg=com.google.android.gms }
02-17 13:54:56.881 D/BoundBrokerSvc(1306): Loading bound service for intent: Intent { act=com.google.android.gms.measurement.START pkg=com.google.android.gms }
02-17 13:54:56.905 I/adbd    (427): jdwp connection from 4399
02-17 13:54:56.946 I/AppsFilter(550): interaction: PackageSetting{c1f4439 com.mycompany.mygame/10159} -> PackageSetting{d045418 com.google.android.apps.nexuslauncher/10137} BLOCKED
02-17 13:54:57.045 D/EGL_emulation(2405): app_time_stats: avg=12544.29ms min=12544.29ms max=12544.29ms count=1
02-17 13:54:57.074 D/CoreBackPreview(550): Window{9809ec6 u0 Taskbar All Apps}: Setting back callback null
02-17 13:54:57.094 D/CompatibilityChangeReporter(4399): Compat change id reported: 171979766; UID 10159; state: ENABLED
02-17 13:54:57.103 W/TransactionTracing(378): Could not find layer handle 0x7fe04d343a10
02-17 13:54:57.104 W/TransactionTracing(378): Could not find layer handle 0x7fe04d347730
02-17 13:54:57.106 W/TransactionTracing(378): Could not find layer handle 0x7fe04d347df0
02-17 13:54:57.114 V/WindowManager(550): Unknown focus tokens, dropping reportFocusChanged
02-17 13:54:57.138 W/ziparchive(4399): Unable to open '/data/app/~~CkTsegzqhfqpRS4vIs-FJA==/com.mycompany.mygame-4VsPvURSAGChirPdowwsgQ==/base.dm': No such file or directory
02-17 13:54:57.138 W/ziparchive(4399): Unable to open '/data/app/~~CkTsegzqhfqpRS4vIs-FJA==/com.mycompany.mygame-4VsPvURSAGChirPdowwsgQ==/base.dm': No such file or directory
02-17 13:54:57.439 D/EGL_emulation(4334): app_time_stats: avg=101.03ms min=5.74ms max=279.49ms count=10
02-17 13:54:57.519 W/TransactionTracing(378): Could not find layer handle 0x7fe04d348ab0
02-17 13:54:57.520 W/TransactionTracing(378): Could not find layer handle 0x7fe04d346170
02-17 13:54:57.521 W/TransactionTracing(378): Could not find layer handle 0x7fe04d346170
02-17 13:54:57.521 W/TransactionTracing(378): Could not find layer handle 0x7fe04d348ab0
02-17 13:54:57.548 D/nativeloader(4399): Configuring classloader-namespace for other apk /data/app/~~CkTsegzqhfqpRS4vIs-FJA==/com.mycompany.mygame-4VsPvURSAGChirPdowwsgQ==/base.apk. target_sdk_version=33, uses_libraries=, library_path=/data/app/~~CkTsegzqhfqpRS4vIs-FJA==/com.mycompany.mygame-4VsPvURSAGChirPdowwsgQ==/lib/x86_64:/data/app/~~CkTsegzqhfqpRS4vIs-FJA==/com.mycompany.mygame-4VsPvURSAGChirPdowwsgQ==/base.apk!/lib/x86_64, permitted_path=/data:/mnt/expand:/data/user/0/com.mycompany.mygame
02-17 13:54:57.561 D/HostConnection(550): createUnique: call
02-17 13:54:57.576 D/HostConnection(550): HostConnection::get() New Host Connection established 0x797812998350, tid 2212
02-17 13:54:57.581 V/GraphicsEnvironment(4399): ANGLE Developer option for 'com.mycompany.mygame' set to: 'default'
02-17 13:54:57.589 V/GraphicsEnvironment(4399): ANGLE GameManagerService for com.mycompany.mygame: false
02-17 13:54:57.590 V/GraphicsEnvironment(4399): Neither updatable production driver nor prerelease driver is supported.
02-17 13:54:57.597 D/HostConnection(550): HostComposition ext ANDROID_EMU_CHECKSUM_HELPER_v1 ANDROID_EMU_native_sync_v2 ANDROID_EMU_native_sync_v3 ANDROID_EMU_native_sync_v4 ANDROID_EMU_dma_v1 ANDROID_EMU_direct_mem ANDROID_EMU_host_composition_v1 ANDROID_EMU_host_composition_v2 ANDROID_EMU_YUV_Cache ANDROID_EMU_has_shared_slots_host_memory_allocator ANDROID_EMU_sync_buffer_data ANDROID_EMU_read_color_buffer_dma ANDROID_EMU_hwc_multi_configs GL_OES_EGL_image_external_essl3 GL_OES_vertex_array_object GL_KHR_texture_compression_astc_ldr ANDROID_EMU_host_side_tracing ANDROID_EMU_gles_max_version_3_0 
02-17 13:54:57.598 W/OpenGLRenderer(550): Failed to choose config with EGL_SWAP_BEHAVIOR_PRESERVED, retrying without...
02-17 13:54:57.599 W/OpenGLRenderer(550): Failed to initialize 101010-2 format, error = EGL_SUCCESS
02-17 13:54:57.606 D/EGL_emulation(550): eglCreateContext: 0x797812999490: maj 3 min 0 rcv 3
02-17 13:54:57.608 D/EGL_emulation(550): eglMakeCurrent: 0x797812999490: ver 3 0 (tinfo 0x797a38760080) (first time)
02-17 13:54:57.613 D/NetworkSecurityConfig(4399): No Network Security Config specified, using platform default
02-17 13:54:57.613 D/NetworkSecurityConfig(4399): No Network Security Config specified, using platform default
02-17 13:54:57.641 I/ActivityManager(550): Killing 1588:com.google.process.gapps/u0a105 (adj 975): empty for 1800s
02-17 13:54:57.648 I/libprocessgroup(550): Successfully killed process cgroup uid 10105 pid 1588 in 0ms
02-17 13:54:57.671 I/Zygote  (336): Process 1588 exited due to signal 9 (Killed)
02-17 13:54:57.804 I/binder  (0): undelivered transaction 267714, process died.
02-17 13:54:57.806 I/binder  (0): undelivered transaction 267323, process died.
02-17 13:54:57.697 D/libEGL  (4399): loaded /vendor/lib64/egl/libEGL_emulation.so
02-17 13:54:57.706 D/libEGL  (4399): loaded /vendor/lib64/egl/libGLESv1_CM_emulation.so
02-17 13:54:57.715 D/libEGL  (4399): loaded /vendor/lib64/egl/libGLESv2_emulation.so
02-17 13:54:57.995 W/com.jme3.system.JmeSystem(4399): WARNING JmeDialogsFactory implementation not found.
02-17 13:54:58.002 I/com.jme3.system.JmeSystem(4399): INFO Running on jMonkeyEngine 3.6.0-beta2
02-17 13:54:58.002 I/com.jme3.system.JmeSystem(4399):  * Branch: HEAD
02-17 13:54:58.002 I/com.jme3.system.JmeSystem(4399):  * Git Hash: e71f506
02-17 13:54:58.002 I/com.jme3.system.JmeSystem(4399):  * Build Date: 2023-02-13
02-17 13:54:58.022 I/com.jme3.system.android.OGLESContext(4399): INFO Android Build Version: 33
02-17 13:54:58.042 I/luscubed.matlog(4334): Background young concurrent copying GC freed 146787(7797KB) AllocSpace objects, 4(208KB) LOS objects, 45% free, 9191KB/16MB, paused 87us,32us total 198.005ms
02-17 13:54:58.119 W/WindowManager(550): Failed looking up window session=Session{b555729 4399:u0a10159} callers=com.android.server.wm.WindowManagerService.windowForClientLocked:5972 com.android.server.wm.Session.updateRequestedVisibilities:701 android.view.IWindowSession$Stub.onTransact:1075 
02-17 13:54:58.123 D/CoreBackPreview(550): Window{561e3dc u0 com.mycompany.mygame/com.mycompany.mygame.MainActivity}: Setting back callback OnBackInvokedCallbackInfo{mCallback=android.window.IOnBackInvokedCallback$Stub$Proxy@54ce3ba, mPriority=0}
02-17 13:54:58.176 D/HostConnection(4399): createUnique: call
02-17 13:54:58.177 D/HostConnection(4399): HostConnection::get() New Host Connection established 0x797812964ed0, tid 4416
02-17 13:54:58.191 D/HostConnection(4399): HostComposition ext ANDROID_EMU_CHECKSUM_HELPER_v1 ANDROID_EMU_native_sync_v2 ANDROID_EMU_native_sync_v3 ANDROID_EMU_native_sync_v4 ANDROID_EMU_dma_v1 ANDROID_EMU_direct_mem ANDROID_EMU_host_composition_v1 ANDROID_EMU_host_composition_v2 ANDROID_EMU_YUV_Cache ANDROID_EMU_has_shared_slots_host_memory_allocator ANDROID_EMU_sync_buffer_data ANDROID_EMU_read_color_buffer_dma ANDROID_EMU_hwc_multi_configs GL_OES_EGL_image_external_essl3 GL_OES_vertex_array_object GL_KHR_texture_compression_astc_ldr ANDROID_EMU_host_side_tracing ANDROID_EMU_gles_max_version_3_0 
02-17 13:54:58.194 W/OpenGLRenderer(4399): Failed to choose config with EGL_SWAP_BEHAVIOR_PRESERVED, retrying without...
02-17 13:54:58.197 W/OpenGLRenderer(4399): Failed to initialize 101010-2 format, error = EGL_SUCCESS
02-17 13:54:58.199 D/EGL_emulation(4399): eglCreateContext: 0x7978129669d0: maj 3 min 0 rcv 3
02-17 13:54:58.205 D/EGL_emulation(4399): eglMakeCurrent: 0x7978129669d0: ver 3 0 (tinfo 0x797a3867e080) (first time)
02-17 13:54:58.228 D/HostConnection(4399): createUnique: call
02-17 13:54:58.229 D/HostConnection(4399): HostConnection::get() New Host Connection established 0x797812966490, tid 4421
02-17 13:54:58.242 D/HostConnection(4399): HostComposition ext ANDROID_EMU_CHECKSUM_HELPER_v1 ANDROID_EMU_native_sync_v2 ANDROID_EMU_native_sync_v3 ANDROID_EMU_native_sync_v4 ANDROID_EMU_dma_v1 ANDROID_EMU_direct_mem ANDROID_EMU_host_composition_v1 ANDROID_EMU_host_composition_v2 ANDROID_EMU_YUV_Cache ANDROID_EMU_has_shared_slots_host_memory_allocator ANDROID_EMU_sync_buffer_data ANDROID_EMU_read_color_buffer_dma ANDROID_EMU_hwc_multi_configs GL_OES_EGL_image_external_essl3 GL_OES_vertex_array_object GL_KHR_texture_compression_astc_ldr ANDROID_EMU_host_side_tracing ANDROID_EMU_gles_max_version_3_0 
02-17 13:54:58.243 I/hwservicemanager(185): getTransport: Cannot find entry android.hardware.graphics.mapper@4.0::IMapper/default in either framework or device VINTF manifest.
02-17 13:54:58.247 I/Gralloc4(4399): mapper 4.x is not supported
02-17 13:54:58.250 D/EGL_emulation(4399): eglCreateContext: 0x7978129657d0: maj 3 min 0 rcv 3
02-17 13:54:58.254 D/HostConnection(4399): createUnique: call
02-17 13:54:58.255 D/HostConnection(4399): HostConnection::get() New Host Connection established 0x797812964390, tid 4416
02-17 13:54:58.255 D/goldfish-address-space(4399): allocate: Ask for block of size 0x100
02-17 13:54:58.255 D/goldfish-address-space(4399): allocate: ioctl allocate returned offset 0x3f7ffe000 size 0x2000
02-17 13:54:58.308 I/hwservicemanager(185): getTransport: Cannot find entry android.hardware.graphics.allocator@4.0::IAllocator/default in either framework or device VINTF manifest.
02-17 13:54:58.310 I/servicemanager(184): Could not find android.hardware.graphics.allocator.IAllocator/default in the VINTF manifest.
02-17 13:54:58.310 W/Gralloc4(4399): allocator 4.x is not supported
02-17 13:54:58.312 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fb098000 0x3fb26d000]
02-17 13:54:58.335 D/HostConnection(4399): HostComposition ext ANDROID_EMU_CHECKSUM_HELPER_v1 ANDROID_EMU_native_sync_v2 ANDROID_EMU_native_sync_v3 ANDROID_EMU_native_sync_v4 ANDROID_EMU_dma_v1 ANDROID_EMU_direct_mem ANDROID_EMU_host_composition_v1 ANDROID_EMU_host_composition_v2 ANDROID_EMU_YUV_Cache ANDROID_EMU_has_shared_slots_host_memory_allocator ANDROID_EMU_sync_buffer_data ANDROID_EMU_read_color_buffer_dma ANDROID_EMU_hwc_multi_configs GL_OES_EGL_image_external_essl3 GL_OES_vertex_array_object GL_KHR_texture_compression_astc_ldr ANDROID_EMU_host_side_tracing ANDROID_EMU_gles_max_version_3_0 
02-17 13:54:58.344 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fb8f0000 0x3fba96000]
02-17 13:54:58.346 D/EGL_emulation(4399): eglMakeCurrent: 0x7978129657d0: ver 3 0 (tinfo 0x797a3867e100) (first time)
02-17 13:54:58.388 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fac78000 0x3fae4d000]
02-17 13:54:58.408 W/Parcel  (4399): Expecting binder but got null!

Ali_RS · February 17, 2023, 10:42am

02-17 13:54:58.440 W/ActivityTaskManager(550): Request to remove task ignored for non-existent task 51
02-17 13:54:58.509 I/com.jme3.renderer.opengl.GLRenderer(4399): INFO OpenGL Renderer Information
02-17 13:54:58.509 I/com.jme3.renderer.opengl.GLRenderer(4399):  * Vendor: Google (Intel Open Source Technology Center)
02-17 13:54:58.509 I/com.jme3.renderer.opengl.GLRenderer(4399):  * Renderer: Android Emulator OpenGL ES Translator (Mesa DRI Intel(R) HD Graphics 3000 (SNB GT2))
02-17 13:54:58.509 I/com.jme3.renderer.opengl.GLRenderer(4399):  * OpenGL Version: OpenGL ES 3.0 (3.3 (Core Profile) Mesa 20.0.8)
02-17 13:54:58.509 I/com.jme3.renderer.opengl.GLRenderer(4399):  * GLSL Version: OpenGL ES GLSL ES 3.00
02-17 13:54:58.509 I/com.jme3.renderer.opengl.GLRenderer(4399):  * Profile: Compatibility
02-17 13:54:58.570 W/TransactionTracing(378): Could not find layer handle 0x7fe04d344370
02-17 13:54:58.591 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.cursors.plugins.CursorLoader
02-17 13:54:58.615 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.scene.plugins.ogre.MeshLoader
02-17 13:54:58.621 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.scene.plugins.ogre.SkeletonLoader
02-17 13:54:58.623 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.scene.plugins.ogre.MaterialLoader
02-17 13:54:58.625 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.scene.plugins.ogre.SceneLoader
02-17 13:54:58.628 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.scene.plugins.fbx.FbxLoader
02-17 13:54:58.630 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.scene.plugins.gltf.GltfLoader
02-17 13:54:58.632 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.scene.plugins.gltf.BinLoader
02-17 13:54:58.638 W/com.jme3.asset.AssetConfig(4399): WARNING Cannot find loader com.jme3.scene.plugins.gltf.GlbLoader
02-17 13:54:58.694 D/openal  (4399): [ALSOFT] (II) Initializing library v1.21.1-ae4eacf1 HEAD
02-17 13:54:58.695 D/openal  (4399): [ALSOFT] (II) Supported backends: opensl, null, wave
02-17 13:54:58.696 D/openal  (4399): [ALSOFT] (II) Loading config /etc/openal/alsoft.conf...
02-17 13:54:58.697 D/openal  (4399): [ALSOFT] (II) Loading config /etc/xdg/alsoft.conf...
02-17 13:54:58.697 D/openal  (4399): [ALSOFT] (II) Got binary: /system/bin, app_process64
02-17 13:54:58.698 D/openal  (4399): [ALSOFT] (II) Loading config /system/bin/alsoft.conf...
02-17 13:54:58.703 D/openal  (4399): [ALSOFT] (II) Key disable-cpu-exts not found
02-17 13:54:58.703 D/openal  (4399): [ALSOFT] (II) Extensions: -none-
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Key rt-prio not found
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Key resampler not found
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Key trap-al-error not found
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Key trap-alc-error not found
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Key reverb/boost not found
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Key drivers not found
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Initialized backend "opensl"
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Added "opensl" for playback
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Added "opensl" for capture
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Key excludefx not found
02-17 13:54:58.704 D/openal  (4399): [ALSOFT] (II) Key default-reverb not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key channels not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key sample-type not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key frequency not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key period_size not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key periods not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key sources not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key slots not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key sends not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key ambi-format not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Created device 0x797962988f70, "OpenSL"
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Key hrtf not found
02-17 13:54:58.706 D/openal  (4399): [ALSOFT] (II) Pre-reset: Stereo, Float32, 44100hz, 882 / 2646 buffer
02-17 13:54:58.721 D/ycompany.mygame(4399): PlayerBase::PlayerBase()
02-17 13:54:58.721 D/ycompany.mygame(4399): TrackPlayerBase::TrackPlayerBase()
02-17 13:54:58.721 I/libOpenSLES(4399): Emulating old channel mask behavior (ignoring positional mask 0x3, using default mask 0x3 based on channel count of 2)
02-17 13:54:58.726 W/AudioFlinger(375): createTrack_l(): mismatch between requested flags (00000104) and output flags (00000002)
02-17 13:54:58.727 D/AudioFlinger(375): Client defaulted notificationFrames to 882 for frameCount 1948
02-17 13:54:58.728 D/AF::TrackHandle(375): OpPlayAudio: track:59 usage:1 not muted
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Post-reset: Stereo, Int16, 44100hz, 882 / 2646 buffer
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Key stereo-mode not found
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Key cf_level not found
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Key stereo-encoding not found
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Stereo rendering
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Channel config, Main: 3, Real: 2
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Allocating 5 channels, 20480 bytes
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Enabling single-band first-order ambisonic decoder
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Max sources: 256 (255 + 1), effect slots: 64, sends: 2
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Key dither not found
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Key dither-depth not found
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Dithering enabled (16-bit, 32768)
02-17 13:54:58.742 D/openal  (4399): [ALSOFT] (II) Key output-limiter not found
02-17 13:54:58.743 D/openal  (4399): [ALSOFT] (II) Output limiter enabled, -0.0005dB limit
02-17 13:54:58.743 D/openal  (4399): [ALSOFT] (II) Fixed device latency: 997732ns
02-17 13:54:58.745 D/openal  (4399): [ALSOFT] (II) Increasing allocated voices to 256
02-17 13:54:58.756 E/openal  (4399): [ALSOFT] (EE) Failed to set real-time priority for thread: Operation not permitted (1)
02-17 13:54:58.778 D/openal  (4399): [ALSOFT] (II) Key volume-adjust not found
02-17 13:54:58.778 D/openal  (4399): [ALSOFT] (II) Created context 0x7978729772c0
02-17 13:54:58.788 I/com.jme3.audio.openal.ALAudioRenderer(4399): INFO Audio Renderer Information
02-17 13:54:58.788 I/com.jme3.audio.openal.ALAudioRenderer(4399):  * Device: OpenAL Soft
02-17 13:54:58.788 I/com.jme3.audio.openal.ALAudioRenderer(4399):  * Vendor: OpenAL Community
02-17 13:54:58.788 I/com.jme3.audio.openal.ALAudioRenderer(4399):  * Renderer: OpenAL Soft
02-17 13:54:58.788 I/com.jme3.audio.openal.ALAudioRenderer(4399):  * Version: 1.1 ALSOFT 1.21.1
02-17 13:54:58.788 I/com.jme3.audio.openal.ALAudioRenderer(4399):  * Supported channels: 64
02-17 13:54:58.788 I/com.jme3.audio.openal.ALAudioRenderer(4399):  * ALC extensions: ALC_ENUMERATE_ALL_EXT ALC_ENUMERATION_EXT ALC_EXT_CAPTURE ALC_EXT_DEDICATED ALC_EXT_disconnect ALC_EXT_EFX ALC_EXT_thread_local_context ALC_SOFT_device_clock ALC_SOFT_HRTF ALC_SOFT_loopback ALC_SOFT_loopback_bformat ALC_SOFT_output_limiter ALC_SOFT_pause_device
02-17 13:54:58.788 I/com.jme3.audio.openal.ALAudioRenderer(4399):  * AL extensions: AL_EXT_ALAW AL_EXT_BFORMAT AL_EXT_DOUBLE AL_EXT_EXPONENT_DISTANCE AL_EXT_FLOAT32 AL_EXT_IMA4 AL_EXT_LINEAR_DISTANCE AL_EXT_MCFORMATS AL_EXT_MULAW AL_EXT_MULAW_BFORMAT AL_EXT_MULAW_MCFORMATS AL_EXT_OFFSET AL_EXT_source_distance_model AL_EXT_SOURCE_RADIUS AL_EXT_STEREO_ANGLES AL_LOKI_quadriphonic AL_SOFT_bformat_ex AL_SOFTX_bformat_hoa AL_SOFT_block_alignment AL_SOFTX_callback_buffer AL_SOFTX_convolution_reverb AL_SOFT_deferred_updates AL_SOFT_direct_channels AL_SOFT_direct_channels_remix AL_SOFT_effect_target AL_SOFT_events AL_SOFTX_filter_gain_ex AL_SOFT_gain_clamp_ex AL_SOFT_loop_points AL_SOFTX_map_buffer AL_SOFT_MSADPCM AL_SOFT_source_latency AL_SOFT_source_length AL_SOFT_source_resampler AL_SOFT_source_spatialize
02-17 13:54:58.804 I/com.jme3.audio.openal.ALAudioRenderer(4399): INFO Audio effect extension version: 1.0
02-17 13:54:58.806 I/com.jme3.audio.openal.ALAudioRenderer(4399): INFO Audio max auxiliary sends: 2
02-17 13:54:59.063 W/ziparchive(550): Unable to open '/data/app/~~CkTsegzqhfqpRS4vIs-FJA==/com.mycompany.mygame-4VsPvURSAGChirPdowwsgQ==/base.dm': No such file or directory
02-17 13:54:59.077 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3faaa3000 0x3fac78000]
02-17 13:54:59.081 I/ActivityTaskManager(550): Displayed com.mycompany.mygame/.MainActivity: +2s564ms
02-17 13:54:59.091 D/CompatibilityChangeReporter(550): Compat change id reported: 214016041; UID 10159; state: ENABLED
02-17 13:54:59.099 I/GoogleInputMethodService(1226): GoogleInputMethodService.onFinishInput():3220 
02-17 13:54:59.104 I/GoogleInputMethodService(1226): GoogleInputMethodService.updateDeviceLockedStatus():2114 repeatCheckTimes = 0, unlocked = true
02-17 13:54:59.104 I/GoogleInputMethodService(1226): GoogleInputMethodService.onStartInput():1919 onStartInput(EditorInfo{inputType=0x0(NULL) imeOptions=0x0 privateImeOptions=null actionName=UNSPECIFIED actionLabel=null actionId=0 initialSelStart=-1 initialSelEnd=-1 initialCapsMode=0x0 hintText=null label=null packageName=com.mycompany.mygame fieldId=-1 fieldName=null extras=null}, false)
02-17 13:54:59.105 I/GoogleInputMethodService(1226): GoogleInputMethodService.updateDeviceLockedStatus():2114 repeatCheckTimes = 2, unlocked = true
02-17 13:54:59.113 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:54:59.113 D/AudioTrack(4399): stop(19): called with 15876 frames delivered
02-17 13:54:59.130 D/EGL_emulation(2405): app_time_stats: avg=343.88ms min=16.45ms max=1892.75ms count=6
02-17 13:54:59.152 W/TransactionTracing(378): Could not find layer handle 0x7fe04d343ad0
02-17 13:54:59.190 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:54:59.190 D/AudioTrack(4399): stop(19): called with 882 frames delivered
02-17 13:54:59.330 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:54:59.331 D/AudioTrack(4399): stop(19): called with 882 frames delivered
02-17 13:54:59.443 W/InputManager-JNI(550): Input channel object 'b144576 Splash Screen com.mycompany.mygame (client)' was disposed without first being removed with the input manager!
02-17 13:54:59.457 D/CoreBackPreview(550): Window{b144576 u0 Splash Screen com.mycompany.mygame EXITING}: Setting back callback null
02-17 13:54:59.461 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:54:59.461 D/AudioTrack(4399): stop(19): called with 6174 frames delivered
02-17 13:54:59.478 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:54:59.478 D/AudioTrack(4399): stop(19): called with 882 frames delivered
02-17 13:54:59.502 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:54:59.502 D/AudioTrack(4399): stop(19): called with 882 frames delivered
02-17 13:54:59.515 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:54:59.515 D/AudioTrack(4399): stop(19): called with 882 frames delivered
02-17 13:54:59.636 W/TransactionTracing(378): Could not find layer handle 0x7fe04d347b50
02-17 13:54:59.636 W/TransactionTracing(378): Could not find layer handle 0x7fe04d3449d0
02-17 13:54:59.636 W/TransactionTracing(378): Could not find layer handle 0x7fe04d33f690
02-17 13:54:59.636 W/TransactionTracing(378): Could not find layer handle 0x7fe04d33f690
02-17 13:54:59.636 W/TransactionTracing(378): Could not find layer handle 0x7fe04d3449d0
02-17 13:54:59.755 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fba96000 0x3fbc3c000]
02-17 13:55:00.014 W/ActivityManager(550): Unable to start service Intent { act=android.service.smartspace.SmartspaceService cmp=com.google.android.as/com.google.android.apps.miphone.aiai.app.AiAiSmartspaceService } U=0: not found
02-17 13:55:00.020 W/RemoteSmartspaceService(550): could not bind to Intent { act=android.service.smartspace.SmartspaceService cmp=com.google.android.as/com.google.android.apps.miphone.aiai.app.AiAiSmartspaceService } using flags 67112961
02-17 13:55:00.021 W/ActivityManager(550): Unbind failed: could not find connection for android.app.LoadedApk$ServiceDispatcher$InnerConnection@5d4803c
02-17 13:55:00.756 D/EGL_emulation(4399): app_time_stats: avg=14.10ms min=2.47ms max=497.01ms count=61
02-17 13:55:01.762 D/EGL_emulation(4399): app_time_stats: avg=4.70ms min=2.21ms max=10.95ms count=60
02-17 13:55:02.771 D/EGL_emulation(4399): app_time_stats: avg=3.77ms min=2.14ms max=10.27ms count=61
02-17 13:55:03.435 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:03.435 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:03.773 D/EGL_emulation(4399): app_time_stats: avg=3.61ms min=2.11ms max=8.52ms count=60
02-17 13:55:03.868 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:04.778 D/AudioFlinger(375): mixer(0x781eedfa39a0) throttle end: throttle time(1)
02-17 13:55:04.793 D/EGL_emulation(4399): app_time_stats: avg=3.57ms min=2.01ms max=8.11ms count=60
02-17 13:55:05.805 D/EGL_emulation(4399): app_time_stats: avg=3.34ms min=1.83ms max=8.05ms count=61
02-17 13:55:06.151 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.151 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.151 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.151 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.496 D/AutofillManagerService(550): onBackKeyPressed()
02-17 13:55:06.499 E/RemoteAugmentedAutofillService(550): Bad service name for flags 1048704: com.google.android.as/com.google.android.apps.miphone.aiai.app.AiAiAugmentedAutofillService
02-17 13:55:06.502 I/ActivityTaskManager(550): moveTaskToBack: Task{ca55805 #52 type=standard A=10159:com.mycompany.mygame}
02-17 13:55:06.521 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:55:06.521 D/AudioTrack(4399): stop(19): called with 308700 frames delivered
02-17 13:55:06.523 I/ActivityManager(550): Killing 1871:com.google.android.gms.unstable/u0a105 (adj 965): empty for 1804s
02-17 13:55:06.548 I/libprocessgroup(550): Successfully killed process cgroup uid 10105 pid 1871 in 8ms
02-17 13:55:06.557 D/AutofillManagerService(550): onBackKeyPressed()
02-17 13:55:06.557 E/RemoteAugmentedAutofillService(550): Bad service name for flags 1048704: com.google.android.as/com.google.android.apps.miphone.aiai.app.AiAiAugmentedAutofillService
02-17 13:55:06.558 W/InputDispatcher(550): Waiting because no window has focus but ActivityRecord{2962838 u0 com.mycompany.mygame/.MainActivity} t52} may eventually add a window when it finishes starting up. Will wait for 5000ms
02-17 13:55:06.573 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:55:06.573 D/AudioTrack(4399): stop(19): called with 882 frames delivered
02-17 13:55:06.713 I/binder  (0): undelivered transaction 267709, process died.
02-17 13:55:06.714 I/binder  (0): undelivered transaction 267318, process died.
02-17 13:55:06.584 I/Zygote  (336): Process 1871 exited due to signal 9 (Killed)
02-17 13:55:06.590 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:55:06.590 D/AudioTrack(4399): stop(19): called with 882 frames delivered
02-17 13:55:06.592 D/ycompany.mygame(4399): PlayerBase::stop() from IPlayer
02-17 13:55:06.593 D/AudioTrack(4399): stop(19): called with 882 frames delivered
02-17 13:55:06.596 W/InputDispatcher(550): Waiting because no window has focus but ActivityRecord{31a9807 u0 com.pluscubed.matlog/com.pluscubed.logcat.ui.LogcatActivity} t50} may eventually add a window when it finishes starting up. Will wait for 5000ms
02-17 13:55:06.619 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.621 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.621 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.622 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.627 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fae4d000 0x3fb022000]
02-17 13:55:06.684 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fbc3c000 0x3fbe11000]
02-17 13:55:06.685 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fb66b000 0x3fb840000]
02-17 13:55:06.751 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.751 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.754 D/goldfish-address-space(354): claimShared: Ask to claim region [0x3fbe11000 0x3fbf3d000]
02-17 13:55:06.792 I/GoogleInputMethodService(1226): GoogleInputMethodService.onFinishInput():3220 
02-17 13:55:06.795 I/GoogleInputMethodService(1226): GoogleInputMethodService.updateDeviceLockedStatus():2114 repeatCheckTimes = 0, unlocked = true
02-17 13:55:06.795 I/GoogleInputMethodService(1226): GoogleInputMethodService.onStartInput():1919 onStartInput(EditorInfo{inputType=0x0(NULL) imeOptions=0x0 privateImeOptions=null actionName=UNSPECIFIED actionLabel=null actionId=0 initialSelStart=-1 initialSelEnd=-1 initialCapsMode=0x0 hintText=null label=null packageName=com.pluscubed.matlog fieldId=-1 fieldName=null extras=null}, false)
02-17 13:55:06.796 I/GoogleInputMethodService(1226): GoogleInputMethodService.updateDeviceLockedStatus():2114 repeatCheckTimes = 2, unlocked = true
02-17 13:55:06.819 W/TransactionTracing(378): Could not find layer handle 0x7fe04d3417f0
02-17 13:55:06.986 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:06.986 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:07.018 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:07.018 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:07.069 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:07.069 W/TransactionTracing(378): Could not find layer id -1
02-17 13:55:07.097 E/FrameTracker(975): force finish cuj because of time out:J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 24, 656811, 0, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 24, 656811, 0, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missing HWUI jank callback for vsyncId: 656811, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 80, 656827, 0, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missing HWUI jank callback for vsyncId: 656827, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 656865, 44518512, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 656865, 44518512, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 80, 656873, 43851986, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 80, 656896, 27971026, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 80, 656904, 26048723, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 80, 656912, 31274446, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 656927, 42816096, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 656927, 42816096, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 656942, 61075696, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 656942, 61075696, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 656965, 57879000, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 656965, 57879000, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 656981, 64722701, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 656981, 64722701, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 656989, 80490111, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 656989, 80490111, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 656998, 60706646, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 656998, 60706646, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.098 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 657007, 62659183, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.104 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 657007, 62659183, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.104 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 657015, 112850967, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.104 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 657015, 112850967, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.104 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 657031, 102642143, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.104 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 657031, 102642143, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.104 W/FrameTracker(975): Missed App frame:UNKNOWN: 88, 657068, 120551152, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.104 W/FrameTracker(975): Missed SF frame:UNKNOWN: 88, 657068, 120551152, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.104 W/FrameTracker(975): Missing SF jank callback for vsyncId: 657149, CUJ=J<TASKBAR_COLLAPSE>
02-17 13:55:07.285 W/TransactionTracing(378): Could not find layer handle 0x7fe04d342ff0
02-17 13:55:07.285 W/TransactionTracing(378): Could not find layer handle 0x7fe04d348db0
02-17 13:55:07.285 W/TransactionTracing(378): Could not find layer handle 0x7fe04d348db0
02-17 13:55:07.285 W/TransactionTracing(378): Could not find layer handle 0x7fe04d342ff0
02-17 13:55:07.352 W/TransactionTracing(378): Could not find layer handle 0x7fe04d347370
02-17 13:55:07.961 D/TaplEvents(975): TIS / TouchInteractionService.onInputEvent: MotionEvent { action=ACTION_DOWN, actionButton=0, id[0]=0, x[0]=623.9746, y[0]=57.989502, toolType[0]=TOOL_TYPE_STYLUS, buttonState=0, classification=NONE, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1978721, downTime=1978721, deviceId=4, source=0x5002, displayId=0, eventId=163050093 }
02-17 13:55:07.984 D/EGL_emulation(4334): app_time_stats: avg=39.23ms min=4.69ms max=464.96ms count=30

Pavl_G · February 17, 2023, 11:37am

@Ali_RS Those logs are SDK logs, they are fine.

To display jme native logs, you need to switch this flag to debug instead of release disable the NDEBUG macro and enable log debugs:

github.com

jMonkeyEngine/jmonkeyengine/blob/493195eae810c4a38744e6c34ea0e7e8c48542a9/jme3-android-native/src/native/jme_decode/Application.mk#L2


      
          APP_PLATFORM := android-9
          APP_OPTIM := release
          APP_ABI := all

Then, make sure to reference the ndk here, the native android development kit ships the LLVM compiler toolchain frontend clang, clang++, and the libc and the libstdc++ and other shared object libraries:

github.com

jMonkeyEngine/jmonkeyengine/blob/493195eae810c4a38744e6c34ea0e7e8c48542a9/gradle.properties#L31


      
          

          buildForPlatforms = Linux64,Linux32,Windows64,Windows32,Mac64

          # Forcefully ignore prebuilt libraries

          skipPrebuildLibraries=false

          

          # Enable spotbugs

          enableSpotBugs=false

          

          # Path to android NDK for building native libraries

          #ndkPath=/Users/normenhansen/Documents/Code-Import/android-ndk-r7

          ndkPath = /opt/android-ndk-r16b

          

          # POM settings

          POM_NAME=jMonkeyEngine

          POM_DESCRIPTION=jMonkeyEngine is a 3-D game engine for adventurous Java developers

          POM_URL=http://jmonkeyengine.org

          POM_SCM_URL=https://github.com/jMonkeyEngine/jmonkeyengine

          POM_SCM_CONNECTION=scm:git:git://github.com/jMonkeyEngine/jmonkeyengine.git

          POM_SCM_DEVELOPER_CONNECTION=scm:git:git@github.com:jMonkeyEngine/jmonkeyengine.git

          POM_LICENSE_NAME=New BSD (3-clause) License

          POM_LICENSE_URL=http://opensource.org/licenses/BSD-3-Clause

Then run the following command:

└──╼ $./gradlew -PbuildNativeProjects=true build && ./gradlew install

For me, this is the logs after doing the proposed fix on api-33 android-13 emulator with AudioData.Buffer:

D/openal: [ALSOFT] (II) Key stereo-encoding not found
D/openal: [ALSOFT] (II) Stereo rendering
D/openal: [ALSOFT] (II) Channel config, Main: 3, Real: 2
D/openal: [ALSOFT] (II) Allocating 5 channels, 20480 bytes
D/openal: [ALSOFT] (II) Enabling single-band first-order ambisonic decoder
D/openal: [ALSOFT] (II) Max sources: 256 (255 + 1), effect slots: 64, sends: 2
D/openal: [ALSOFT] (II) Key dither not found
D/openal: [ALSOFT] (II) Key dither-depth not found
D/openal: [ALSOFT] (II) Dithering enabled (16-bit, 32768)
D/openal: [ALSOFT] (II) Key output-limiter not found
D/openal: [ALSOFT] (II) Output limiter enabled, -0.0005dB limit
D/openal: [ALSOFT] (II) Fixed device latency: 997732ns
D/openal: [ALSOFT] (II) Increasing allocated voices to 256
E/openal: [ALSOFT] (EE) Failed to set real-time priority for thread: Operation not permitted (1)
D/openal: [ALSOFT] (II) Key volume-adjust not found
D/openal: [ALSOFT] (II) Created context 0x741b67d6f340
I/ALAudioRenderer: Audio Renderer Information
     * Device: {0}
     * Vendor: {1}
     * Renderer: {2}
     * Version: {3}
     * Supported channels: {4}
     * ALC extensions: {5}
     * AL extensions: {6}
I/ALAudioRenderer: Audio effect extension version: {0}.{1}
I/ALAudioRenderer: Audio max auxiliary sends: {0}
I/NativeImageLoader: stbi_load_from_callbacks
I/NativeImageLoader: InputStream->read(tmp, 0, 128) = 128
I/NativeImageLoader: memcpy(native[0], java, 128)
I/NativeImageLoader: InputStream->read(tmp, 0, 9806) = 9806
I/NativeImageLoader: memcpy(native[0], java, 9806)
I/NativeImageLoader: InputStream->read(tmp, 0, 128) = 16
I/NativeImageLoader: memcpy(native[0], java, 16)
I/NativeImageLoader: InputStream->read(tmp, 0, 112) = -1
I/NativeImageLoader: Flipping image
I/NativeImageLoader: Creating jME3 image
I/System.out: Playing without filter
I/NativeVorbisFile: nativeInit
I/NativeVorbisFile: open: fd = 106, off = 64, len = 23055
I/NativeVorbisFile: FD seek(64) = 64
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD seek(23119) = 23119
I/NativeVorbisFile: FD tell = 23119
I/NativeVorbisFile: FD seek(22159) = 22159
I/NativeVorbisFile: FD read(960) = 960
I/NativeVorbisFile: FD seek(21135) = 21135
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(960) = 960
I/NativeVorbisFile: FD seek(20111) = 20111
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(960) = 960
I/NativeVorbisFile: FD seek(20549) = 20549
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(522) = 522
I/NativeVorbisFile: FD seek(20549) = 20549
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(522) = 522
I/NativeVorbisFile: FD seek(20550) = 20550
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(521) = 521
I/NativeVorbisFile: FD seek(3574) = 3574
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD seek(23119) = 23119
I/NativeVorbisFile: FD seek(22095) = 22095
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD seek(21071) = 21071
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD seek(20047) = 20047
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD seek(20549) = 20549
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(522) = 522
I/NativeVorbisFile: FD seek(64) = 64
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: ov_open OK
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: ov_read(0, 282626) = 256
I/NativeVorbisFile: ov_read(256, 282370) = 256
I/NativeVorbisFile: ov_read(512, 282114) = 256
I/NativeVorbisFile: ov_read(768, 281858) = 256
I/NativeVorbisFile: ov_read(1024, 281602) = 256
I/NativeVorbisFile: ov_read(1280, 281346) = 256
I/NativeVorbisFile: ov_read(1536, 281090) = 256
I/NativeVorbisFile: ov_read(1792, 280834) = 256
I/NativeVorbisFile: ov_read(2048, 280578) = 256
I/NativeVorbisFile: ov_read(2304, 280322) = 256
I/NativeVorbisFile: ov_read(2560, 280066) = 1152
I/NativeVorbisFile: ov_read(3712, 278914) = 2048
I/NativeVorbisFile: ov_read(5760, 276866) = 2048
I/NativeVorbisFile: ov_read(7808, 274818) = 1152
I/NativeVorbisFile: ov_read(8960, 273666) = 256
I/NativeVorbisFile: ov_read(9216, 273410) = 256
I/NativeVorbisFile: ov_read(9472, 273154) = 256
I/NativeVorbisFile: ov_read(9728, 272898) = 256
I/NativeVorbisFile: ov_read(9984, 272642) = 256
I/NativeVorbisFile: ov_read(10240, 272386) = 256
I/NativeVorbisFile: ov_read(10496, 272130) = 256
I/NativeVorbisFile: ov_read(10752, 271874) = 256
I/NativeVorbisFile: ov_read(11008, 271618) = 256
I/NativeVorbisFile: ov_read(11264, 271362) = 1152
I/NativeVorbisFile: ov_read(12416, 270210) = 2048
I/NativeVorbisFile: ov_read(14464, 268162) = 2048
I/NativeVorbisFile: ov_read(16512, 266114) = 2048
I/NativeVorbisFile: ov_read(18560, 264066) = 2048
I/NativeVorbisFile: ov_read(20608, 262018) = 2048
I/NativeVorbisFile: ov_read(22656, 259970) = 2048
I/NativeVorbisFile: ov_read(24704, 257922) = 2048
I/NativeVorbisFile: ov_read(26752, 255874) = 2048
I/NativeVorbisFile: ov_read(28800, 253826) = 2048
I/NativeVorbisFile: ov_read(30848, 251778) = 2048
I/NativeVorbisFile: ov_read(32896, 249730) = 2048
I/NativeVorbisFile: ov_read(34944, 247682) = 2048
I/NativeVorbisFile: ov_read(36992, 245634) = 2048
I/NativeVorbisFile: ov_read(39040, 243586) = 2048
I/NativeVorbisFile: ov_read(41088, 241538) = 2048
I/NativeVorbisFile: ov_read(43136, 239490) = 2048
I/NativeVorbisFile: ov_read(45184, 237442) = 2048
I/NativeVorbisFile: ov_read(47232, 235394) = 2048
I/NativeVorbisFile: ov_read(49280, 233346) = 2048
I/NativeVorbisFile: ov_read(51328, 231298) = 2048
I/NativeVorbisFile: ov_read(53376, 229250) = 2048
I/NativeVorbisFile: ov_read(55424, 227202) = 2048
I/NativeVorbisFile: ov_read(57472, 225154) = 2048
I/NativeVorbisFile: ov_read(59520, 223106) = 2048
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: ov_read(61568, 221058) = 2048
I/NativeVorbisFile: ov_read(63616, 219010) = 2048
I/NativeVorbisFile: ov_read(65664, 216962) = 2048
I/NativeVorbisFile: ov_read(67712, 214914) = 2048
I/NativeVorbisFile: ov_read(69760, 212866) = 2048
I/NativeVorbisFile: ov_read(71808, 210818) = 2048
I/NativeVorbisFile: ov_read(73856, 208770) = 1152
I/NativeVorbisFile: ov_read(75008, 207618) = 256
I/NativeVorbisFile: ov_read(75264, 207362) = 256
I/NativeVorbisFile: ov_read(75520, 207106) = 256
I/NativeVorbisFile: ov_read(75776, 206850) = 1152
I/NativeVorbisFile: ov_read(76928, 205698) = 2048
I/NativeVorbisFile: ov_read(78976, 203650) = 2048
I/NativeVorbisFile: ov_read(81024, 201602) = 1152
I/NativeVorbisFile: ov_read(82176, 200450) = 256
I/NativeVorbisFile: ov_read(82432, 200194) = 256
I/NativeVorbisFile: ov_read(82688, 199938) = 256
I/NativeVorbisFile: ov_read(82944, 199682) = 256
I/NativeVorbisFile: ov_read(83200, 199426) = 1152
I/NativeVorbisFile: ov_read(84352, 198274) = 2048
I/NativeVorbisFile: ov_read(86400, 196226) = 2048
I/NativeVorbisFile: ov_read(88448, 194178) = 2048
I/NativeVorbisFile: ov_read(90496, 192130) = 2048
I/NativeVorbisFile: ov_read(92544, 190082) = 2048
I/NativeVorbisFile: ov_read(94592, 188034) = 2048
I/NativeVorbisFile: ov_read(96640, 185986) = 2048
I/NativeVorbisFile: ov_read(98688, 183938) = 2048
I/NativeVorbisFile: ov_read(100736, 181890) = 2048
I/NativeVorbisFile: ov_read(102784, 179842) = 2048
I/NativeVorbisFile: ov_read(104832, 177794) = 2048
I/NativeVorbisFile: ov_read(106880, 175746) = 2048
I/NativeVorbisFile: ov_read(108928, 173698) = 2048
I/NativeVorbisFile: ov_read(110976, 171650) = 2048
I/NativeVorbisFile: ov_read(113024, 169602) = 2048
I/NativeVorbisFile: ov_read(115072, 167554) = 2048
I/NativeVorbisFile: ov_read(117120, 165506) = 2048
I/NativeVorbisFile: ov_read(119168, 163458) = 2048
I/NativeVorbisFile: ov_read(121216, 161410) = 2048
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: ov_read(123264, 159362) = 2048
I/NativeVorbisFile: ov_read(125312, 157314) = 2048
I/NativeVorbisFile: ov_read(127360, 155266) = 2048
I/NativeVorbisFile: ov_read(129408, 153218) = 2048
I/NativeVorbisFile: ov_read(131456, 151170) = 2048
I/NativeVorbisFile: ov_read(133504, 149122) = 2048
I/NativeVorbisFile: ov_read(135552, 147074) = 2048
I/NativeVorbisFile: ov_read(137600, 145026) = 2048
I/NativeVorbisFile: ov_read(139648, 142978) = 2048
I/NativeVorbisFile: ov_read(141696, 140930) = 2048
I/NativeVorbisFile: ov_read(143744, 138882) = 1152
I/NativeVorbisFile: ov_read(144896, 137730) = 256
I/NativeVorbisFile: ov_read(145152, 137474) = 256
I/NativeVorbisFile: ov_read(145408, 137218) = 256
I/NativeVorbisFile: ov_read(145664, 136962) = 256
I/NativeVorbisFile: ov_read(145920, 136706) = 1152
I/NativeVorbisFile: ov_read(147072, 135554) = 2048
I/NativeVorbisFile: ov_read(149120, 133506) = 2048
I/NativeVorbisFile: ov_read(151168, 131458) = 1152
I/NativeVorbisFile: ov_read(152320, 130306) = 256
I/NativeVorbisFile: ov_read(152576, 130050) = 256
I/NativeVorbisFile: ov_read(152832, 129794) = 256
I/NativeVorbisFile: ov_read(153088, 129538) = 256
I/NativeVorbisFile: ov_read(153344, 129282) = 256
I/NativeVorbisFile: ov_read(153600, 129026) = 1152
I/NativeVorbisFile: ov_read(154752, 127874) = 2048
I/NativeVorbisFile: ov_read(156800, 125826) = 2048
I/NativeVorbisFile: ov_read(158848, 123778) = 2048
I/NativeVorbisFile: ov_read(160896, 121730) = 2048
I/NativeVorbisFile: ov_read(162944, 119682) = 2048
I/NativeVorbisFile: ov_read(164992, 117634) = 2048
I/NativeVorbisFile: ov_read(167040, 115586) = 2048
I/NativeVorbisFile: ov_read(169088, 113538) = 2048
I/NativeVorbisFile: ov_read(171136, 111490) = 2048
I/NativeVorbisFile: ov_read(173184, 109442) = 2048
I/NativeVorbisFile: ov_read(175232, 107394) = 2048
I/NativeVorbisFile: ov_read(177280, 105346) = 2048
I/NativeVorbisFile: ov_read(179328, 103298) = 2048
I/NativeVorbisFile: ov_read(181376, 101250) = 2048
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: ov_read(183424, 99202) = 2048
I/NativeVorbisFile: ov_read(185472, 97154) = 2048
I/NativeVorbisFile: ov_read(187520, 95106) = 2048
I/NativeVorbisFile: ov_read(189568, 93058) = 2048
I/NativeVorbisFile: ov_read(191616, 91010) = 2048
I/NativeVorbisFile: ov_read(193664, 88962) = 2048
I/NativeVorbisFile: ov_read(195712, 86914) = 2048
I/NativeVorbisFile: ov_read(197760, 84866) = 2048
I/NativeVorbisFile: ov_read(199808, 82818) = 2048
I/NativeVorbisFile: ov_read(201856, 80770) = 2048
I/NativeVorbisFile: ov_read(203904, 78722) = 2048
I/NativeVorbisFile: ov_read(205952, 76674) = 2048
I/NativeVorbisFile: ov_read(208000, 74626) = 2048
I/NativeVorbisFile: ov_read(210048, 72578) = 2048
I/NativeVorbisFile: ov_read(212096, 70530) = 2048
I/NativeVorbisFile: ov_read(214144, 68482) = 1152
I/NativeVorbisFile: ov_read(215296, 67330) = 256
I/NativeVorbisFile: ov_read(215552, 67074) = 256
I/NativeVorbisFile: ov_read(215808, 66818) = 256
I/NativeVorbisFile: ov_read(216064, 66562) = 256
I/NativeVorbisFile: ov_read(216320, 66306) = 256
I/NativeVorbisFile: ov_read(216576, 66050) = 256
I/NativeVorbisFile: ov_read(216832, 65794) = 256
I/NativeVorbisFile: ov_read(217088, 65538) = 256
I/NativeVorbisFile: ov_read(217344, 65282) = 1152
I/NativeVorbisFile: ov_read(218496, 64130) = 2048
I/NativeVorbisFile: ov_read(220544, 62082) = 2048
I/NativeVorbisFile: ov_read(222592, 60034) = 1152
I/NativeVorbisFile: ov_read(223744, 58882) = 256
I/NativeVorbisFile: ov_read(224000, 58626) = 256
I/NativeVorbisFile: ov_read(224256, 58370) = 256
I/NativeVorbisFile: ov_read(224512, 58114) = 256
I/NativeVorbisFile: ov_read(224768, 57858) = 256
I/NativeVorbisFile: ov_read(225024, 57602) = 1152
I/NativeVorbisFile: ov_read(226176, 56450) = 2048
I/NativeVorbisFile: ov_read(228224, 54402) = 2048
I/NativeVorbisFile: ov_read(230272, 52354) = 2048
I/NativeVorbisFile: ov_read(232320, 50306) = 2048
I/NativeVorbisFile: ov_read(234368, 48258) = 2048
I/NativeVorbisFile: ov_read(236416, 46210) = 2048
I/NativeVorbisFile: ov_read(238464, 44162) = 2048
I/NativeVorbisFile: ov_read(240512, 42114) = 2048
I/NativeVorbisFile: FD read(1024) = 1024
I/NativeVorbisFile: FD read(527) = 527
I/NativeVorbisFile: ov_read(242560, 40066) = 2048
I/NativeVorbisFile: ov_read(244608, 38018) = 2048
I/NativeVorbisFile: ov_read(246656, 35970) = 2048
I/NativeVorbisFile: ov_read(248704, 33922) = 2048
I/NativeVorbisFile: ov_read(250752, 31874) = 1152
I/NativeVorbisFile: ov_read(251904, 30722) = 256
I/NativeVorbisFile: ov_read(252160, 30466) = 256
I/NativeVorbisFile: ov_read(252416, 30210) = 256
I/NativeVorbisFile: ov_read(252672, 29954) = 256
I/NativeVorbisFile: ov_read(252928, 29698) = 1152
I/NativeVorbisFile: ov_read(254080, 28546) = 2048
I/NativeVorbisFile: ov_read(256128, 26498) = 2048
I/NativeVorbisFile: ov_read(258176, 24450) = 2048
I/NativeVorbisFile: ov_read(260224, 22402) = 2048
I/NativeVorbisFile: ov_read(262272, 20354) = 2048
I/NativeVorbisFile: ov_read(264320, 18306) = 2048
I/NativeVorbisFile: ov_read(266368, 16258) = 2048
I/NativeVorbisFile: ov_read(268416, 14210) = 2048
I/NativeVorbisFile: ov_read(270464, 12162) = 2048
I/NativeVorbisFile: ov_read(272512, 10114) = 2048
I/NativeVorbisFile: ov_read(274560, 8066) = 2048
I/NativeVorbisFile: ov_read(276608, 6018) = 2048
I/NativeVorbisFile: ov_read(278656, 3970) = 2048
I/NativeVorbisFile: ov_read(280704, 1922) = 1922
I/NativeVorbisFile: close
I/NativeVorbisFile: Cleared OggVorbisFile resources -- Delegated stream closure to the ParcelFileDescriptor
I/JmeSurfaceView: JmeGame started in GLThread Asynchronously.......

And this is specifically the part where jme calls file.close() as it logs close then the ov_clear calls the overridden close function which does nothing (the proposed fix here); because it shouldn’t do, we delegated this to the ParcelFileDescriptor and the rest of the OggVorbisFile data structure are left to be cleared by ov_clear…

EDIT:
If you want to test this, i will upload my local snapshot to you now on my jmonkeyengine fork, but you will have to include it locally in the libs folder.

EDIT2:

EDIT3:
I tested the fix on my physical device and the sound works fine.

Pavl_G · February 17, 2023, 1:03pm

Read this about the fdsan (file descriptor sanitizer), the fdsan docs:
https://android.googlesource.com/platform/bionic/+/master/docs/fdsan.md#using-fdsan-to-fix-a-bug

This is a typical case that happens with jMonkeyEngine NativeVorbisLoader, a double closure of resources, in this example, we are duplicating the references to the same file descriptor and trying to close the file descriptor from an object that doesn’t own it (the bystander function):

#include <err.h>
#include <unistd.h>

#include <chrono>
#include <thread>
#include <vector>

#include <android-base/unique_fd.h>

using namespace std::chrono_literals;
using std::this_thread::sleep_for;

void victim() {
  sleep_for(300ms);
  android::base::unique_fd fd(dup(STDOUT_FILENO));
  sleep_for(200ms);
  ssize_t rc = write(fd, "good\n", 5);
  if (rc == -1) {
    err(1, "good failed to write?!");
  }
}

void bystander() {
  sleep_for(100ms);
  int fd = dup(STDOUT_FILENO);
  sleep_for(300ms);
  close(fd);
}

This case, throws this error:

pid: 25587, tid: 25589, name: fdsan_test  >>> fdsan_test <<<
signal 35 (<debuggerd signal>), code -1 (SI_QUEUE), fault addr --------
Abort message: 'attempted to close file descriptor 3, expected to be unowned, actually owned by unique_fd 0x7bf15dc448'
    x0  0000000000000000  x1  00000000000063f5  x2  0000000000000023  x3  0000007bf14de338
    x4  0000007bf14de3b8  x5  3463643531666237  x6  3463643531666237  x7  3834346364353166
    x8  00000000000000f0  x9  0000000000000000  x10 0000000000000059  x11 0000000000000035
    x12 0000007bf1bebcfa  x13 0000007bf14ddf0a  x14 0000007bf14ddf0a  x15 0000000000000000
    x16 0000007bf1c33048  x17 0000007bf1ba9990  x18 0000000000000000  x19 00000000000063f3
    x20 00000000000063f5  x21 0000007bf14de588  x22 0000007bf1f1b864  x23 0000000000000001
    x24 0000007bf14de130  x25 0000007bf13e1000  x26 0000007bf1f1f580  x27 0000005ab43ab8f0
    x28 0000000000000000  x29 0000007bf14de400
    sp  0000007bf14ddff0  lr  0000007bf1b5fd6c  pc  0000007bf1b5fd90

backtrace:
    #00 pc 0000000000008d90  /system/lib64/libc.so (fdsan_error(char const*, ...)+384)
    #01 pc 0000000000008ba8  /system/lib64/libc.so (android_fdsan_close_with_tag+632)
    #02 pc 00000000000092a0  /system/lib64/libc.so (close+16)
    #03 pc 00000000000003e4  /system/bin/fdsan_test (bystander()+84)
    #04 pc 0000000000000918  /system/bin/fdsan_test
    #05 pc 000000000006689c  /system/lib64/libc.so (__pthread_start(void*)+36)
    #06 pc 000000000000712c  /system/lib64/libc.so (__start_thread+68)

As you can see the backtrace shows the bystander function which calls close on an unowned fd:

    #02 pc 00000000000092a0  /system/lib64/libc.so (close+16)
    #03 pc 00000000000003e4  /system/bin/fdsan_test (bystander()+84)

Cool ! Now we need to refactor rename the jme NativeVorbisFile#close(), NativeVorbisFile#open() and their respective jni functions with a proper documentation.

BTW, the AudioData.Stream doesn’t fire the crash; because the file.close is guarded by this:

github.com

jMonkeyEngine/jmonkeyengine/blob/493195eae810c4a38744e6c34ea0e7e8c48542a9/jme3-android/src/main/java/com/jme3/audio/plugins/NativeVorbisLoader.java#L108


      
                  file = new NativeVorbisFile(fd, afd.getStartOffset(), afd.getLength());
                  
                  AudioStream stream = new AudioStream();
                  stream.setupFormat(file.channels, 16, file.sampleRate);
                  stream.updateData(new VorbisInputStream(afd, file), file.duration);
                  
                  success = true;
                  
                  return stream;
              } finally {
                  if (!success) {
                      if (file != null) {
                          file.close();
                      }
                      if (afd != null) {
                          afd.close();
                      }
                  }
              }
          }

Pavl_G · February 17, 2023, 1:13pm

As the open function is utilizing an already opened file and the close function is now not closing the file (the fix), so i propose to also refactor:

open() to getVorbisFromFile().
close() to clearResources().

As i go to refactor this, if i did ever find better names, i will use them…

EDIT:

@Anuj_Topiwala Thanks for sending this, you did save the day !

Ali_RS · February 17, 2023, 2:18pm

Cool, thank you!

I will test with the jme3-android-native-3.6.0-FIX.jar you uploaded and let you know.

By the way, where is the log file saved? Do I need to do something on the android emulator to enable logging?

The previous logs I posted above, I grabbed them using the Matlog app. Do I need to do it another way for this case to be able to get the correct logs from the natives you uploaded?

Pavl_G · February 17, 2023, 3:41pm

The logs are provided by the adb shell, you can use the adb shell command directly to install and launch the MainActivity or the android studio logcat in the bottom bar…it reads the stdout on the terminal running the adb shell…

On adb shell binary directory:

└──╼ $./adb devices
List of devices attached
9f06dcb0	device
emulator-5554	offline


# To start the mainactivity using the am (activity manager) and to show logs
└──╼ $./adb -s 9f06dcb0 shell am start -n "com.scrappers.testjmevorbisloader/com.scrappers.testjmevorbisloader.MainActivity" -a android.intent.action.MAIN -c android.intent.category.LAUNCHER && 
./adb -s 9f06dcb0 logcat

Replace the "com.scrappers.testjmevorbisloader/com.scrappers.testjmevorbisloader.MainActivity with your mainactivity name…

I recommend using android studio, it provides a logcat out of the box…

EDIT:
I have already enabled the debugging logs on the binary jme3-android-native-FIX.jar, so if you are using Matlog and it logs good, then you can still use it … If you don’t want to use android studio…

Ali_RS · February 17, 2023, 4:02pm

I tried and it works! Great job

Below is the log from Matlog, I will also try with the adb shell as you said.

https://drive.google.com/file/d/1DvFH3M5TmZWUEhc-BJ1GCEfUWlWKJnQa/view?usp=sharing

Pavl_G · February 17, 2023, 4:07pm

Thanks for testing, if you also checked the AudioData.Stream, you should never find this log:

02-17 19:00:32.608 I/NativeVorbisFile(3844): clear
02-17 19:00:32.608 I/NativeVorbisFile(3844): Cleared OggVorbisFile resources -- Delegated stream closure to the ParcelFileDescriptor

Because it doesn’t call the close function if the load is successful (i currently still have no idea what is the use of this, i will read it again later).

Pavl_G · February 17, 2023, 4:12pm

The key fix was just to remove this and return 0 instead; because the same fd is owned by the java ParcelFileDescriptor , but we should take care of refactoring method names as well and may be adding some documentation…

EDIT:
I will see, if i can remove the method completely for clean code purposes without throwing a memory segmentation error…

Pavl_G · February 17, 2023, 9:41pm

I created a draft PR:

github.com/jMonkeyEngine/jmonkeyengine

Android-native-vorbis: fix double asset file descriptor closure

jMonkeyEngine:master ← JMonkey-Archive:fix-vorbisnative-patch

opened 09:38PM - 17 Feb 23 UTC

Scrappers-glitch

+39 -23

### This PR fixes the following: - [x] Issue [#1955] by delegating the file clo…sure to the android [`ParcelFileDescriptor`](https://github.com/jMonkeyEngine/jmonkeyengine/blob/493195eae810c4a38744e6c34ea0e7e8c48542a9/jme3-android/src/main/java/com/jme3/audio/plugins/NativeVorbisLoader.java#L71), the original resource that opens the audio asset. ### This PR adds the following: - [ ] Native and java documentation (WIP). ### This PR refactors the following: - [x] `NativeVorbisFile#open(int, long, long)` to `NativeVorbisFile#init(int, long, long)`. - [x] `NativeVorbisFile#close()` to `NativeVorbisFile#clearResources()`.

EDIT:
Btw, i forked the ogg vorbis native library used by android from xiph.org, and i will give it a try later, it will be better to maintain this library rather than relying on the outdated TremorAndroid file…

Ali_RS · February 18, 2023, 6:32am

Thanks so much, Pavl

Ali_RS · February 18, 2023, 11:27am

By the way, do you know if JME supports loading audio data using the android built-in media library? (like it does for loading images)

I could find anything related from a quick glance in the JME source code.

Android’s built-in media library supports a variety of audio formats including wave, vorbis, mp3,… that can remove the hassle of maintaining multiple formats on JME side

Pavl_G · February 18, 2023, 12:04pm

Afaik, there are no another native sound decoders rather than the vorbis one on the jme native side, this is the wave loader:

github.com

jMonkeyEngine/jmonkeyengine/blob/493195eae810c4a38744e6c34ea0e7e8c48542a9/jme3-core/src/plugins/java/com/jme3/audio/plugins/WAVLoader.java#L50


      
          import com.jme3.audio.SeekableStream;
          import com.jme3.util.BufferUtils;
          import com.jme3.util.LittleEndien;
          import java.io.BufferedInputStream;
          import java.io.IOException;
          import java.io.InputStream;
          import java.nio.ByteBuffer;
          import java.util.logging.Level;
          import java.util.logging.Logger;
          
          
public class WAVLoader implements AssetLoader {
          
          
    private static final Logger logger = Logger.getLogger(WAVLoader.class.getName());
          
          
    // all these are in big endian
              private static final int i_RIFF = 0x46464952;
              private static final int i_WAVE = 0x45564157;
              private static final int i_fmt  = 0x20746D66;
              private static final int i_data = 0x61746164;
          
          
    private boolean readStream = false;

And i guess it is also used by android…

The audio AssetLoader job is to read the sound file and load into a buffer for the renderer…

To know whether this file is an .ogg or .wav, there should be a point in the AssetManager where this check occurs to decide which loader to use.

The link you referenced now, states that the android API has an ogg decoder, idk why the original author uses a 3rd party plugin, but one guess may be the behavior or the output buffer of the android native ogg decoder is not compatible with jme, may be, this needs some study…we may open an issue with a question label to investigate it later…

Ali_RS · February 18, 2023, 12:18pm

Agree with you, I submitted an issue for this

Pavl_G · February 18, 2023, 12:35pm

Btw, this is the loaders map that the loaded asset extension should be checked against before acquiring the loader:

github.com

jMonkeyEngine/jmonkeyengine/blob/493195eae810c4a38744e6c34ea0e7e8c48542a9/jme3-core/src/main/resources/com/jme3/asset/General.cfg#L5


      
          # Generic locators that should be supported on all platforms.
          LOCATOR / com.jme3.asset.plugins.ClasspathLocator
          
          
# Generic loaders that should be supported on all platforms.
          LOADER com.jme3.audio.plugins.WAVLoader : wav
          LOADER com.jme3.cursors.plugins.CursorLoader : ani, cur, ico
          LOADER com.jme3.material.plugins.J3MLoader : j3m
          LOADER com.jme3.material.plugins.J3MLoader : j3md
          LOADER com.jme3.material.plugins.ShaderNodeDefinitionLoader : j3sn
          LOADER com.jme3.font.plugins.BitmapFontLoader : fnt
          LOADER com.jme3.texture.plugins.DDSLoader : dds
          LOADER com.jme3.texture.plugins.PFMLoader : pfm
          LOADER com.jme3.texture.plugins.HDRLoader : hdr
          LOADER com.jme3.texture.plugins.TGALoader : tga
          LOADER com.jme3.export.binary.BinaryLoader : j3o

And those are the android ones that include the General map:

github.com

jMonkeyEngine/jmonkeyengine/blob/493195eae810c4a38744e6c34ea0e7e8c48542a9/jme3-android/src/main/resources/com/jme3/asset/Android.cfg

INCLUDE com/jme3/asset/General.cfg

# Android specific locators
LOCATOR / com.jme3.asset.plugins.AndroidLocator

# Android specific loaders
LOADER com.jme3.texture.plugins.AndroidNativeImageLoader : jpg, bmp, gif, png, jpeg
LOADER com.jme3.texture.plugins.AndroidBufferImageLoader : webp, heic, heif
LOADER com.jme3.audio.plugins.NativeVorbisLoader : ogg

EDIT:
So, android uses the WAVLoader for loading the wave files.